2019-06-07 05:02:43,128 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-07 05:03:33,168 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-07 05:04:23,214 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-07 05:05:13,259 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-07 05:06:03,310 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-07 05:08:12,950 [salt.utils.decorators:613 ][WARNING ][2705] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 05:08:13,517 [salt.utils.decorators:613 ][WARNING ][2705] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 05:08:15,676 [salt.loaded.int.states.file:2298][WARNING ][2840] 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-07 05:08:21,134 [salt.state       :2022][WARNING ][2955] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-07 05:08:23,685 [salt.utils.decorators:613 ][WARNING ][2955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 05:23:30,612 [salt.utils.decorators:613 ][WARNING ][2955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 05:51:23,193 [salt.utils.decorators:613 ][WARNING ][2955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:06:25,593 [salt.utils.decorators:613 ][WARNING ][2955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:06:29,332 [salt.loaded.ext.module.maasng:1008][WARNING ][2955] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-07 06:06:29,332 [salt.loaded.ext.module.maasng:1011][WARNING ][2955] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-07 06:06:30,084 [salt.loaded.ext.module.maasng:1235][WARNING ][2955] Ignoring parameter vlan:0
2019-06-07 06:06:30,991 [salt.utils.decorators:613 ][WARNING ][2955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:06:33,241 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10540] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-07 06:06:33,278 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10540] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-07 06:06:33,304 [salt.utils.parsers:1051][WARNING ][360] Minion received a SIGTERM. Exiting.
2019-06-07 06:06:34,298 [salt.cli.daemons :293 ][INFO    ][10613] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-06-07 06:06:34,427 [salt.cli.daemons :82  ][INFO    ][10613] Starting up the Salt Minion
2019-06-07 06:06:34,428 [salt.utils.event :1017][INFO    ][10613] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-06-07 06:06:35,247 [salt.minion      :976 ][INFO    ][10613] Creating minion process manager
2019-06-07 06:06:36,564 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10613] Executing command ['date', '+%z'] in directory '/root'
2019-06-07 06:06:36,583 [salt.utils.schedule:568 ][INFO    ][10613] Updating job settings for scheduled job: __mine_interval
2019-06-07 06:06:36,584 [salt.minion      :1108][INFO    ][10613] Added mine.update to scheduler
2019-06-07 06:06:36,588 [salt.minion      :1975][INFO    ][10613] Minion is starting as user 'root'
2019-06-07 06:06:36,601 [salt.minion      :2336][INFO    ][10613] Minion is ready to receive requests!
2019-06-07 06:06:36,916 [salt.utils.decorators:613 ][WARNING ][10545] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:06:36,995 [salt.loaded.ext.module.maas:412 ][WARNING ][10545] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:06:41,912 [salt.loaded.ext.module.maas:412 ][WARNING ][10545] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:06:46,672 [salt.loaded.ext.module.maas:412 ][WARNING ][10545] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:06:46,906 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060646895702
2019-06-07 06:06:46,925 [salt.minion      :1432][INFO    ][10821] Starting a new job with PID 10821
2019-06-07 06:06:46,947 [salt.minion      :1711][INFO    ][10821] Returning information for job: 20190607060646895702
2019-06-07 06:06:51,183 [salt.loaded.ext.module.maas:412 ][WARNING ][10545] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:06:55,982 [salt.loaded.ext.module.maas:412 ][WARNING ][10545] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:07:30,626 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607060730613074
2019-06-07 06:07:30,648 [salt.minion      :1432][INFO    ][11045] Starting a new job with PID 11045
2019-06-07 06:07:34,233 [salt.state       :915 ][INFO    ][11045] Loading fresh modules for state activity
2019-06-07 06:07:34,285 [salt.fileclient  :1219][INFO    ][11045] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-07 06:07:34,331 [salt.state       :1780][INFO    ][11045] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:07:34.331653
2019-06-07 06:07:34,332 [salt.state       :1813][INFO    ][11045] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:07:34,334 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11045] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:07:35,759 [salt.state       :300 ][INFO    ][11045] {'pid': 11053, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:07:35,760 [salt.state       :1951][INFO    ][11045] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:07:35.760622 duration_in_ms=1428.969
2019-06-07 06:07:35,763 [salt.state       :1780][INFO    ][11045] Running state [maas.wait_for_machine_status] at time 06:07:35.763659
2019-06-07 06:07:35,764 [salt.state       :1813][INFO    ][11045] Executing state module.run for [maas.wait_for_machine_status]
2019-06-07 06:07:35,764 [salt.utils.decorators:613 ][WARNING ][11045] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:07:36,711 [salt.loaded.ext.module.maas:1023][INFO    ][11045] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.06307101s left)
2019-06-07 06:07:45,738 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060745725436
2019-06-07 06:07:45,761 [salt.minion      :1432][INFO    ][11064] Starting a new job with PID 11064
2019-06-07 06:07:45,785 [salt.minion      :1711][INFO    ][11064] Returning information for job: 20190607060745725436
2019-06-07 06:08:07,526 [salt.loaded.ext.module.maas:1023][INFO    ][11045] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.24832702s left)
2019-06-07 06:08:15,782 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060815769036
2019-06-07 06:08:15,804 [salt.minion      :1432][INFO    ][11084] Starting a new job with PID 11084
2019-06-07 06:08:15,827 [salt.minion      :1711][INFO    ][11084] Returning information for job: 20190607060815769036
2019-06-07 06:08:45,848 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060845842118
2019-06-07 06:08:45,859 [salt.minion      :1432][INFO    ][11336] Starting a new job with PID 11336
2019-06-07 06:08:45,880 [salt.minion      :1711][INFO    ][11336] Returning information for job: 20190607060845842118
2019-06-07 06:09:15,913 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060915900129
2019-06-07 06:09:15,936 [salt.minion      :1432][INFO    ][11560] Starting a new job with PID 11560
2019-06-07 06:09:15,961 [salt.minion      :1711][INFO    ][11560] Returning information for job: 20190607060915900129
2019-06-07 06:09:46,002 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607060945988572
2019-06-07 06:09:46,025 [salt.minion      :1432][INFO    ][11667] Starting a new job with PID 11667
2019-06-07 06:09:46,054 [salt.minion      :1711][INFO    ][11667] Returning information for job: 20190607060945988572
2019-06-07 06:10:16,071 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061016059202
2019-06-07 06:10:16,095 [salt.minion      :1432][INFO    ][11707] Starting a new job with PID 11707
2019-06-07 06:10:16,119 [salt.minion      :1711][INFO    ][11707] Returning information for job: 20190607061016059202
2019-06-07 06:10:46,152 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061046138789
2019-06-07 06:10:46,173 [salt.minion      :1432][INFO    ][11880] Starting a new job with PID 11880
2019-06-07 06:10:46,194 [salt.minion      :1711][INFO    ][11880] Returning information for job: 20190607061046138789
2019-06-07 06:11:16,213 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061116201641
2019-06-07 06:11:16,233 [salt.minion      :1432][INFO    ][11899] Starting a new job with PID 11899
2019-06-07 06:11:16,253 [salt.minion      :1711][INFO    ][11899] Returning information for job: 20190607061116201641
2019-06-07 06:11:46,293 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061146279928
2019-06-07 06:11:46,315 [salt.minion      :1432][INFO    ][11934] Starting a new job with PID 11934
2019-06-07 06:11:46,338 [salt.minion      :1711][INFO    ][11934] Returning information for job: 20190607061146279928
2019-06-07 06:12:16,392 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061216378934
2019-06-07 06:12:16,408 [salt.minion      :1432][INFO    ][11959] Starting a new job with PID 11959
2019-06-07 06:12:16,430 [salt.minion      :1711][INFO    ][11959] Returning information for job: 20190607061216378934
2019-06-07 06:12:46,483 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061246470306
2019-06-07 06:12:46,501 [salt.minion      :1432][INFO    ][11987] Starting a new job with PID 11987
2019-06-07 06:12:46,516 [salt.minion      :1711][INFO    ][11987] Returning information for job: 20190607061246470306
2019-06-07 06:13:16,570 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061316557338
2019-06-07 06:13:16,587 [salt.minion      :1432][INFO    ][12009] Starting a new job with PID 12009
2019-06-07 06:13:16,609 [salt.minion      :1711][INFO    ][12009] Returning information for job: 20190607061316557338
2019-06-07 06:13:46,665 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061346652594
2019-06-07 06:13:46,688 [salt.minion      :1432][INFO    ][12035] Starting a new job with PID 12035
2019-06-07 06:13:46,712 [salt.minion      :1711][INFO    ][12035] Returning information for job: 20190607061346652594
2019-06-07 06:14:16,775 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061416760105
2019-06-07 06:14:16,798 [salt.minion      :1432][INFO    ][12060] Starting a new job with PID 12060
2019-06-07 06:14:16,821 [salt.minion      :1711][INFO    ][12060] Returning information for job: 20190607061416760105
2019-06-07 06:14:46,688 [salt.state       :302 ][ERROR   ][11045] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-06-07 06:14:46,689 [salt.state       :1951][INFO    ][11045] Completed state [maas.wait_for_machine_status] at time 06:14:46.689156 duration_in_ms=430925.496
2019-06-07 06:14:46,692 [salt.minion      :1711][INFO    ][11045] Returning information for job: 20190607060730613074
2019-06-07 06:14:57,478 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command pillar.get with jid 20190607061457465092
2019-06-07 06:14:57,500 [salt.minion      :1432][INFO    ][12366] Starting a new job with PID 12366
2019-06-07 06:14:57,509 [salt.minion      :1711][INFO    ][12366] Returning information for job: 20190607061457465092
2019-06-07 06:14:58,054 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command service.status with jid 20190607061458042156
2019-06-07 06:14:58,071 [salt.minion      :1432][INFO    ][12372] Starting a new job with PID 12372
2019-06-07 06:14:58,462 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12372] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-07 06:14:58,490 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12372] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-07 06:14:58,503 [salt.minion      :1711][INFO    ][12372] Returning information for job: 20190607061458042156
2019-06-07 06:14:59,055 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607061459048182
2019-06-07 06:14:59,075 [salt.minion      :1432][INFO    ][12383] Starting a new job with PID 12383
2019-06-07 06:15:02,679 [salt.state       :915 ][INFO    ][12383] Loading fresh modules for state activity
2019-06-07 06:15:03,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:15:03,429 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:15:04,181 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:15:04,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:15:05,779 [salt.state       :1780][INFO    ][12383] Running state [salt-minion] at time 06:15:05.778999
2019-06-07 06:15:05,779 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [salt-minion]
2019-06-07 06:15:05,779 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:15:05,857 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:05,857 [salt.state       :1951][INFO    ][12383] Completed state [salt-minion] at time 06:15:05.857286 duration_in_ms=78.287
2019-06-07 06:15:05,857 [salt.state       :1780][INFO    ][12383] Running state [salt_minion_dependency_packages] at time 06:15:05.857545
2019-06-07 06:15:05,857 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-07 06:15:05,862 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:05,862 [salt.state       :1951][INFO    ][12383] Completed state [salt_minion_dependency_packages] at time 06:15:05.862736 duration_in_ms=5.191
2019-06-07 06:15:05,865 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/minion.d/minion.conf] at time 06:15:05.865172
2019-06-07 06:15:05,865 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-07 06:15:06,040 [salt.state       :300 ][INFO    ][12383] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-07 06:15:06,041 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/minion.d/minion.conf] at time 06:15:06.040977 duration_in_ms=175.805
2019-06-07 06:15:06,041 [salt.state       :1780][INFO    ][12383] Running state [python-netaddr] at time 06:15:06.041172
2019-06-07 06:15:06,041 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [python-netaddr]
2019-06-07 06:15:06,045 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:06,045 [salt.state       :1951][INFO    ][12383] Completed state [python-netaddr] at time 06:15:06.045949 duration_in_ms=4.778
2019-06-07 06:15:06,048 [salt.state       :1780][INFO    ][12383] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:15:06.048028
2019-06-07 06:15:06,048 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-07 06:15:06,056 [salt.state       :300 ][INFO    ][12383] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-07 06:15:06,056 [salt.state       :1951][INFO    ][12383] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:15:06.056718 duration_in_ms=8.689
2019-06-07 06:15:06,057 [salt.state       :1780][INFO    ][12383] Running state [salt-minion] at time 06:15:06.057356
2019-06-07 06:15:06,057 [salt.state       :1813][INFO    ][12383] Executing state service.running for [salt-minion]
2019-06-07 06:15:06,057 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:06,093 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-07 06:15:06,110 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-07 06:15:06,126 [salt.state       :300 ][INFO    ][12383] The service salt-minion is already running
2019-06-07 06:15:06,126 [salt.state       :1951][INFO    ][12383] Completed state [salt-minion] at time 06:15:06.126890 duration_in_ms=69.533
2019-06-07 06:15:06,128 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains.d] at time 06:15:06.128340
2019-06-07 06:15:06,128 [salt.state       :1813][INFO    ][12383] Executing state file.directory for [/etc/salt/grains.d]
2019-06-07 06:15:06,129 [salt.state       :300 ][INFO    ][12383] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-07 06:15:06,129 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains.d] at time 06:15:06.129806 duration_in_ms=1.466
2019-06-07 06:15:06,130 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains] at time 06:15:06.130442
2019-06-07 06:15:06,130 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/grains]
2019-06-07 06:15:06,131 [salt.state       :300 ][INFO    ][12383] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-07 06:15:06,131 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains] at time 06:15:06.131494 duration_in_ms=1.052
2019-06-07 06:15:06,132 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains.d/placeholder] at time 06:15:06.131954
2019-06-07 06:15:06,132 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-07 06:15:06,132 [salt.state       :300 ][INFO    ][12383] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-07 06:15:06,133 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains.d/placeholder] at time 06:15:06.132955 duration_in_ms=1.001
2019-06-07 06:15:06,133 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains.d/sphinx] at time 06:15:06.133393
2019-06-07 06:15:06,133 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-07 06:15:06,148 [salt.state       :300 ][INFO    ][12383] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-07 06:15:06,148 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains.d/sphinx] at time 06:15:06.148729 duration_in_ms=15.336
2019-06-07 06:15:06,151 [salt.state       :1780][INFO    ][12383] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.150953
2019-06-07 06:15:06,151 [salt.state       :1813][INFO    ][12383] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-07 06:15:06,151 [salt.state       :300 ][INFO    ][12383] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:15:06,151 [salt.state       :1951][INFO    ][12383] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.151826 duration_in_ms=0.874
2019-06-07 06:15:06,152 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains.d/dns_records] at time 06:15:06.152298
2019-06-07 06:15:06,152 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-07 06:15:06,166 [salt.state       :300 ][INFO    ][12383] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-07 06:15:06,166 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains.d/dns_records] at time 06:15:06.166511 duration_in_ms=14.213
2019-06-07 06:15:06,167 [salt.state       :1780][INFO    ][12383] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.167437
2019-06-07 06:15:06,167 [salt.state       :1813][INFO    ][12383] 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-07 06:15:06,168 [salt.state       :300 ][INFO    ][12383] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:15:06,168 [salt.state       :1951][INFO    ][12383] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.168321 duration_in_ms=0.884
2019-06-07 06:15:06,168 [salt.state       :1780][INFO    ][12383] Running state [/etc/salt/grains.d/salt] at time 06:15:06.168819
2019-06-07 06:15:06,169 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-07 06:15:06,178 [salt.state       :300 ][INFO    ][12383] File /etc/salt/grains.d/salt is in the correct state
2019-06-07 06:15:06,178 [salt.state       :1951][INFO    ][12383] Completed state [/etc/salt/grains.d/salt] at time 06:15:06.178590 duration_in_ms=9.771
2019-06-07 06:15:06,179 [salt.state       :1780][INFO    ][12383] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.179523
2019-06-07 06:15:06,179 [salt.state       :1813][INFO    ][12383] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-07 06:15:06,180 [salt.state       :300 ][INFO    ][12383] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:15:06,180 [salt.state       :1951][INFO    ][12383] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:15:06.180434 duration_in_ms=0.912
2019-06-07 06:15:06,182 [salt.state       :1780][INFO    ][12383] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:15:06.182395
2019-06-07 06:15:06,182 [salt.state       :1813][INFO    ][12383] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-07 06:15:06,183 [salt.state       :300 ][INFO    ][12383] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-07 06:15:06,183 [salt.state       :1951][INFO    ][12383] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:15:06.183319 duration_in_ms=0.923
2019-06-07 06:15:06,184 [salt.state       :1780][INFO    ][12383] Running state [mine.update] at time 06:15:06.184039
2019-06-07 06:15:06,184 [salt.state       :1813][INFO    ][12383] Executing state module.wait for [mine.update]
2019-06-07 06:15:06,184 [salt.state       :300 ][INFO    ][12383] No changes made for mine.update
2019-06-07 06:15:06,184 [salt.state       :1951][INFO    ][12383] Completed state [mine.update] at time 06:15:06.184896 duration_in_ms=0.856
2019-06-07 06:15:06,185 [salt.state       :1780][INFO    ][12383] Running state [ca-certificates] at time 06:15:06.185153
2019-06-07 06:15:06,185 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [ca-certificates]
2019-06-07 06:15:06,193 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:06,193 [salt.state       :1951][INFO    ][12383] Completed state [ca-certificates] at time 06:15:06.193311 duration_in_ms=8.158
2019-06-07 06:15:06,194 [salt.state       :1780][INFO    ][12383] Running state [update-ca-certificates] at time 06:15:06.194028
2019-06-07 06:15:06,194 [salt.state       :1813][INFO    ][12383] Executing state cmd.wait for [update-ca-certificates]
2019-06-07 06:15:06,194 [salt.state       :300 ][INFO    ][12383] No changes made for update-ca-certificates
2019-06-07 06:15:06,194 [salt.state       :1951][INFO    ][12383] Completed state [update-ca-certificates] at time 06:15:06.194853 duration_in_ms=0.824
2019-06-07 06:15:06,195 [salt.state       :1780][INFO    ][12383] Running state [iptables] at time 06:15:06.195098
2019-06-07 06:15:06,195 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [iptables]
2019-06-07 06:15:06,202 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:06,202 [salt.state       :1951][INFO    ][12383] Completed state [iptables] at time 06:15:06.202517 duration_in_ms=7.419
2019-06-07 06:15:06,202 [salt.state       :1780][INFO    ][12383] Running state [iptables-persistent] at time 06:15:06.202766
2019-06-07 06:15:06,203 [salt.state       :1813][INFO    ][12383] Executing state pkg.installed for [iptables-persistent]
2019-06-07 06:15:06,209 [salt.state       :300 ][INFO    ][12383] All specified packages are already installed
2019-06-07 06:15:06,209 [salt.state       :1951][INFO    ][12383] Completed state [iptables-persistent] at time 06:15:06.209893 duration_in_ms=7.126
2019-06-07 06:15:06,210 [salt.state       :1780][INFO    ][12383] Running state [iptables_modules_v4_load] at time 06:15:06.210887
2019-06-07 06:15:06,211 [salt.state       :1813][INFO    ][12383] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-07 06:15:06,211 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'lsmod' in directory '/root'
2019-06-07 06:15:06,233 [salt.state       :300 ][INFO    ][12383] Kernel modules iptable_filter, ip_tables are already present
2019-06-07 06:15:06,234 [salt.state       :1951][INFO    ][12383] Completed state [iptables_modules_v4_load] at time 06:15:06.233958 duration_in_ms=23.071
2019-06-07 06:15:06,234 [salt.state       :1780][INFO    ][12383] Running state [/etc/iptables/rules.v4] at time 06:15:06.234584
2019-06-07 06:15:06,234 [salt.state       :1813][INFO    ][12383] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-07 06:15:06,310 [salt.state       :300 ][INFO    ][12383] File /etc/iptables/rules.v4 is in the correct state
2019-06-07 06:15:06,310 [salt.state       :1951][INFO    ][12383] Completed state [/etc/iptables/rules.v4] at time 06:15:06.310251 duration_in_ms=75.667
2019-06-07 06:15:06,311 [salt.state       :1780][INFO    ][12383] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:15:06.311017
2019-06-07 06:15:06,311 [salt.state       :1813][INFO    ][12383] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-07 06:15:06,311 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-07 06:15:06,331 [salt.state       :300 ][INFO    ][12383] onlyif execution failed
2019-06-07 06:15:06,331 [salt.state       :1951][INFO    ][12383] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:15:06.331446 duration_in_ms=20.429
2019-06-07 06:15:06,332 [salt.state       :1780][INFO    ][12383] Running state [netfilter-persistent] at time 06:15:06.332169
2019-06-07 06:15:06,332 [salt.state       :1813][INFO    ][12383] Executing state service.running for [netfilter-persistent]
2019-06-07 06:15:06,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:06,351 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-07 06:15:06,367 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-07 06:15:06,383 [salt.state       :300 ][INFO    ][12383] The service netfilter-persistent is already running
2019-06-07 06:15:06,384 [salt.state       :1951][INFO    ][12383] Completed state [netfilter-persistent] at time 06:15:06.384079 duration_in_ms=51.909
2019-06-07 06:15:06,384 [salt.state       :1780][INFO    ][12383] Running state [iptables_extra.remove_stale_tables] at time 06:15:06.384788
2019-06-07 06:15:06,385 [salt.state       :1813][INFO    ][12383] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-07 06:15:06,385 [salt.state       :300 ][INFO    ][12383] No changes made for iptables_extra.remove_stale_tables
2019-06-07 06:15:06,385 [salt.state       :1951][INFO    ][12383] Completed state [iptables_extra.remove_stale_tables] at time 06:15:06.385584 duration_in_ms=0.796
2019-06-07 06:15:06,385 [salt.state       :1780][INFO    ][12383] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:15:06.385804
2019-06-07 06:15:06,386 [salt.state       :1813][INFO    ][12383] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-07 06:15:06,386 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12383] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-07 06:15:06,400 [salt.state       :300 ][INFO    ][12383] onlyif execution failed
2019-06-07 06:15:06,400 [salt.state       :1951][INFO    ][12383] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:15:06.400567 duration_in_ms=14.763
2019-06-07 06:15:06,401 [salt.state       :1780][INFO    ][12383] Running state [/etc/iptables/rules.v6] at time 06:15:06.401522
2019-06-07 06:15:06,401 [salt.state       :1813][INFO    ][12383] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-07 06:15:06,402 [salt.state       :300 ][INFO    ][12383] File /etc/iptables/rules.v6 is not present
2019-06-07 06:15:06,402 [salt.state       :1951][INFO    ][12383] Completed state [/etc/iptables/rules.v6] at time 06:15:06.402552 duration_in_ms=1.03
2019-06-07 06:15:06,403 [salt.state       :1780][INFO    ][12383] Running state [iptables_extra.flush_all] at time 06:15:06.403201
2019-06-07 06:15:06,403 [salt.state       :1813][INFO    ][12383] Executing state module.wait for [iptables_extra.flush_all]
2019-06-07 06:15:06,403 [salt.state       :300 ][INFO    ][12383] No changes made for iptables_extra.flush_all
2019-06-07 06:15:06,404 [salt.state       :1951][INFO    ][12383] Completed state [iptables_extra.flush_all] at time 06:15:06.403998 duration_in_ms=0.798
2019-06-07 06:15:06,406 [salt.minion      :1711][INFO    ][12383] Returning information for job: 20190607061459048182
2019-06-07 06:15:07,032 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607061507019463
2019-06-07 06:15:07,054 [salt.minion      :1432][INFO    ][12477] Starting a new job with PID 12477
2019-06-07 06:15:07,809 [salt.state       :915 ][INFO    ][12477] Loading fresh modules for state activity
2019-06-07 06:15:08,452 [salt.state       :1780][INFO    ][12477] Running state [maas-rack-controller] at time 06:15:08.452341
2019-06-07 06:15:08,452 [salt.state       :1813][INFO    ][12477] Executing state pkg.installed for [maas-rack-controller]
2019-06-07 06:15:08,453 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12477] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:15:08,615 [salt.state       :300 ][INFO    ][12477] All specified packages are already installed
2019-06-07 06:15:08,615 [salt.state       :1951][INFO    ][12477] Completed state [maas-rack-controller] at time 06:15:08.615541 duration_in_ms=163.2
2019-06-07 06:15:08,616 [salt.state       :1780][INFO    ][12477] Running state [ipmitool] at time 06:15:08.615997
2019-06-07 06:15:08,616 [salt.state       :1813][INFO    ][12477] Executing state pkg.installed for [ipmitool]
2019-06-07 06:15:08,624 [salt.state       :300 ][INFO    ][12477] All specified packages are already installed
2019-06-07 06:15:08,624 [salt.state       :1951][INFO    ][12477] Completed state [ipmitool] at time 06:15:08.624448 duration_in_ms=8.451
2019-06-07 06:15:08,628 [salt.state       :1780][INFO    ][12477] Running state [/etc/maas/rackd.conf] at time 06:15:08.628082
2019-06-07 06:15:08,628 [salt.state       :1813][INFO    ][12477] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-07 06:15:08,629 [salt.state       :300 ][INFO    ][12477] No changes needed to be made
2019-06-07 06:15:08,629 [salt.state       :1951][INFO    ][12477] Completed state [/etc/maas/rackd.conf] at time 06:15:08.629802 duration_in_ms=1.72
2019-06-07 06:15:08,630 [salt.state       :1780][INFO    ][12477] Running state [/etc/maas/rackd.conf] at time 06:15:08.630071
2019-06-07 06:15:08,630 [salt.state       :1813][INFO    ][12477] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-07 06:15:08,630 [salt.loaded.int.states.file:2298][WARNING ][12477] 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-07 06:15:08,631 [salt.state       :300 ][INFO    ][12477] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-07 06:15:08,631 [salt.state       :1951][INFO    ][12477] Completed state [/etc/maas/rackd.conf] at time 06:15:08.631412 duration_in_ms=1.341
2019-06-07 06:15:08,632 [salt.state       :1780][INFO    ][12477] Running state [maas-rackd] at time 06:15:08.632420
2019-06-07 06:15:08,632 [salt.state       :1813][INFO    ][12477] Executing state service.running for [maas-rackd]
2019-06-07 06:15:08,633 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12477] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:08,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12477] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-07 06:15:08,680 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12477] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-07 06:15:08,695 [salt.state       :300 ][INFO    ][12477] The service maas-rackd is already running
2019-06-07 06:15:08,695 [salt.state       :1951][INFO    ][12477] Completed state [maas-rackd] at time 06:15:08.695792 duration_in_ms=63.37
2019-06-07 06:15:08,697 [salt.minion      :1711][INFO    ][12477] Returning information for job: 20190607061507019463
2019-06-07 06:15:09,309 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607061509295277
2019-06-07 06:15:09,331 [salt.minion      :1432][INFO    ][12509] Starting a new job with PID 12509
2019-06-07 06:15:10,072 [salt.state       :915 ][INFO    ][12509] Loading fresh modules for state activity
2019-06-07 06:15:10,827 [salt.state       :1780][INFO    ][12509] Running state [maas-region-controller] at time 06:15:10.827199
2019-06-07 06:15:10,827 [salt.state       :1813][INFO    ][12509] Executing state pkg.installed for [maas-region-controller]
2019-06-07 06:15:10,828 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:15:10,916 [salt.state       :300 ][INFO    ][12509] All specified packages are already installed
2019-06-07 06:15:10,917 [salt.state       :1951][INFO    ][12509] Completed state [maas-region-controller] at time 06:15:10.917066 duration_in_ms=89.869
2019-06-07 06:15:10,917 [salt.state       :1780][INFO    ][12509] Running state [python-oauth] at time 06:15:10.917431
2019-06-07 06:15:10,917 [salt.state       :1813][INFO    ][12509] Executing state pkg.installed for [python-oauth]
2019-06-07 06:15:10,924 [salt.state       :300 ][INFO    ][12509] All specified packages are already installed
2019-06-07 06:15:10,924 [salt.state       :1951][INFO    ][12509] Completed state [python-oauth] at time 06:15:10.924497 duration_in_ms=7.066
2019-06-07 06:15:10,927 [salt.state       :1780][INFO    ][12509] Running state [/etc/maas/regiond.conf] at time 06:15:10.927682
2019-06-07 06:15:10,927 [salt.state       :1813][INFO    ][12509] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-07 06:15:10,969 [salt.state       :300 ][INFO    ][12509] No changes needed to be made
2019-06-07 06:15:10,969 [salt.state       :1951][INFO    ][12509] Completed state [/etc/maas/regiond.conf] at time 06:15:10.969640 duration_in_ms=41.957
2019-06-07 06:15:10,970 [salt.state       :1780][INFO    ][12509] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:15:10.970070
2019-06-07 06:15:10,970 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-07 06:15:11,038 [salt.state       :300 ][INFO    ][12509] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-07 06:15:11,040 [salt.state       :1951][INFO    ][12509] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:15:11.039912 duration_in_ms=69.838
2019-06-07 06:15:11,041 [salt.state       :1780][INFO    ][12509] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:15:11.041752
2019-06-07 06:15:11,042 [salt.state       :1813][INFO    ][12509] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-07 06:15:11,061 [salt.state       :300 ][INFO    ][12509] No changes needed to be made
2019-06-07 06:15:11,062 [salt.state       :1951][INFO    ][12509] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:15:11.062118 duration_in_ms=20.366
2019-06-07 06:15:11,062 [salt.state       :1780][INFO    ][12509] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:15:11.062857
2019-06-07 06:15:11,063 [salt.state       :1813][INFO    ][12509] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-07 06:15:11,091 [salt.state       :300 ][INFO    ][12509] No changes needed to be made
2019-06-07 06:15:11,091 [salt.state       :1951][INFO    ][12509] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:15:11.091836 duration_in_ms=28.979
2019-06-07 06:15:11,092 [salt.state       :1780][INFO    ][12509] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:15:11.092642
2019-06-07 06:15:11,093 [salt.state       :1813][INFO    ][12509] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-07 06:15:11,132 [salt.state       :300 ][INFO    ][12509] No changes needed to be made
2019-06-07 06:15:11,133 [salt.state       :1951][INFO    ][12509] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:15:11.132947 duration_in_ms=40.305
2019-06-07 06:15:11,133 [salt.state       :1780][INFO    ][12509] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:15:11.133624
2019-06-07 06:15:11,134 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-07 06:15:11,149 [salt.state       :300 ][INFO    ][12509] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-07 06:15:11,149 [salt.state       :1951][INFO    ][12509] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:15:11.149850 duration_in_ms=16.225
2019-06-07 06:15:11,155 [salt.state       :1780][INFO    ][12509] Running state [a2enmod headers] at time 06:15:11.155217
2019-06-07 06:15:11,155 [salt.state       :1813][INFO    ][12509] Executing state cmd.run for [a2enmod headers]
2019-06-07 06:15:11,156 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command 'a2enmod headers' in directory '/root'
2019-06-07 06:15:11,223 [salt.state       :300 ][INFO    ][12509] {'pid': 12540, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-07 06:15:11,224 [salt.state       :1951][INFO    ][12509] Completed state [a2enmod headers] at time 06:15:11.224092 duration_in_ms=68.875
2019-06-07 06:15:11,224 [salt.state       :1780][INFO    ][12509] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:15:11.224656
2019-06-07 06:15:11,225 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-07 06:15:11,242 [salt.state       :300 ][INFO    ][12509] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-07 06:15:11,242 [salt.state       :1951][INFO    ][12509] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:15:11.242626 duration_in_ms=17.97
2019-06-07 06:15:11,243 [salt.state       :1780][INFO    ][12509] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:15:11.243421
2019-06-07 06:15:11,243 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-07 06:15:11,323 [salt.state       :300 ][INFO    ][12509] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-07 06:15:11,323 [salt.state       :1951][INFO    ][12509] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:15:11.323813 duration_in_ms=80.392
2019-06-07 06:15:11,324 [salt.state       :1780][INFO    ][12509] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:15:11.324506
2019-06-07 06:15:11,324 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-07 06:15:11,383 [salt.state       :300 ][INFO    ][12509] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-07 06:15:11,383 [salt.state       :1951][INFO    ][12509] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:15:11.383422 duration_in_ms=58.916
2019-06-07 06:15:11,384 [salt.state       :1780][INFO    ][12509] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:15:11.383992
2019-06-07 06:15:11,384 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-07 06:15:11,449 [salt.state       :300 ][INFO    ][12509] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-07 06:15:11,449 [salt.state       :1951][INFO    ][12509] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:15:11.449292 duration_in_ms=65.3
2019-06-07 06:15:11,449 [salt.state       :1780][INFO    ][12509] Running state [/root/.pgpass] at time 06:15:11.449539
2019-06-07 06:15:11,449 [salt.state       :1813][INFO    ][12509] Executing state file.managed for [/root/.pgpass]
2019-06-07 06:15:11,490 [salt.state       :300 ][INFO    ][12509] File /root/.pgpass is in the correct state
2019-06-07 06:15:11,490 [salt.state       :1951][INFO    ][12509] Completed state [/root/.pgpass] at time 06:15:11.490920 duration_in_ms=41.38
2019-06-07 06:15:11,494 [salt.state       :1780][INFO    ][12509] Running state [maas-region syncdb --noinput] at time 06:15:11.494766
2019-06-07 06:15:11,495 [salt.state       :1813][INFO    ][12509] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-07 06:15:11,495 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-07 06:15:13,302 [salt.state       :300 ][INFO    ][12509] {'pid': 12555, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, metadataserver, piston3, contenttypes, sites, auth, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-07 06:15:13,303 [salt.state       :1951][INFO    ][12509] Completed state [maas-region syncdb --noinput] at time 06:15:13.303112 duration_in_ms=1808.345
2019-06-07 06:15:13,303 [salt.state       :2022][WARNING ][12509] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-07 06:15:13,306 [salt.state       :1780][INFO    ][12509] Running state [maas-regiond] at time 06:15:13.306802
2019-06-07 06:15:13,307 [salt.state       :1813][INFO    ][12509] Executing state service.running for [maas-regiond]
2019-06-07 06:15:13,309 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:13,346 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-07 06:15:13,364 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-07 06:15:13,381 [salt.state       :300 ][INFO    ][12509] The service maas-regiond is already running
2019-06-07 06:15:13,382 [salt.state       :1951][INFO    ][12509] Completed state [maas-regiond] at time 06:15:13.382132 duration_in_ms=75.331
2019-06-07 06:15:13,384 [salt.state       :1780][INFO    ][12509] Running state [bind9] at time 06:15:13.384674
2019-06-07 06:15:13,385 [salt.state       :1813][INFO    ][12509] Executing state service.running for [bind9]
2019-06-07 06:15:13,386 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:13,404 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-07 06:15:13,421 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-07 06:15:13,438 [salt.state       :300 ][INFO    ][12509] The service bind9 is already running
2019-06-07 06:15:13,439 [salt.state       :1951][INFO    ][12509] Completed state [bind9] at time 06:15:13.438982 duration_in_ms=54.307
2019-06-07 06:15:13,441 [salt.state       :1780][INFO    ][12509] Running state [apache2] at time 06:15:13.441519
2019-06-07 06:15:13,442 [salt.state       :1813][INFO    ][12509] Executing state service.running for [apache2]
2019-06-07 06:15:13,443 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-07 06:15:13,461 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-07 06:15:13,478 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-07 06:15:13,498 [salt.state       :300 ][INFO    ][12509] The service apache2 is already running
2019-06-07 06:15:13,499 [salt.state       :1951][INFO    ][12509] Completed state [apache2] at time 06:15:13.499119 duration_in_ms=57.6
2019-06-07 06:15:13,501 [salt.state       :1780][INFO    ][12509] Running state [maasng.wait_for_http_code] at time 06:15:13.501594
2019-06-07 06:15:13,502 [salt.state       :1813][INFO    ][12509] Executing state module.run for [maasng.wait_for_http_code]
2019-06-07 06:15:13,502 [salt.utils.decorators:613 ][WARNING ][12509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:13,511 [salt.state       :300 ][INFO    ][12509] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-07 06:15:13,512 [salt.state       :1951][INFO    ][12509] Completed state [maasng.wait_for_http_code] at time 06:15:13.512058 duration_in_ms=10.464
2019-06-07 06:15:13,513 [salt.state       :1780][INFO    ][12509] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:15:13.513184
2019-06-07 06:15:13,513 [salt.state       :1813][INFO    ][12509] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-07 06:15:13,514 [salt.state       :300 ][INFO    ][12509] /var/lib/maas/.setup_admin exists
2019-06-07 06:15:13,514 [salt.state       :1951][INFO    ][12509] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:15:13.514589 duration_in_ms=1.404
2019-06-07 06:15:13,515 [salt.state       :1780][INFO    ][12509] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:13.515600
2019-06-07 06:15:13,516 [salt.state       :1813][INFO    ][12509] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:15:13,516 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12509] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:15:14,947 [salt.state       :300 ][INFO    ][12509] {'pid': 12583, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:15:14,947 [salt.state       :1951][INFO    ][12509] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:14.947854 duration_in_ms=1432.253
2019-06-07 06:15:14,951 [salt.state       :1780][INFO    ][12509] Running state [maas_region_boot_source_resources_mirror] at time 06:15:14.951565
2019-06-07 06:15:14,951 [salt.state       :1813][INFO    ][12509] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-07 06:15:15,047 [salt.state       :300 ][INFO    ][12509] {'changes': {}}
2019-06-07 06:15:15,047 [salt.state       :1951][INFO    ][12509] Completed state [maas_region_boot_source_resources_mirror] at time 06:15:15.047859 duration_in_ms=96.294
2019-06-07 06:15:15,048 [salt.state       :1780][INFO    ][12509] Running state [maasng.boot_resources_import] at time 06:15:15.048393
2019-06-07 06:15:15,048 [salt.state       :1813][INFO    ][12509] Executing state module.run for [maasng.boot_resources_import]
2019-06-07 06:15:15,049 [salt.utils.decorators:613 ][WARNING ][12509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:15,149 [salt.loaded.ext.module.maasng:1600][INFO    ][12509] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-07 06:15:20,221 [salt.loaded.ext.module.maasng:1600][INFO    ][12509] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-07 06:15:24,348 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061524341676
2019-06-07 06:15:24,361 [salt.minion      :1432][INFO    ][12795] Starting a new job with PID 12795
2019-06-07 06:15:24,374 [salt.minion      :1711][INFO    ][12795] Returning information for job: 20190607061524341676
2019-06-07 06:15:25,276 [salt.loaded.ext.module.maasng:1600][INFO    ][12509] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-07 06:15:30,379 [salt.state       :300 ][INFO    ][12509] {'ret': True}
2019-06-07 06:15:30,380 [salt.state       :1951][INFO    ][12509] Completed state [maasng.boot_resources_import] at time 06:15:30.380176 duration_in_ms=15331.781
2019-06-07 06:15:30,381 [salt.state       :1780][INFO    ][12509] Running state [maas_region_boot_sources_selection_xenial] at time 06:15:30.381395
2019-06-07 06:15:30,381 [salt.state       :1813][INFO    ][12509] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-07 06:15:30,564 [salt.state       :300 ][INFO    ][12509] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-07 06:15:30,564 [salt.state       :1951][INFO    ][12509] Completed state [maas_region_boot_sources_selection_xenial] at time 06:15:30.564745 duration_in_ms=183.35
2019-06-07 06:15:30,566 [salt.state       :1780][INFO    ][12509] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:15:30.566140
2019-06-07 06:15:30,566 [salt.state       :1813][INFO    ][12509] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-07 06:15:30,567 [salt.utils.decorators:613 ][WARNING ][12509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:30,567 [salt.loaded.ext.module.maasng:1771][INFO    ][12509] boot-sources sync initiated for ALL Rack's
2019-06-07 06:15:31,501 [salt.state       :300 ][INFO    ][12509] {'ret': True}
2019-06-07 06:15:31,502 [salt.state       :1951][INFO    ][12509] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:15:31.502041 duration_in_ms=935.9
2019-06-07 06:15:31,504 [salt.state       :1780][INFO    ][12509] Running state [maas.process_maas_config] at time 06:15:31.504025
2019-06-07 06:15:31,504 [salt.state       :1813][INFO    ][12509] Executing state module.run for [maas.process_maas_config]
2019-06-07 06:15:31,505 [salt.utils.decorators:613 ][WARNING ][12509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:31,505 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=enable_http_proxy value=True
2019-06-07 06:15:31,554 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=upstream_dns value=8.8.8.8
2019-06-07 06:15:31,622 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=commissioning_distro_series value=xenial
2019-06-07 06:15:31,687 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=default_osystem value=ubuntu
2019-06-07 06:15:31,740 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=active_discovery_interval value=600
2019-06-07 06:15:31,788 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=dnssec_validation value=no
2019-06-07 06:15:31,836 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=maas_name value=mas01
2019-06-07 06:15:31,897 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=network_discovery value=enabled
2019-06-07 06:15:31,992 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=enable_third_party_drivers value=True
2019-06-07 06:15:32,034 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=default_storage_layout value=lvm
2019-06-07 06:15:32,076 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=ntp_external_only value=True
2019-06-07 06:15:32,131 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-07 06:15:32,177 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=default_distro_series value=xenial
2019-06-07 06:15:32,244 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-07 06:15:32,358 [salt.state       :300 ][INFO    ][12509] {'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-07 06:15:32,358 [salt.state       :1951][INFO    ][12509] Completed state [maas.process_maas_config] at time 06:15:32.358440 duration_in_ms=854.414
2019-06-07 06:15:32,359 [salt.state       :1780][INFO    ][12509] Running state [pxe_admin] at time 06:15:32.359358
2019-06-07 06:15:32,359 [salt.state       :1813][INFO    ][12509] Executing state maasng.fabric_present for [pxe_admin]
2019-06-07 06:15:32,423 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'primary_rack': u'rgq6cx', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-07 06:15:34,664 [salt.loaded.ext.module.maasng:1008][WARNING ][12509] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-07 06:15:34,664 [salt.loaded.ext.module.maasng:1011][WARNING ][12509] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-07 06:15:34,735 [salt.state       :300 ][INFO    ][12509] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-07 06:15:34,736 [salt.state       :1951][INFO    ][12509] Completed state [pxe_admin] at time 06:15:34.735924 duration_in_ms=2376.566
2019-06-07 06:15:34,736 [salt.state       :1780][INFO    ][12509] Running state [vlan 0] at time 06:15:34.736335
2019-06-07 06:15:34,736 [salt.state       :1813][INFO    ][12509] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-07 06:15:34,801 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'class_type': None, 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'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'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'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'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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-07 06:15:34,939 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'class_type': None, 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'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'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'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'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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-07 06:15:35,223 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'primary_rack': u'rgq6cx', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-07 06:15:35,307 [salt.state       :300 ][INFO    ][12509] {'new': 'Vlan untagged was updated'}
2019-06-07 06:15:35,308 [salt.state       :1951][INFO    ][12509] Completed state [vlan 0] at time 06:15:35.308064 duration_in_ms=571.728
2019-06-07 06:15:35,309 [salt.state       :1780][INFO    ][12509] Running state [192.168.11.0/24] at time 06:15:35.309246
2019-06-07 06:15:35,309 [salt.state       :1813][INFO    ][12509] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-07 06:15:35,511 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:15:35,512 [salt.loaded.ext.module.maasng:1235][WARNING ][12509] Ignoring parameter vlan:0
2019-06-07 06:15:35,598 [salt.state       :300 ][INFO    ][12509] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-07 06:15:35,598 [salt.state       :1951][INFO    ][12509] Completed state [192.168.11.0/24] at time 06:15:35.598780 duration_in_ms=289.533
2019-06-07 06:15:35,600 [salt.state       :1780][INFO    ][12509] Running state [maas_create_iprange_1] at time 06:15:35.600110
2019-06-07 06:15:35,600 [salt.state       :1813][INFO    ][12509] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-07 06:15:35,657 [salt.state       :300 ][INFO    ][12509] Iprange maas_create_iprange_1 already exist.
2019-06-07 06:15:35,658 [salt.state       :1951][INFO    ][12509] Completed state [maas_create_iprange_1] at time 06:15:35.658136 duration_in_ms=58.026
2019-06-07 06:15:35,658 [salt.state       :1780][INFO    ][12509] Running state [vlan 0] at time 06:15:35.658576
2019-06-07 06:15:35,659 [salt.state       :1813][INFO    ][12509] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-07 06:15:35,723 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-07 06:15:35,843 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'class_type': None, 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'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'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'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'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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-07 06:15:36,080 [salt.loaded.ext.module.maasng:945 ][INFO    ][12509] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-07 06:15:36,171 [salt.state       :300 ][INFO    ][12509] {'new': 'Vlan untagged was updated'}
2019-06-07 06:15:36,171 [salt.state       :1951][INFO    ][12509] Completed state [vlan 0] at time 06:15:36.171623 duration_in_ms=513.046
2019-06-07 06:15:36,172 [salt.state       :1780][INFO    ][12509] Running state [opnfv] at time 06:15:36.172734
2019-06-07 06:15:36,173 [salt.state       :1813][INFO    ][12509] Executing state maasng.sshkey_present for [opnfv]
2019-06-07 06:15:36,220 [salt.loaded.ext.module.maasng:1903][INFO    ][12509] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-06-07 06:15:36,221 [salt.state       :300 ][INFO    ][12509] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-07 06:15:36,221 [salt.state       :1951][INFO    ][12509] Completed state [opnfv] at time 06:15:36.221839 duration_in_ms=49.105
2019-06-07 06:15:36,222 [salt.state       :1780][INFO    ][12509] Running state [maas.process_tags] at time 06:15:36.222902
2019-06-07 06:15:36,223 [salt.state       :1813][INFO    ][12509] Executing state module.run for [maas.process_tags]
2019-06-07 06:15:36,223 [salt.utils.decorators:613 ][WARNING ][12509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:36,269 [salt.loaded.ext.module.maas:92  ][INFO    ][12509] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-07 06:15:36,329 [salt.state       :300 ][INFO    ][12509] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-07 06:15:36,329 [salt.state       :1951][INFO    ][12509] Completed state [maas.process_tags] at time 06:15:36.329891 duration_in_ms=106.985
2019-06-07 06:15:36,334 [salt.minion      :1711][INFO    ][12509] Returning information for job: 20190607061509295277
2019-06-07 06:15:36,830 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607061536818244
2019-06-07 06:15:36,848 [salt.minion      :1432][INFO    ][13191] Starting a new job with PID 13191
2019-06-07 06:15:40,572 [salt.state       :915 ][INFO    ][13191] Loading fresh modules for state activity
2019-06-07 06:15:40,664 [salt.state       :1780][INFO    ][13191] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:40.664632
2019-06-07 06:15:40,665 [salt.state       :1813][INFO    ][13191] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:15:40,667 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13191] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:15:42,081 [salt.state       :300 ][INFO    ][13191] {'pid': 13215, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:15:42,082 [salt.state       :1951][INFO    ][13191] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:42.082350 duration_in_ms=1417.717
2019-06-07 06:15:42,084 [salt.state       :1780][INFO    ][13191] Running state [maas.process_machines] at time 06:15:42.084902
2019-06-07 06:15:42,085 [salt.state       :1813][INFO    ][13191] Executing state module.run for [maas.process_machines]
2019-06-07 06:15:42,086 [salt.utils.decorators:613 ][WARNING ][13191] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:15:42,401 [salt.loaded.ext.module.maas:412 ][WARNING ][13191] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:15:42,402 [salt.loaded.ext.module.maas:92  ][INFO    ][13191] 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=chwarn architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:15:43,420 [salt.loaded.ext.module.maas:412 ][WARNING ][13191] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:15:43,421 [salt.loaded.ext.module.maas:92  ][INFO    ][13191] 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=p43xbs architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:15:44,385 [salt.loaded.ext.module.maas:412 ][WARNING ][13191] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:15:44,386 [salt.loaded.ext.module.maas:92  ][INFO    ][13191] 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=phscb6 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:15:45,438 [salt.loaded.ext.module.maas:412 ][WARNING ][13191] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:15:45,439 [salt.loaded.ext.module.maas:92  ][INFO    ][13191] 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=7hpy64 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:15:46,382 [salt.loaded.ext.module.maas:412 ][WARNING ][13191] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:15:46,383 [salt.loaded.ext.module.maas:92  ][INFO    ][13191] 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=rf4b8n architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:15:47,400 [salt.state       :300 ][INFO    ][13191] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-07 06:15:47,401 [salt.state       :1951][INFO    ][13191] Completed state [maas.process_machines] at time 06:15:47.401327 duration_in_ms=5316.423
2019-06-07 06:15:47,405 [salt.minion      :1711][INFO    ][13191] Returning information for job: 20190607061536818244
2019-06-07 06:16:18,560 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607061618546902
2019-06-07 06:16:18,582 [salt.minion      :1432][INFO    ][13567] Starting a new job with PID 13567
2019-06-07 06:16:22,338 [salt.state       :915 ][INFO    ][13567] Loading fresh modules for state activity
2019-06-07 06:16:22,422 [salt.state       :1780][INFO    ][13567] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:22.422696
2019-06-07 06:16:22,423 [salt.state       :1813][INFO    ][13567] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:16:22,425 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13567] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:16:24,176 [salt.state       :300 ][INFO    ][13567] {'pid': 13574, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:16:24,177 [salt.state       :1951][INFO    ][13567] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:24.177359 duration_in_ms=1754.664
2019-06-07 06:16:24,178 [salt.state       :1780][INFO    ][13567] Running state [maas.wait_for_machine_status] at time 06:16:24.178573
2019-06-07 06:16:24,178 [salt.state       :1813][INFO    ][13567] Executing state module.run for [maas.wait_for_machine_status]
2019-06-07 06:16:24,179 [salt.utils.decorators:613 ][WARNING ][13567] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:16:26,750 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1497.43330002s left)
2019-06-07 06:16:33,630 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061633617003
2019-06-07 06:16:33,653 [salt.minion      :1432][INFO    ][13635] Starting a new job with PID 13635
2019-06-07 06:16:33,677 [salt.minion      :1711][INFO    ][13635] Returning information for job: 20190607061633617003
2019-06-07 06:16:59,751 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1464.43282413s left)
2019-06-07 06:17:03,684 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061703671470
2019-06-07 06:17:03,707 [salt.minion      :1432][INFO    ][13665] Starting a new job with PID 13665
2019-06-07 06:17:03,730 [salt.minion      :1711][INFO    ][13665] Returning information for job: 20190607061703671470
2019-06-07 06:17:31,024 [salt.loaded.ext.module.maas:981 ][INFO    ][13567] Machine p43xbs deleted
2019-06-07 06:17:31,859 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:31,860 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=chwarn architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:32,798 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:32,799 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] machine hostname=cmp001 power_type=ipmi mac_addresses=00:25:b5:a0:00:5a power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:33,730 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061733718214
2019-06-07 06:17:33,752 [salt.minion      :1432][INFO    ][13829] Starting a new job with PID 13829
2019-06-07 06:17:33,767 [salt.minion      :1711][INFO    ][13829] Returning information for job: 20190607061733718214
2019-06-07 06:17:34,283 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:34,283 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=phscb6 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:35,409 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:35,410 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=7hpy64 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:36,384 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:36,385 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=rf4b8n architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:38,626 [salt.loaded.ext.module.maas:981 ][INFO    ][13567] Machine 7hpy64 deleted
2019-06-07 06:17:39,446 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:39,446 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=chwarn architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:40,546 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:40,546 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=fsw73e architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:41,270 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:41,271 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=phscb6 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:42,426 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:42,427 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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-07 06:17:43,867 [salt.loaded.ext.module.maas:412 ][WARNING ][13567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:17:43,868 [salt.loaded.ext.module.maas:92  ][INFO    ][13567] 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=rf4b8n architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:17:45,649 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1418.53481507s left)
2019-06-07 06:18:03,774 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061803761542
2019-06-07 06:18:03,796 [salt.minion      :1432][INFO    ][14225] Starting a new job with PID 14225
2019-06-07 06:18:03,820 [salt.minion      :1711][INFO    ][14225] Returning information for job: 20190607061803761542
2019-06-07 06:18:18,101 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1386.08285093s left)
2019-06-07 06:18:33,821 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061833808603
2019-06-07 06:18:33,844 [salt.minion      :1432][INFO    ][14293] Starting a new job with PID 14293
2019-06-07 06:18:33,869 [salt.minion      :1711][INFO    ][14293] Returning information for job: 20190607061833808603
2019-06-07 06:18:50,660 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1353.52334595s left)
2019-06-07 06:19:03,874 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061903861580
2019-06-07 06:19:03,897 [salt.minion      :1432][INFO    ][14333] Starting a new job with PID 14333
2019-06-07 06:19:03,920 [salt.minion      :1711][INFO    ][14333] Returning information for job: 20190607061903861580
2019-06-07 06:19:22,522 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1321.66141295s left)
2019-06-07 06:19:33,904 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607061933898249
2019-06-07 06:19:33,925 [salt.minion      :1432][INFO    ][14446] Starting a new job with PID 14446
2019-06-07 06:19:33,948 [salt.minion      :1711][INFO    ][14446] Returning information for job: 20190607061933898249
2019-06-07 06:19:54,924 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1289.25980997s left)
2019-06-07 06:20:03,957 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062003944811
2019-06-07 06:20:03,978 [salt.minion      :1432][INFO    ][14490] Starting a new job with PID 14490
2019-06-07 06:20:04,000 [salt.minion      :1711][INFO    ][14490] Returning information for job: 20190607062003944811
2019-06-07 06:20:27,127 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1257.05640411s left)
2019-06-07 06:20:34,020 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062034007255
2019-06-07 06:20:34,043 [salt.minion      :1432][INFO    ][14830] Starting a new job with PID 14830
2019-06-07 06:20:34,067 [salt.minion      :1711][INFO    ][14830] Returning information for job: 20190607062034007255
2019-06-07 06:20:59,655 [salt.loaded.ext.module.maas:1023][INFO    ][13567] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:1500s (1224.52863097s left)
2019-06-07 06:21:04,089 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062104076149
2019-06-07 06:21:04,111 [salt.minion      :1432][INFO    ][14850] Starting a new job with PID 14850
2019-06-07 06:21:04,134 [salt.minion      :1711][INFO    ][14850] Returning information for job: 20190607062104076149
2019-06-07 06:21:32,862 [salt.state       :300 ][INFO    ][13567] {'ret': True}
2019-06-07 06:21:32,862 [salt.state       :1951][INFO    ][13567] Completed state [maas.wait_for_machine_status] at time 06:21:32.862792 duration_in_ms=308684.217
2019-06-07 06:21:32,866 [salt.minion      :1711][INFO    ][13567] Returning information for job: 20190607061618546902
2019-06-07 06:21:33,518 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607062133505328
2019-06-07 06:21:33,541 [salt.minion      :1432][INFO    ][14968] Starting a new job with PID 14968
2019-06-07 06:21:37,231 [salt.state       :915 ][INFO    ][14968] Loading fresh modules for state activity
2019-06-07 06:21:37,284 [salt.fileclient  :1219][INFO    ][14968] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-07 06:21:37,370 [salt.state       :1780][INFO    ][14968] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:37.370149
2019-06-07 06:21:37,370 [salt.state       :1813][INFO    ][14968] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:21:37,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14968] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:21:38,873 [salt.state       :300 ][INFO    ][14968] {'pid': 14975, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:21:38,873 [salt.state       :1951][INFO    ][14968] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:38.873802 duration_in_ms=1503.652
2019-06-07 06:21:38,876 [salt.state       :1780][INFO    ][14968] Running state [maas_machines_storage_cmp002_lvm] at time 06:21:38.876838
2019-06-07 06:21:38,877 [salt.state       :1813][INFO    ][14968] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-07 06:21:39,915 [salt.loaded.ext.module.maasng:610 ][INFO    ][14968] chwarn
2019-06-07 06:21:39,916 [salt.loaded.ext.module.maasng:626 ][INFO    ][14968] sda
2019-06-07 06:21:40,586 [salt.loaded.ext.module.maasng:361 ][INFO    ][14968] chwarn
2019-06-07 06:21:40,719 [salt.loaded.ext.module.maasng:367 ][INFO    ][14968] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'chwarn', u'partition_table_type': u'GPT', u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'9ac2f552-1cc8-4a1d-adbe-02dd5f011d70', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'chwarn', u'device_id': 1, u'filesystem': {u'uuid': u'91d2d6f0-9a87-46b3-af8a-e4c2698078d5', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'size': 2397992648704}], u'type': u'physical', u'id': 1, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'filesystem': {u'uuid': u'911bae9c-41f7-4eac-b731-925bcddcd810', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'0a09e829-14e8-447e-9306-7ac1ab09f69a', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'chwarn', u'partition_table_type': None, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/4/', u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 4, u'size': 2397988454400}]
2019-06-07 06:21:40,719 [salt.loaded.ext.module.maasng:632 ][INFO    ][14968] vgroot
2019-06-07 06:21:40,720 [salt.loaded.ext.module.maasng:635 ][INFO    ][14968] lvroot
2019-06-07 06:21:40,720 [salt.loaded.ext.module.maasng:639 ][INFO    ][14968] 107374182400
2019-06-07 06:21:41,420 [salt.loaded.ext.module.maasng:645 ][INFO    ][14968] {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'ip_addresses': [], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'chwarn', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/interfaces/4/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'partitions': [{u'uuid': u'28d6c9b6-155c-413e-a3fb-590459c78501', u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'chwarn', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'62dcb92e-4ae3-43c6-b732-241c900b9078', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'chwarn', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/', u'name': u'sda'}, u'fqdn': u'cmp002.maas', u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'disable_ipv4': False, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'chwarn', 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'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'partitions': [{u'uuid': u'28d6c9b6-155c-413e-a3fb-590459c78501', u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'chwarn', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'62dcb92e-4ae3-43c6-b732-241c900b9078', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'chwarn', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/', u'name': u'sda'}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'filesystem': None, u'partitions': [{u'uuid': u'28d6c9b6-155c-413e-a3fb-590459c78501', u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'chwarn', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'62dcb92e-4ae3-43c6-b732-241c900b9078', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'chwarn', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/1/', u'name': u'sda'}, {u'size': 107374182400, u'model': None, u'uuid': u'59f798e7-2ed2-441f-b5b7-912ce1a38d98', u'tags': [], u'type': u'virtual', u'id': 11, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'58482f05-390d-45b8-a981-95fcfcd4f6bb', u'fstype': u'ext4', u'label': u'root'}, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'chwarn', 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'used_size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/11/', u'name': u'vgroot-lvroot'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'chwarn', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'current_commissioning_result_id': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'available_size': 0, u'uuid': u'59f798e7-2ed2-441f-b5b7-912ce1a38d98', u'tags': [], u'type': u'virtual', u'id': 11, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'chwarn', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'58482f05-390d-45b8-a981-95fcfcd4f6bb', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/blockdevices/11/', u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'chwarn', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/interfaces/4/'}, {u'name': u'enp8s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 9, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'chwarn', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/interfaces/9/'}, {u'name': u'enp7s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 10, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'chwarn', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/interfaces/10/'}, {u'name': u'enp9s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'chwarn', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/chwarn/interfaces/11/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/chwarn/'}
2019-06-07 06:21:41,422 [salt.state       :300 ][INFO    ][14968] {'new': {'storage_layout': 'lvm'}}
2019-06-07 06:21:41,423 [salt.state       :1951][INFO    ][14968] Completed state [maas_machines_storage_cmp002_lvm] at time 06:21:41.423078 duration_in_ms=2546.239
2019-06-07 06:21:41,423 [salt.state       :1780][INFO    ][14968] Running state [maas_machines_storage_cmp001_lvm] at time 06:21:41.423612
2019-06-07 06:21:41,424 [salt.state       :1813][INFO    ][14968] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-07 06:21:42,730 [salt.loaded.ext.module.maasng:610 ][INFO    ][14968] fsw73e
2019-06-07 06:21:42,730 [salt.loaded.ext.module.maasng:626 ][INFO    ][14968] sda
2019-06-07 06:21:43,371 [salt.loaded.ext.module.maasng:361 ][INFO    ][14968] fsw73e
2019-06-07 06:21:43,491 [salt.loaded.ext.module.maasng:367 ][INFO    ][14968] [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'c41cdfe5-5324-432c-8028-8e9dfcd13d21', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsw73e', u'device_id': 7, u'filesystem': {u'uuid': u'7bfd7f72-63d5-4c4f-a0ce-71db84c7a1f6', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/partition/4', u'type': u'partition', u'id': 4, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'fsw73e', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/'}, {u'size': 2397988454400, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 9, u'partitions': [], u'uuid': u'1169d0b7-ee7c-4366-baa8-67d249811f23', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'fsw73e', u'partition_table_type': None, u'filesystem': {u'uuid': u'1b3deb7f-16b1-4e33-8d6a-8fa0ad50aa4e', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/9/'}]
2019-06-07 06:21:43,492 [salt.loaded.ext.module.maasng:632 ][INFO    ][14968] vgroot
2019-06-07 06:21:43,492 [salt.loaded.ext.module.maasng:635 ][INFO    ][14968] lvroot
2019-06-07 06:21:43,492 [salt.loaded.ext.module.maasng:639 ][INFO    ][14968] 107374182400
2019-06-07 06:21:44,205 [salt.loaded.ext.module.maasng:645 ][INFO    ][14968] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', 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/fsw73e/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'fsw73e', 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'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'0fdaa054-3b19-4a7b-ad61-97ed6bbb2dd0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsw73e', u'device_id': 7, u'filesystem': {u'uuid': u'8caba33c-c2ad-4b74-a530-190b3bc4b648', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'fsw73e', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/'}, {u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 12, u'partitions': [], u'uuid': u'0098d3c8-5872-45b1-812f-1f8aa4c00d61', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'fsw73e', u'partition_table_type': None, u'filesystem': {u'uuid': u'8057ee51-413b-41a0-95e4-c8a0e186d1db', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/12/'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'0fdaa054-3b19-4a7b-ad61-97ed6bbb2dd0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsw73e', u'device_id': 7, u'filesystem': {u'uuid': u'8caba33c-c2ad-4b74-a530-190b3bc4b648', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'fsw73e', u'partition_table_type': u'GPT', u'filesystem': None, u'id': 7, u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/'}], u'ip_addresses': [u'192.168.11.38'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'fsw73e', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 37}], u'tags': [], u'vlan': {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'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 18, 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'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'fsw73e', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/interfaces/18/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 37}], u'tags': [], u'vlan': {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'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 18, 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'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'fsw73e', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/interfaces/18/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 39}], u'tags': [], u'vlan': {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'enabled': True, u'effective_mtu': 1500, u'id': 21, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'fsw73e', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/interfaces/21/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 41}], u'tags': [], u'vlan': {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'enabled': True, u'effective_mtu': 1500, u'id': 23, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'fsw73e', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/interfaces/23/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 42}], u'tags': [], u'vlan': {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'enabled': True, u'effective_mtu': 1500, u'id': 25, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'fsw73e', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/interfaces/25/'}], u'current_testing_result_id': 13, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'0098d3c8-5872-45b1-812f-1f8aa4c00d61', u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'fsw73e', u'partition_table_type': None, u'filesystem': {u'uuid': u'8057ee51-413b-41a0-95e4-c8a0e186d1db', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 12, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/12/'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'boot_disk': {u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'0fdaa054-3b19-4a7b-ad61-97ed6bbb2dd0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsw73e', u'device_id': 7, u'filesystem': {u'uuid': u'8caba33c-c2ad-4b74-a530-190b3bc4b648', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'fsw73e', u'partition_table_type': u'GPT', u'filesystem': None, u'id': 7, u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fsw73e/blockdevices/7/'}, u'current_commissioning_result_id': 12, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-06-07 06:21:44,208 [salt.state       :300 ][INFO    ][14968] {'new': {'storage_layout': 'lvm'}}
2019-06-07 06:21:44,208 [salt.state       :1951][INFO    ][14968] Completed state [maas_machines_storage_cmp001_lvm] at time 06:21:44.208349 duration_in_ms=2784.736
2019-06-07 06:21:44,212 [salt.minion      :1711][INFO    ][14968] Returning information for job: 20190607062133505328
2019-06-07 06:21:44,853 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607062144840144
2019-06-07 06:21:44,876 [salt.minion      :1432][INFO    ][15010] Starting a new job with PID 15010
2019-06-07 06:21:45,628 [salt.state       :915 ][INFO    ][15010] Loading fresh modules for state activity
2019-06-07 06:21:45,679 [salt.fileclient  :1219][INFO    ][15010] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-07 06:21:45,719 [salt.state       :1780][INFO    ][15010] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:45.719441
2019-06-07 06:21:45,719 [salt.state       :1813][INFO    ][15010] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:21:45,721 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15010] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:21:47,258 [salt.state       :300 ][INFO    ][15010] {'pid': 15017, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:21:47,259 [salt.state       :1951][INFO    ][15010] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:47.259600 duration_in_ms=1540.158
2019-06-07 06:21:47,262 [salt.state       :1780][INFO    ][15010] Running state [maas.deploy_machines] at time 06:21:47.261981
2019-06-07 06:21:47,262 [salt.state       :1813][INFO    ][15010] Executing state module.run for [maas.deploy_machines]
2019-06-07 06:21:47,263 [salt.utils.decorators:613 ][WARNING ][15010] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:21:47,920 [salt.loaded.ext.module.maas:684 ][INFO    ][15010] deploymachines hwe_kernel=hwe-16.04 system_id=chwarn distro_series=xenial
2019-06-07 06:21:50,559 [salt.loaded.ext.module.maas:684 ][INFO    ][15010] deploymachines hwe_kernel=hwe-16.04 system_id=fsw73e distro_series=xenial
2019-06-07 06:21:53,283 [salt.loaded.ext.module.maas:684 ][INFO    ][15010] deploymachines hwe_kernel=hwe-16.04 system_id=phscb6 distro_series=xenial
2019-06-07 06:21:55,338 [salt.loaded.ext.module.maas:684 ][INFO    ][15010] deploymachines hwe_kernel=hwe-16.04 system_id=n8ks6p distro_series=xenial
2019-06-07 06:21:57,758 [salt.loaded.ext.module.maas:684 ][INFO    ][15010] deploymachines hwe_kernel=hwe-16.04 system_id=rf4b8n distro_series=xenial
2019-06-07 06:21:59,900 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062159888066
2019-06-07 06:21:59,922 [salt.minion      :1432][INFO    ][15286] Starting a new job with PID 15286
2019-06-07 06:21:59,942 [salt.minion      :1711][INFO    ][15286] Returning information for job: 20190607062159888066
2019-06-07 06:22:00,106 [salt.state       :300 ][INFO    ][15010] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-07 06:22:00,107 [salt.state       :1951][INFO    ][15010] Completed state [maas.deploy_machines] at time 06:22:00.106925 duration_in_ms=12844.943
2019-06-07 06:22:00,110 [salt.minion      :1711][INFO    ][15010] Returning information for job: 20190607062144840144
2019-06-07 06:22:00,744 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607062200731448
2019-06-07 06:22:00,765 [salt.minion      :1432][INFO    ][15301] Starting a new job with PID 15301
2019-06-07 06:22:04,580 [salt.state       :915 ][INFO    ][15301] Loading fresh modules for state activity
2019-06-07 06:22:04,632 [salt.fileclient  :1219][INFO    ][15301] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-07 06:22:04,672 [salt.state       :1780][INFO    ][15301] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:22:04.672913
2019-06-07 06:22:04,673 [salt.state       :1813][INFO    ][15301] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:22:04,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15301] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:22:06,001 [salt.state       :300 ][INFO    ][15301] {'pid': 15315, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:22:06,001 [salt.state       :1951][INFO    ][15301] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:22:06.001865 duration_in_ms=1328.952
2019-06-07 06:22:06,003 [salt.state       :1780][INFO    ][15301] Running state [maas.wait_for_machine_status] at time 06:22:06.003239
2019-06-07 06:22:06,003 [salt.state       :1813][INFO    ][15301] Executing state module.run for [maas.wait_for_machine_status]
2019-06-07 06:22:06,003 [salt.utils.decorators:613 ][WARNING ][15301] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:22:09,222 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.78571892s left)
2019-06-07 06:22:15,864 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062215851324
2019-06-07 06:22:15,887 [salt.minion      :1432][INFO    ][15327] Starting a new job with PID 15327
2019-06-07 06:22:15,911 [salt.minion      :1711][INFO    ][15327] Returning information for job: 20190607062215851324
2019-06-07 06:22:42,581 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.42692304s left)
2019-06-07 06:22:45,919 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062245906552
2019-06-07 06:22:45,941 [salt.minion      :1432][INFO    ][15381] Starting a new job with PID 15381
2019-06-07 06:22:45,965 [salt.minion      :1711][INFO    ][15381] Returning information for job: 20190607062245906552
2019-06-07 06:23:15,828 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.17982507s left)
2019-06-07 06:23:15,960 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062315947057
2019-06-07 06:23:15,983 [salt.minion      :1432][INFO    ][15401] Starting a new job with PID 15401
2019-06-07 06:23:16,008 [salt.minion      :1711][INFO    ][15401] Returning information for job: 20190607062315947057
2019-06-07 06:23:46,010 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062345998210
2019-06-07 06:23:46,029 [salt.minion      :1432][INFO    ][15575] Starting a new job with PID 15575
2019-06-07 06:23:46,040 [salt.minion      :1711][INFO    ][15575] Returning information for job: 20190607062345998210
2019-06-07 06:23:49,224 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.78352213s left)
2019-06-07 06:24:16,043 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062416029911
2019-06-07 06:24:16,066 [salt.minion      :1432][INFO    ][15737] Starting a new job with PID 15737
2019-06-07 06:24:16,088 [salt.minion      :1711][INFO    ][15737] Returning information for job: 20190607062416029911
2019-06-07 06:24:22,996 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.01171207s left)
2019-06-07 06:24:46,103 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062446090245
2019-06-07 06:24:46,126 [salt.minion      :1432][INFO    ][16333] Starting a new job with PID 16333
2019-06-07 06:24:46,150 [salt.minion      :1711][INFO    ][16333] Returning information for job: 20190607062446090245
2019-06-07 06:24:56,389 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.61881208s left)
2019-06-07 06:25:16,159 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062516146072
2019-06-07 06:25:16,182 [salt.minion      :1432][INFO    ][16428] Starting a new job with PID 16428
2019-06-07 06:25:16,207 [salt.minion      :1711][INFO    ][16428] Returning information for job: 20190607062516146072
2019-06-07 06:25:30,102 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.90506196s left)
2019-06-07 06:25:46,229 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062546214086
2019-06-07 06:25:46,252 [salt.minion      :1432][INFO    ][16697] Starting a new job with PID 16697
2019-06-07 06:25:46,275 [salt.minion      :1711][INFO    ][16697] Returning information for job: 20190607062546214086
2019-06-07 06:26:03,930 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.07713413s left)
2019-06-07 06:26:16,294 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062616282197
2019-06-07 06:26:16,316 [salt.minion      :1432][INFO    ][16728] Starting a new job with PID 16728
2019-06-07 06:26:16,340 [salt.minion      :1711][INFO    ][16728] Returning information for job: 20190607062616282197
2019-06-07 06:26:37,074 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1978.93325496s left)
2019-06-07 06:26:46,370 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062646358348
2019-06-07 06:26:46,392 [salt.minion      :1432][INFO    ][17143] Starting a new job with PID 17143
2019-06-07 06:26:46,415 [salt.minion      :1711][INFO    ][17143] Returning information for job: 20190607062646358348
2019-06-07 06:27:10,447 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.56042004s left)
2019-06-07 06:27:16,441 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062716428674
2019-06-07 06:27:16,456 [salt.minion      :1432][INFO    ][17170] Starting a new job with PID 17170
2019-06-07 06:27:16,470 [salt.minion      :1711][INFO    ][17170] Returning information for job: 20190607062716428674
2019-06-07 06:27:43,975 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.03277707s left)
2019-06-07 06:27:46,496 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062746483728
2019-06-07 06:27:46,519 [salt.minion      :1432][INFO    ][17611] Starting a new job with PID 17611
2019-06-07 06:27:46,544 [salt.minion      :1711][INFO    ][17611] Returning information for job: 20190607062746483728
2019-06-07 06:28:16,584 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062816571404
2019-06-07 06:28:16,605 [salt.minion      :1432][INFO    ][17631] Starting a new job with PID 17631
2019-06-07 06:28:16,627 [salt.minion      :1711][INFO    ][17631] Returning information for job: 20190607062816571404
2019-06-07 06:28:17,649 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.3584311s left)
2019-06-07 06:28:46,669 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062846656146
2019-06-07 06:28:46,691 [salt.minion      :1432][INFO    ][17885] Starting a new job with PID 17885
2019-06-07 06:28:46,714 [salt.minion      :1711][INFO    ][17885] Returning information for job: 20190607062846656146
2019-06-07 06:28:51,221 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1844.78645492s left)
2019-06-07 06:29:16,762 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062916750297
2019-06-07 06:29:16,785 [salt.minion      :1432][INFO    ][17949] Starting a new job with PID 17949
2019-06-07 06:29:16,808 [salt.minion      :1711][INFO    ][17949] Returning information for job: 20190607062916750297
2019-06-07 06:29:24,334 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1811.6735611s left)
2019-06-07 06:29:46,784 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607062946772217
2019-06-07 06:29:46,805 [salt.minion      :1432][INFO    ][18155] Starting a new job with PID 18155
2019-06-07 06:29:46,826 [salt.minion      :1711][INFO    ][18155] Returning information for job: 20190607062946772217
2019-06-07 06:29:57,629 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1778.378829s left)
2019-06-07 06:30:16,889 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063016876060
2019-06-07 06:30:16,913 [salt.minion      :1432][INFO    ][18236] Starting a new job with PID 18236
2019-06-07 06:30:16,938 [salt.minion      :1711][INFO    ][18236] Returning information for job: 20190607063016876060
2019-06-07 06:30:30,785 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1745.22209811s left)
2019-06-07 06:30:47,000 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063046987782
2019-06-07 06:30:47,023 [salt.minion      :1432][INFO    ][18611] Starting a new job with PID 18611
2019-06-07 06:30:47,048 [salt.minion      :1711][INFO    ][18611] Returning information for job: 20190607063046987782
2019-06-07 06:31:04,169 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1711.83825493s left)
2019-06-07 06:31:17,124 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063117110887
2019-06-07 06:31:17,147 [salt.minion      :1432][INFO    ][18641] Starting a new job with PID 18641
2019-06-07 06:31:17,174 [salt.minion      :1711][INFO    ][18641] Returning information for job: 20190607063117110887
2019-06-07 06:31:37,258 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1678.74984908s left)
2019-06-07 06:31:47,255 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063147242794
2019-06-07 06:31:47,277 [salt.minion      :1432][INFO    ][18686] Starting a new job with PID 18686
2019-06-07 06:31:47,300 [salt.minion      :1711][INFO    ][18686] Returning information for job: 20190607063147242794
2019-06-07 06:32:10,917 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1645.09001613s left)
2019-06-07 06:32:17,389 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063217377316
2019-06-07 06:32:17,411 [salt.minion      :1432][INFO    ][18716] Starting a new job with PID 18716
2019-06-07 06:32:17,437 [salt.minion      :1711][INFO    ][18716] Returning information for job: 20190607063217377316
2019-06-07 06:32:44,408 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1611.59912896s left)
2019-06-07 06:32:47,527 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063247514105
2019-06-07 06:32:47,549 [salt.minion      :1432][INFO    ][18764] Starting a new job with PID 18764
2019-06-07 06:32:47,573 [salt.minion      :1711][INFO    ][18764] Returning information for job: 20190607063247514105
2019-06-07 06:33:17,679 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063317666304
2019-06-07 06:33:17,700 [salt.minion      :1432][INFO    ][18919] Starting a new job with PID 18919
2019-06-07 06:33:17,725 [salt.minion      :1711][INFO    ][18919] Returning information for job: 20190607063317666304
2019-06-07 06:33:17,732 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1578.27547812s left)
2019-06-07 06:33:47,834 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063347822305
2019-06-07 06:33:47,857 [salt.minion      :1432][INFO    ][18972] Starting a new job with PID 18972
2019-06-07 06:33:47,883 [salt.minion      :1711][INFO    ][18972] Returning information for job: 20190607063347822305
2019-06-07 06:33:51,218 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1544.78923202s left)
2019-06-07 06:34:18,007 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063417994038
2019-06-07 06:34:18,029 [salt.minion      :1432][INFO    ][19009] Starting a new job with PID 19009
2019-06-07 06:34:18,054 [salt.minion      :1711][INFO    ][19009] Returning information for job: 20190607063417994038
2019-06-07 06:34:25,038 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1510.96951509s left)
2019-06-07 06:34:48,181 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063448168665
2019-06-07 06:34:48,199 [salt.minion      :1432][INFO    ][19057] Starting a new job with PID 19057
2019-06-07 06:34:48,224 [salt.minion      :1711][INFO    ][19057] Returning information for job: 20190607063448168665
2019-06-07 06:34:58,595 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1477.4126091s left)
2019-06-07 06:35:18,365 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063518352548
2019-06-07 06:35:18,387 [salt.minion      :1432][INFO    ][19087] Starting a new job with PID 19087
2019-06-07 06:35:18,410 [salt.minion      :1711][INFO    ][19087] Returning information for job: 20190607063518352548
2019-06-07 06:35:32,009 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1443.99897313s left)
2019-06-07 06:35:48,566 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063548553106
2019-06-07 06:35:48,589 [salt.minion      :1432][INFO    ][19131] Starting a new job with PID 19131
2019-06-07 06:35:48,615 [salt.minion      :1711][INFO    ][19131] Returning information for job: 20190607063548553106
2019-06-07 06:36:05,541 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1410.46643305s left)
2019-06-07 06:36:18,780 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063618767794
2019-06-07 06:36:18,802 [salt.minion      :1432][INFO    ][19161] Starting a new job with PID 19161
2019-06-07 06:36:18,828 [salt.minion      :1711][INFO    ][19161] Returning information for job: 20190607063618767794
2019-06-07 06:36:38,948 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1377.05911493s left)
2019-06-07 06:36:49,001 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063648989039
2019-06-07 06:36:49,023 [salt.minion      :1432][INFO    ][19205] Starting a new job with PID 19205
2019-06-07 06:36:49,048 [salt.minion      :1711][INFO    ][19205] Returning information for job: 20190607063648989039
2019-06-07 06:37:12,380 [salt.loaded.ext.module.maas:1023][INFO    ][15301] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1343.62716293s left)
2019-06-07 06:37:19,034 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063719020961
2019-06-07 06:37:19,060 [salt.minion      :1432][INFO    ][19234] Starting a new job with PID 19234
2019-06-07 06:37:19,089 [salt.minion      :1711][INFO    ][19234] Returning information for job: 20190607063719020961
2019-06-07 06:37:44,400 [salt.loaded.ext.module.maas:993 ][INFO    ][15301] Machine phscb6 mark broken
2019-06-07 06:37:45,182 [salt.loaded.ext.module.maas:996 ][INFO    ][15301] Machine phscb6 mark fixed
2019-06-07 06:37:46,438 [salt.loaded.ext.module.maas:684 ][INFO    ][15301] deploymachines hwe_kernel=hwe-16.04 system_id=phscb6 distro_series=xenial
2019-06-07 06:37:49,078 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063749065738
2019-06-07 06:37:49,101 [salt.minion      :1432][INFO    ][19344] Starting a new job with PID 19344
2019-06-07 06:37:49,129 [salt.minion      :1711][INFO    ][19344] Returning information for job: 20190607063749065738
2019-06-07 06:37:49,206 [salt.loaded.ext.module.maas:160 ][ERROR   ][15301] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-06-07 06:37:49,208 [salt.state       :302 ][ERROR   ][15301] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-06-07 06:37:49,208 [salt.state       :1951][INFO    ][15301] Completed state [maas.wait_for_machine_status] at time 06:37:49.208740 duration_in_ms=943205.476
2019-06-07 06:37:49,217 [salt.minion      :1711][INFO    ][15301] Returning information for job: 20190607062200731448
2019-06-07 06:37:59,912 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command pillar.get with jid 20190607063759899773
2019-06-07 06:37:59,927 [salt.minion      :1432][INFO    ][19361] Starting a new job with PID 19361
2019-06-07 06:37:59,932 [salt.minion      :1711][INFO    ][19361] Returning information for job: 20190607063759899773
2019-06-07 06:38:00,465 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command service.status with jid 20190607063800456928
2019-06-07 06:38:00,481 [salt.minion      :1432][INFO    ][19366] Starting a new job with PID 19366
2019-06-07 06:38:00,856 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][19366] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:00,891 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][19366] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-07 06:38:00,908 [salt.minion      :1711][INFO    ][19366] Returning information for job: 20190607063800456928
2019-06-07 06:38:01,376 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607063801365077
2019-06-07 06:38:01,395 [salt.minion      :1432][INFO    ][19377] Starting a new job with PID 19377
2019-06-07 06:38:05,151 [salt.state       :915 ][INFO    ][19377] Loading fresh modules for state activity
2019-06-07 06:38:05,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:38:05,842 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:38:06,676 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:38:07,045 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'salt-minion --version' in directory '/root'
2019-06-07 06:38:08,405 [salt.state       :1780][INFO    ][19377] Running state [salt-minion] at time 06:38:08.405271
2019-06-07 06:38:08,405 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [salt-minion]
2019-06-07 06:38:08,406 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:38:08,486 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,486 [salt.state       :1951][INFO    ][19377] Completed state [salt-minion] at time 06:38:08.486796 duration_in_ms=81.524
2019-06-07 06:38:08,487 [salt.state       :1780][INFO    ][19377] Running state [salt_minion_dependency_packages] at time 06:38:08.487081
2019-06-07 06:38:08,487 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-07 06:38:08,493 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,493 [salt.state       :1951][INFO    ][19377] Completed state [salt_minion_dependency_packages] at time 06:38:08.493240 duration_in_ms=6.159
2019-06-07 06:38:08,496 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/minion.d/minion.conf] at time 06:38:08.496003
2019-06-07 06:38:08,496 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-07 06:38:08,692 [salt.state       :300 ][INFO    ][19377] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-07 06:38:08,692 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/minion.d/minion.conf] at time 06:38:08.692402 duration_in_ms=196.398
2019-06-07 06:38:08,692 [salt.state       :1780][INFO    ][19377] Running state [python-netaddr] at time 06:38:08.692748
2019-06-07 06:38:08,693 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [python-netaddr]
2019-06-07 06:38:08,701 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,701 [salt.state       :1951][INFO    ][19377] Completed state [python-netaddr] at time 06:38:08.701888 duration_in_ms=9.14
2019-06-07 06:38:08,705 [salt.state       :1780][INFO    ][19377] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:38:08.705560
2019-06-07 06:38:08,705 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-07 06:38:08,716 [salt.state       :300 ][INFO    ][19377] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-07 06:38:08,716 [salt.state       :1951][INFO    ][19377] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:38:08.716871 duration_in_ms=11.311
2019-06-07 06:38:08,718 [salt.state       :1780][INFO    ][19377] Running state [salt-minion] at time 06:38:08.717986
2019-06-07 06:38:08,718 [salt.state       :1813][INFO    ][19377] Executing state service.running for [salt-minion]
2019-06-07 06:38:08,718 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:08,755 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-07 06:38:08,773 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-07 06:38:08,790 [salt.state       :300 ][INFO    ][19377] The service salt-minion is already running
2019-06-07 06:38:08,790 [salt.state       :1951][INFO    ][19377] Completed state [salt-minion] at time 06:38:08.790576 duration_in_ms=72.589
2019-06-07 06:38:08,792 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains.d] at time 06:38:08.792385
2019-06-07 06:38:08,792 [salt.state       :1813][INFO    ][19377] Executing state file.directory for [/etc/salt/grains.d]
2019-06-07 06:38:08,793 [salt.state       :300 ][INFO    ][19377] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-07 06:38:08,794 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains.d] at time 06:38:08.794204 duration_in_ms=1.818
2019-06-07 06:38:08,795 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains] at time 06:38:08.795018
2019-06-07 06:38:08,795 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/grains]
2019-06-07 06:38:08,796 [salt.state       :300 ][INFO    ][19377] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-07 06:38:08,796 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains] at time 06:38:08.796306 duration_in_ms=1.289
2019-06-07 06:38:08,796 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains.d/placeholder] at time 06:38:08.796876
2019-06-07 06:38:08,797 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-07 06:38:08,797 [salt.state       :300 ][INFO    ][19377] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-07 06:38:08,798 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains.d/placeholder] at time 06:38:08.798111 duration_in_ms=1.235
2019-06-07 06:38:08,798 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains.d/sphinx] at time 06:38:08.798667
2019-06-07 06:38:08,799 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-07 06:38:08,811 [salt.state       :300 ][INFO    ][19377] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-07 06:38:08,812 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains.d/sphinx] at time 06:38:08.812125 duration_in_ms=13.458
2019-06-07 06:38:08,814 [salt.state       :1780][INFO    ][19377] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.814806
2019-06-07 06:38:08,815 [salt.state       :1813][INFO    ][19377] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-07 06:38:08,815 [salt.state       :300 ][INFO    ][19377] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:38:08,815 [salt.state       :1951][INFO    ][19377] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.815840 duration_in_ms=1.036
2019-06-07 06:38:08,816 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains.d/dns_records] at time 06:38:08.816411
2019-06-07 06:38:08,816 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-07 06:38:08,829 [salt.state       :300 ][INFO    ][19377] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-07 06:38:08,829 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains.d/dns_records] at time 06:38:08.829874 duration_in_ms=13.463
2019-06-07 06:38:08,831 [salt.state       :1780][INFO    ][19377] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.830970
2019-06-07 06:38:08,831 [salt.state       :1813][INFO    ][19377] 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-07 06:38:08,831 [salt.state       :300 ][INFO    ][19377] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:38:08,832 [salt.state       :1951][INFO    ][19377] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.832001 duration_in_ms=1.031
2019-06-07 06:38:08,832 [salt.state       :1780][INFO    ][19377] Running state [/etc/salt/grains.d/salt] at time 06:38:08.832593
2019-06-07 06:38:08,832 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-07 06:38:08,841 [salt.state       :300 ][INFO    ][19377] File /etc/salt/grains.d/salt is in the correct state
2019-06-07 06:38:08,841 [salt.state       :1951][INFO    ][19377] Completed state [/etc/salt/grains.d/salt] at time 06:38:08.841887 duration_in_ms=9.294
2019-06-07 06:38:08,843 [salt.state       :1780][INFO    ][19377] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.842949
2019-06-07 06:38:08,843 [salt.state       :1813][INFO    ][19377] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-07 06:38:08,843 [salt.state       :300 ][INFO    ][19377] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-07 06:38:08,844 [salt.state       :1951][INFO    ][19377] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:38:08.843970 duration_in_ms=1.02
2019-06-07 06:38:08,846 [salt.state       :1780][INFO    ][19377] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:38:08.846220
2019-06-07 06:38:08,846 [salt.state       :1813][INFO    ][19377] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-07 06:38:08,847 [salt.state       :300 ][INFO    ][19377] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-07 06:38:08,847 [salt.state       :1951][INFO    ][19377] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:38:08.847247 duration_in_ms=1.027
2019-06-07 06:38:08,848 [salt.state       :1780][INFO    ][19377] Running state [mine.update] at time 06:38:08.848047
2019-06-07 06:38:08,848 [salt.state       :1813][INFO    ][19377] Executing state module.wait for [mine.update]
2019-06-07 06:38:08,848 [salt.state       :300 ][INFO    ][19377] No changes made for mine.update
2019-06-07 06:38:08,849 [salt.state       :1951][INFO    ][19377] Completed state [mine.update] at time 06:38:08.849006 duration_in_ms=0.96
2019-06-07 06:38:08,849 [salt.state       :1780][INFO    ][19377] Running state [ca-certificates] at time 06:38:08.849308
2019-06-07 06:38:08,849 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [ca-certificates]
2019-06-07 06:38:08,858 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,858 [salt.state       :1951][INFO    ][19377] Completed state [ca-certificates] at time 06:38:08.858594 duration_in_ms=9.287
2019-06-07 06:38:08,859 [salt.state       :1780][INFO    ][19377] Running state [update-ca-certificates] at time 06:38:08.859389
2019-06-07 06:38:08,859 [salt.state       :1813][INFO    ][19377] Executing state cmd.wait for [update-ca-certificates]
2019-06-07 06:38:08,860 [salt.state       :300 ][INFO    ][19377] No changes made for update-ca-certificates
2019-06-07 06:38:08,860 [salt.state       :1951][INFO    ][19377] Completed state [update-ca-certificates] at time 06:38:08.860326 duration_in_ms=0.937
2019-06-07 06:38:08,860 [salt.state       :1780][INFO    ][19377] Running state [iptables] at time 06:38:08.860624
2019-06-07 06:38:08,860 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [iptables]
2019-06-07 06:38:08,868 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,869 [salt.state       :1951][INFO    ][19377] Completed state [iptables] at time 06:38:08.869038 duration_in_ms=8.413
2019-06-07 06:38:08,869 [salt.state       :1780][INFO    ][19377] Running state [iptables-persistent] at time 06:38:08.869316
2019-06-07 06:38:08,869 [salt.state       :1813][INFO    ][19377] Executing state pkg.installed for [iptables-persistent]
2019-06-07 06:38:08,877 [salt.state       :300 ][INFO    ][19377] All specified packages are already installed
2019-06-07 06:38:08,877 [salt.state       :1951][INFO    ][19377] Completed state [iptables-persistent] at time 06:38:08.877415 duration_in_ms=8.099
2019-06-07 06:38:08,878 [salt.state       :1780][INFO    ][19377] Running state [iptables_modules_v4_load] at time 06:38:08.878510
2019-06-07 06:38:08,878 [salt.state       :1813][INFO    ][19377] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-07 06:38:08,879 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'lsmod' in directory '/root'
2019-06-07 06:38:08,902 [salt.state       :300 ][INFO    ][19377] Kernel modules iptable_filter, ip_tables are already present
2019-06-07 06:38:08,903 [salt.state       :1951][INFO    ][19377] Completed state [iptables_modules_v4_load] at time 06:38:08.903085 duration_in_ms=24.574
2019-06-07 06:38:08,903 [salt.state       :1780][INFO    ][19377] Running state [/etc/iptables/rules.v4] at time 06:38:08.903818
2019-06-07 06:38:08,904 [salt.state       :1813][INFO    ][19377] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-07 06:38:09,021 [salt.state       :300 ][INFO    ][19377] File /etc/iptables/rules.v4 is in the correct state
2019-06-07 06:38:09,021 [salt.state       :1951][INFO    ][19377] Completed state [/etc/iptables/rules.v4] at time 06:38:09.021902 duration_in_ms=118.083
2019-06-07 06:38:09,023 [salt.state       :1780][INFO    ][19377] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:38:09.023127
2019-06-07 06:38:09,023 [salt.state       :1813][INFO    ][19377] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-07 06:38:09,024 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-07 06:38:09,044 [salt.state       :300 ][INFO    ][19377] onlyif execution failed
2019-06-07 06:38:09,044 [salt.state       :1951][INFO    ][19377] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:38:09.044841 duration_in_ms=21.713
2019-06-07 06:38:09,045 [salt.state       :1780][INFO    ][19377] Running state [netfilter-persistent] at time 06:38:09.045927
2019-06-07 06:38:09,046 [salt.state       :1813][INFO    ][19377] Executing state service.running for [netfilter-persistent]
2019-06-07 06:38:09,047 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:09,066 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-07 06:38:09,084 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-07 06:38:09,101 [salt.state       :300 ][INFO    ][19377] The service netfilter-persistent is already running
2019-06-07 06:38:09,101 [salt.state       :1951][INFO    ][19377] Completed state [netfilter-persistent] at time 06:38:09.101432 duration_in_ms=55.504
2019-06-07 06:38:09,102 [salt.state       :1780][INFO    ][19377] Running state [iptables_extra.remove_stale_tables] at time 06:38:09.102440
2019-06-07 06:38:09,102 [salt.state       :1813][INFO    ][19377] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-07 06:38:09,103 [salt.state       :300 ][INFO    ][19377] No changes made for iptables_extra.remove_stale_tables
2019-06-07 06:38:09,103 [salt.state       :1951][INFO    ][19377] Completed state [iptables_extra.remove_stale_tables] at time 06:38:09.103586 duration_in_ms=1.147
2019-06-07 06:38:09,103 [salt.state       :1780][INFO    ][19377] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:38:09.103887
2019-06-07 06:38:09,104 [salt.state       :1813][INFO    ][19377] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-07 06:38:09,105 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19377] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-07 06:38:09,119 [salt.state       :300 ][INFO    ][19377] onlyif execution failed
2019-06-07 06:38:09,120 [salt.state       :1951][INFO    ][19377] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:38:09.120239 duration_in_ms=16.353
2019-06-07 06:38:09,121 [salt.state       :1780][INFO    ][19377] Running state [/etc/iptables/rules.v6] at time 06:38:09.121368
2019-06-07 06:38:09,121 [salt.state       :1813][INFO    ][19377] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-07 06:38:09,122 [salt.state       :300 ][INFO    ][19377] File /etc/iptables/rules.v6 is not present
2019-06-07 06:38:09,122 [salt.state       :1951][INFO    ][19377] Completed state [/etc/iptables/rules.v6] at time 06:38:09.122607 duration_in_ms=1.238
2019-06-07 06:38:09,123 [salt.state       :1780][INFO    ][19377] Running state [iptables_extra.flush_all] at time 06:38:09.123400
2019-06-07 06:38:09,123 [salt.state       :1813][INFO    ][19377] Executing state module.wait for [iptables_extra.flush_all]
2019-06-07 06:38:09,124 [salt.state       :300 ][INFO    ][19377] No changes made for iptables_extra.flush_all
2019-06-07 06:38:09,124 [salt.state       :1951][INFO    ][19377] Completed state [iptables_extra.flush_all] at time 06:38:09.124357 duration_in_ms=0.958
2019-06-07 06:38:09,128 [salt.minion      :1711][INFO    ][19377] Returning information for job: 20190607063801365077
2019-06-07 06:38:09,724 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607063809714996
2019-06-07 06:38:09,743 [salt.minion      :1432][INFO    ][19454] Starting a new job with PID 19454
2019-06-07 06:38:10,443 [salt.state       :915 ][INFO    ][19454] Loading fresh modules for state activity
2019-06-07 06:38:11,043 [salt.state       :1780][INFO    ][19454] Running state [maas-rack-controller] at time 06:38:11.043850
2019-06-07 06:38:11,044 [salt.state       :1813][INFO    ][19454] Executing state pkg.installed for [maas-rack-controller]
2019-06-07 06:38:11,044 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19454] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:38:11,138 [salt.state       :300 ][INFO    ][19454] All specified packages are already installed
2019-06-07 06:38:11,139 [salt.state       :1951][INFO    ][19454] Completed state [maas-rack-controller] at time 06:38:11.138897 duration_in_ms=95.045
2019-06-07 06:38:11,139 [salt.state       :1780][INFO    ][19454] Running state [ipmitool] at time 06:38:11.139392
2019-06-07 06:38:11,139 [salt.state       :1813][INFO    ][19454] Executing state pkg.installed for [ipmitool]
2019-06-07 06:38:11,146 [salt.state       :300 ][INFO    ][19454] All specified packages are already installed
2019-06-07 06:38:11,147 [salt.state       :1951][INFO    ][19454] Completed state [ipmitool] at time 06:38:11.147042 duration_in_ms=7.651
2019-06-07 06:38:11,149 [salt.state       :1780][INFO    ][19454] Running state [/etc/maas/rackd.conf] at time 06:38:11.149930
2019-06-07 06:38:11,150 [salt.state       :1813][INFO    ][19454] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-07 06:38:11,151 [salt.state       :300 ][INFO    ][19454] No changes needed to be made
2019-06-07 06:38:11,151 [salt.state       :1951][INFO    ][19454] Completed state [/etc/maas/rackd.conf] at time 06:38:11.151444 duration_in_ms=1.513
2019-06-07 06:38:11,151 [salt.state       :1780][INFO    ][19454] Running state [/etc/maas/rackd.conf] at time 06:38:11.151768
2019-06-07 06:38:11,152 [salt.state       :1813][INFO    ][19454] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-07 06:38:11,152 [salt.loaded.int.states.file:2298][WARNING ][19454] 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-07 06:38:11,153 [salt.state       :300 ][INFO    ][19454] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-07 06:38:11,153 [salt.state       :1951][INFO    ][19454] Completed state [/etc/maas/rackd.conf] at time 06:38:11.153429 duration_in_ms=1.66
2019-06-07 06:38:11,154 [salt.state       :1780][INFO    ][19454] Running state [maas-rackd] at time 06:38:11.154423
2019-06-07 06:38:11,154 [salt.state       :1813][INFO    ][19454] Executing state service.running for [maas-rackd]
2019-06-07 06:38:11,155 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19454] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:11,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19454] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-07 06:38:11,205 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19454] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-07 06:38:11,221 [salt.state       :300 ][INFO    ][19454] The service maas-rackd is already running
2019-06-07 06:38:11,222 [salt.state       :1951][INFO    ][19454] Completed state [maas-rackd] at time 06:38:11.221937 duration_in_ms=67.512
2019-06-07 06:38:11,223 [salt.minion      :1711][INFO    ][19454] Returning information for job: 20190607063809714996
2019-06-07 06:38:11,803 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607063811790699
2019-06-07 06:38:11,826 [salt.minion      :1432][INFO    ][19479] Starting a new job with PID 19479
2019-06-07 06:38:12,587 [salt.state       :915 ][INFO    ][19479] Loading fresh modules for state activity
2019-06-07 06:38:13,265 [salt.state       :1780][INFO    ][19479] Running state [maas-region-controller] at time 06:38:13.265316
2019-06-07 06:38:13,265 [salt.state       :1813][INFO    ][19479] Executing state pkg.installed for [maas-region-controller]
2019-06-07 06:38:13,266 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-07 06:38:13,340 [salt.state       :300 ][INFO    ][19479] All specified packages are already installed
2019-06-07 06:38:13,340 [salt.state       :1951][INFO    ][19479] Completed state [maas-region-controller] at time 06:38:13.340870 duration_in_ms=75.554
2019-06-07 06:38:13,341 [salt.state       :1780][INFO    ][19479] Running state [python-oauth] at time 06:38:13.341107
2019-06-07 06:38:13,341 [salt.state       :1813][INFO    ][19479] Executing state pkg.installed for [python-oauth]
2019-06-07 06:38:13,345 [salt.state       :300 ][INFO    ][19479] All specified packages are already installed
2019-06-07 06:38:13,345 [salt.state       :1951][INFO    ][19479] Completed state [python-oauth] at time 06:38:13.345948 duration_in_ms=4.842
2019-06-07 06:38:13,348 [salt.state       :1780][INFO    ][19479] Running state [/etc/maas/regiond.conf] at time 06:38:13.348295
2019-06-07 06:38:13,348 [salt.state       :1813][INFO    ][19479] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-07 06:38:13,381 [salt.state       :300 ][INFO    ][19479] No changes needed to be made
2019-06-07 06:38:13,381 [salt.state       :1951][INFO    ][19479] Completed state [/etc/maas/regiond.conf] at time 06:38:13.381501 duration_in_ms=33.205
2019-06-07 06:38:13,382 [salt.state       :1780][INFO    ][19479] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:38:13.381958
2019-06-07 06:38:13,382 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-07 06:38:13,440 [salt.state       :300 ][INFO    ][19479] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-07 06:38:13,441 [salt.state       :1951][INFO    ][19479] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:38:13.441159 duration_in_ms=59.201
2019-06-07 06:38:13,441 [salt.state       :1780][INFO    ][19479] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:38:13.441651
2019-06-07 06:38:13,441 [salt.state       :1813][INFO    ][19479] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-07 06:38:13,454 [salt.state       :300 ][INFO    ][19479] No changes needed to be made
2019-06-07 06:38:13,454 [salt.state       :1951][INFO    ][19479] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:38:13.454389 duration_in_ms=12.737
2019-06-07 06:38:13,454 [salt.state       :1780][INFO    ][19479] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:38:13.454844
2019-06-07 06:38:13,455 [salt.state       :1813][INFO    ][19479] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-07 06:38:13,478 [salt.state       :300 ][INFO    ][19479] No changes needed to be made
2019-06-07 06:38:13,478 [salt.state       :1951][INFO    ][19479] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:38:13.478442 duration_in_ms=23.598
2019-06-07 06:38:13,478 [salt.state       :1780][INFO    ][19479] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:38:13.478922
2019-06-07 06:38:13,479 [salt.state       :1813][INFO    ][19479] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-07 06:38:13,501 [salt.state       :300 ][INFO    ][19479] No changes needed to be made
2019-06-07 06:38:13,501 [salt.state       :1951][INFO    ][19479] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:38:13.501501 duration_in_ms=22.579
2019-06-07 06:38:13,502 [salt.state       :1780][INFO    ][19479] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:38:13.501970
2019-06-07 06:38:13,502 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-07 06:38:13,513 [salt.state       :300 ][INFO    ][19479] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-07 06:38:13,514 [salt.state       :1951][INFO    ][19479] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:38:13.513976 duration_in_ms=12.006
2019-06-07 06:38:13,515 [salt.state       :1780][INFO    ][19479] Running state [a2enmod headers] at time 06:38:13.515124
2019-06-07 06:38:13,515 [salt.state       :1813][INFO    ][19479] Executing state cmd.run for [a2enmod headers]
2019-06-07 06:38:13,515 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command 'a2enmod headers' in directory '/root'
2019-06-07 06:38:13,589 [salt.state       :300 ][INFO    ][19479] {'pid': 19498, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-07 06:38:13,589 [salt.state       :1951][INFO    ][19479] Completed state [a2enmod headers] at time 06:38:13.589818 duration_in_ms=74.692
2019-06-07 06:38:13,590 [salt.state       :1780][INFO    ][19479] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:38:13.590409
2019-06-07 06:38:13,590 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-07 06:38:13,608 [salt.state       :300 ][INFO    ][19479] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-07 06:38:13,608 [salt.state       :1951][INFO    ][19479] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:38:13.608856 duration_in_ms=18.448
2019-06-07 06:38:13,609 [salt.state       :1780][INFO    ][19479] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:38:13.609661
2019-06-07 06:38:13,610 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-07 06:38:13,693 [salt.state       :300 ][INFO    ][19479] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-07 06:38:13,695 [salt.state       :1951][INFO    ][19479] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:38:13.694881 duration_in_ms=85.217
2019-06-07 06:38:13,696 [salt.state       :1780][INFO    ][19479] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:38:13.696248
2019-06-07 06:38:13,696 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-07 06:38:13,770 [salt.state       :300 ][INFO    ][19479] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-07 06:38:13,770 [salt.state       :1951][INFO    ][19479] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:38:13.770874 duration_in_ms=74.626
2019-06-07 06:38:13,771 [salt.state       :1780][INFO    ][19479] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:38:13.771467
2019-06-07 06:38:13,771 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-07 06:38:13,836 [salt.state       :300 ][INFO    ][19479] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-07 06:38:13,836 [salt.state       :1951][INFO    ][19479] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:38:13.836716 duration_in_ms=65.249
2019-06-07 06:38:13,837 [salt.state       :1780][INFO    ][19479] Running state [/root/.pgpass] at time 06:38:13.837010
2019-06-07 06:38:13,837 [salt.state       :1813][INFO    ][19479] Executing state file.managed for [/root/.pgpass]
2019-06-07 06:38:13,884 [salt.state       :300 ][INFO    ][19479] File /root/.pgpass is in the correct state
2019-06-07 06:38:13,884 [salt.state       :1951][INFO    ][19479] Completed state [/root/.pgpass] at time 06:38:13.884640 duration_in_ms=47.631
2019-06-07 06:38:13,890 [salt.state       :1780][INFO    ][19479] Running state [maas-region syncdb --noinput] at time 06:38:13.890243
2019-06-07 06:38:13,890 [salt.state       :1813][INFO    ][19479] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-07 06:38:13,891 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-07 06:38:15,856 [salt.state       :300 ][INFO    ][19479] {'pid': 19511, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, contenttypes, sites, piston3, auth, maasserver, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-07 06:38:15,857 [salt.state       :1951][INFO    ][19479] Completed state [maas-region syncdb --noinput] at time 06:38:15.857206 duration_in_ms=1966.964
2019-06-07 06:38:15,857 [salt.state       :2022][WARNING ][19479] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-07 06:38:15,858 [salt.state       :1780][INFO    ][19479] Running state [maas-regiond] at time 06:38:15.858475
2019-06-07 06:38:15,858 [salt.state       :1813][INFO    ][19479] Executing state service.running for [maas-regiond]
2019-06-07 06:38:15,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:15,893 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-07 06:38:15,909 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-07 06:38:15,925 [salt.state       :300 ][INFO    ][19479] The service maas-regiond is already running
2019-06-07 06:38:15,925 [salt.state       :1951][INFO    ][19479] Completed state [maas-regiond] at time 06:38:15.925459 duration_in_ms=66.984
2019-06-07 06:38:15,926 [salt.state       :1780][INFO    ][19479] Running state [bind9] at time 06:38:15.926566
2019-06-07 06:38:15,926 [salt.state       :1813][INFO    ][19479] Executing state service.running for [bind9]
2019-06-07 06:38:15,927 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:15,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-07 06:38:15,958 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-07 06:38:15,973 [salt.state       :300 ][INFO    ][19479] The service bind9 is already running
2019-06-07 06:38:15,973 [salt.state       :1951][INFO    ][19479] Completed state [bind9] at time 06:38:15.973865 duration_in_ms=47.299
2019-06-07 06:38:15,975 [salt.state       :1780][INFO    ][19479] Running state [apache2] at time 06:38:15.975041
2019-06-07 06:38:15,975 [salt.state       :1813][INFO    ][19479] Executing state service.running for [apache2]
2019-06-07 06:38:15,975 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-07 06:38:15,992 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-07 06:38:16,007 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-07 06:38:16,026 [salt.state       :300 ][INFO    ][19479] The service apache2 is already running
2019-06-07 06:38:16,026 [salt.state       :1951][INFO    ][19479] Completed state [apache2] at time 06:38:16.026537 duration_in_ms=51.496
2019-06-07 06:38:16,027 [salt.state       :1780][INFO    ][19479] Running state [maasng.wait_for_http_code] at time 06:38:16.027736
2019-06-07 06:38:16,028 [salt.state       :1813][INFO    ][19479] Executing state module.run for [maasng.wait_for_http_code]
2019-06-07 06:38:16,028 [salt.utils.decorators:613 ][WARNING ][19479] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:16,161 [salt.state       :300 ][INFO    ][19479] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-07 06:38:16,162 [salt.state       :1951][INFO    ][19479] Completed state [maasng.wait_for_http_code] at time 06:38:16.162229 duration_in_ms=134.492
2019-06-07 06:38:16,163 [salt.state       :1780][INFO    ][19479] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:38:16.163430
2019-06-07 06:38:16,163 [salt.state       :1813][INFO    ][19479] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-07 06:38:16,164 [salt.state       :300 ][INFO    ][19479] /var/lib/maas/.setup_admin exists
2019-06-07 06:38:16,165 [salt.state       :1951][INFO    ][19479] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:38:16.164926 duration_in_ms=1.496
2019-06-07 06:38:16,166 [salt.state       :1780][INFO    ][19479] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:16.165997
2019-06-07 06:38:16,166 [salt.state       :1813][INFO    ][19479] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:38:16,167 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19479] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:38:17,627 [salt.state       :300 ][INFO    ][19479] {'pid': 19532, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:38:17,628 [salt.state       :1951][INFO    ][19479] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:17.628158 duration_in_ms=1462.162
2019-06-07 06:38:17,638 [salt.state       :1780][INFO    ][19479] Running state [maas_region_boot_source_resources_mirror] at time 06:38:17.638849
2019-06-07 06:38:17,639 [salt.state       :1813][INFO    ][19479] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-07 06:38:17,733 [salt.state       :300 ][INFO    ][19479] {'changes': {}}
2019-06-07 06:38:17,733 [salt.state       :1951][INFO    ][19479] Completed state [maas_region_boot_source_resources_mirror] at time 06:38:17.733511 duration_in_ms=94.662
2019-06-07 06:38:17,734 [salt.state       :1780][INFO    ][19479] Running state [maasng.boot_resources_import] at time 06:38:17.734622
2019-06-07 06:38:17,735 [salt.state       :1813][INFO    ][19479] Executing state module.run for [maasng.boot_resources_import]
2019-06-07 06:38:17,735 [salt.utils.decorators:613 ][WARNING ][19479] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:17,847 [salt.loaded.ext.module.maasng:1600][INFO    ][19479] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-07 06:38:24,320 [salt.loaded.ext.module.maasng:1600][INFO    ][19479] Waiting boot-resources import done
sleep for:5s Left:893.0/900s
2019-06-07 06:38:26,865 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063826852072
2019-06-07 06:38:26,888 [salt.minion      :1432][INFO    ][19611] Starting a new job with PID 19611
2019-06-07 06:38:26,916 [salt.minion      :1711][INFO    ][19611] Returning information for job: 20190607063826852072
2019-06-07 06:38:29,392 [salt.loaded.ext.module.maasng:1600][INFO    ][19479] Waiting boot-resources import done
sleep for:5s Left:888.0/900s
2019-06-07 06:38:34,458 [salt.loaded.ext.module.maasng:1600][INFO    ][19479] Waiting boot-resources import done
sleep for:5s Left:883.0/900s
2019-06-07 06:38:39,549 [salt.loaded.ext.module.maasng:1600][INFO    ][19479] Waiting boot-resources import done
sleep for:5s Left:878.0/900s
2019-06-07 06:38:44,661 [salt.state       :300 ][INFO    ][19479] {'ret': True}
2019-06-07 06:38:44,662 [salt.state       :1951][INFO    ][19479] Completed state [maasng.boot_resources_import] at time 06:38:44.662121 duration_in_ms=26927.497
2019-06-07 06:38:44,663 [salt.state       :1780][INFO    ][19479] Running state [maas_region_boot_sources_selection_xenial] at time 06:38:44.663776
2019-06-07 06:38:44,664 [salt.state       :1813][INFO    ][19479] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-07 06:38:44,876 [salt.state       :300 ][INFO    ][19479] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-07 06:38:44,877 [salt.state       :1951][INFO    ][19479] Completed state [maas_region_boot_sources_selection_xenial] at time 06:38:44.877414 duration_in_ms=213.636
2019-06-07 06:38:44,879 [salt.state       :1780][INFO    ][19479] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:38:44.879341
2019-06-07 06:38:44,879 [salt.state       :1813][INFO    ][19479] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-07 06:38:44,880 [salt.utils.decorators:613 ][WARNING ][19479] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:44,881 [salt.loaded.ext.module.maasng:1771][INFO    ][19479] boot-sources sync initiated for ALL Rack's
2019-06-07 06:38:45,642 [salt.state       :300 ][INFO    ][19479] {'ret': True}
2019-06-07 06:38:45,642 [salt.state       :1951][INFO    ][19479] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:38:45.642739 duration_in_ms=763.397
2019-06-07 06:38:45,644 [salt.state       :1780][INFO    ][19479] Running state [maas.process_maas_config] at time 06:38:45.644910
2019-06-07 06:38:45,645 [salt.state       :1813][INFO    ][19479] Executing state module.run for [maas.process_maas_config]
2019-06-07 06:38:45,646 [salt.utils.decorators:613 ][WARNING ][19479] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:45,647 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=enable_http_proxy value=True
2019-06-07 06:38:45,710 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=upstream_dns value=8.8.8.8
2019-06-07 06:38:45,994 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=commissioning_distro_series value=xenial
2019-06-07 06:38:46,068 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=default_osystem value=ubuntu
2019-06-07 06:38:46,134 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=active_discovery_interval value=600
2019-06-07 06:38:46,200 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=dnssec_validation value=no
2019-06-07 06:38:46,260 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=maas_name value=mas01
2019-06-07 06:38:46,313 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=network_discovery value=enabled
2019-06-07 06:38:46,433 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=enable_third_party_drivers value=True
2019-06-07 06:38:46,487 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=default_storage_layout value=lvm
2019-06-07 06:38:46,547 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=ntp_external_only value=True
2019-06-07 06:38:50,383 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-07 06:38:50,446 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=default_distro_series value=xenial
2019-06-07 06:38:50,518 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-07 06:38:50,656 [salt.state       :300 ][INFO    ][19479] {'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-07 06:38:50,656 [salt.state       :1951][INFO    ][19479] Completed state [maas.process_maas_config] at time 06:38:50.656815 duration_in_ms=5011.904
2019-06-07 06:38:50,658 [salt.state       :1780][INFO    ][19479] Running state [pxe_admin] at time 06:38:50.658008
2019-06-07 06:38:50,658 [salt.state       :1813][INFO    ][19479] Executing state maasng.fabric_present for [pxe_admin]
2019-06-07 06:38:50,734 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'primary_rack': u'rgq6cx', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-07 06:38:50,804 [salt.loaded.ext.module.maasng:1008][WARNING ][19479] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-07 06:38:50,805 [salt.loaded.ext.module.maasng:1011][WARNING ][19479] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-07 06:38:50,878 [salt.state       :300 ][INFO    ][19479] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-07 06:38:50,878 [salt.state       :1951][INFO    ][19479] Completed state [pxe_admin] at time 06:38:50.878768 duration_in_ms=220.759
2019-06-07 06:38:50,879 [salt.state       :1780][INFO    ][19479] Running state [vlan 0] at time 06:38:50.879240
2019-06-07 06:38:50,879 [salt.state       :1813][INFO    ][19479] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-07 06:38:50,936 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:38:51,044 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:38:51,302 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:38:51,398 [salt.state       :300 ][INFO    ][19479] {'new': 'Vlan untagged was updated'}
2019-06-07 06:38:51,398 [salt.state       :1951][INFO    ][19479] Completed state [vlan 0] at time 06:38:51.398332 duration_in_ms=519.092
2019-06-07 06:38:51,399 [salt.state       :1780][INFO    ][19479] Running state [192.168.11.0/24] at time 06:38:51.399476
2019-06-07 06:38:51,399 [salt.state       :1813][INFO    ][19479] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-07 06:38:51,583 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, 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'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'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'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'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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-07 06:38:51,584 [salt.loaded.ext.module.maasng:1235][WARNING ][19479] Ignoring parameter vlan:0
2019-06-07 06:38:51,656 [salt.state       :300 ][INFO    ][19479] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-07 06:38:51,656 [salt.state       :1951][INFO    ][19479] Completed state [192.168.11.0/24] at time 06:38:51.656337 duration_in_ms=256.861
2019-06-07 06:38:51,657 [salt.state       :1780][INFO    ][19479] Running state [maas_create_iprange_1] at time 06:38:51.656985
2019-06-07 06:38:51,657 [salt.state       :1813][INFO    ][19479] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-07 06:38:51,697 [salt.state       :300 ][INFO    ][19479] Iprange maas_create_iprange_1 already exist.
2019-06-07 06:38:51,697 [salt.state       :1951][INFO    ][19479] Completed state [maas_create_iprange_1] at time 06:38:51.697759 duration_in_ms=40.773
2019-06-07 06:38:51,698 [salt.state       :1780][INFO    ][19479] Running state [vlan 0] at time 06:38:51.698044
2019-06-07 06:38:51,698 [salt.state       :1813][INFO    ][19479] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-07 06:38:51,739 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:38:51,835 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, 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'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'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'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'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'rgq6cx', 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-07 06:38:52,063 [salt.loaded.ext.module.maasng:945 ][INFO    ][19479] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rgq6cx', 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-07 06:38:52,154 [salt.state       :300 ][INFO    ][19479] {'new': 'Vlan untagged was updated'}
2019-06-07 06:38:52,154 [salt.state       :1951][INFO    ][19479] Completed state [vlan 0] at time 06:38:52.154501 duration_in_ms=456.454
2019-06-07 06:38:52,155 [salt.state       :1780][INFO    ][19479] Running state [opnfv] at time 06:38:52.155843
2019-06-07 06:38:52,156 [salt.state       :1813][INFO    ][19479] Executing state maasng.sshkey_present for [opnfv]
2019-06-07 06:38:52,200 [salt.loaded.ext.module.maasng:1903][INFO    ][19479] [{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-07 06:38:52,200 [salt.state       :300 ][INFO    ][19479] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-07 06:38:52,201 [salt.state       :1951][INFO    ][19479] Completed state [opnfv] at time 06:38:52.201312 duration_in_ms=45.47
2019-06-07 06:38:52,202 [salt.state       :1780][INFO    ][19479] Running state [maas.process_tags] at time 06:38:52.202572
2019-06-07 06:38:52,203 [salt.state       :1813][INFO    ][19479] Executing state module.run for [maas.process_tags]
2019-06-07 06:38:52,203 [salt.utils.decorators:613 ][WARNING ][19479] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:52,248 [salt.loaded.ext.module.maas:92  ][INFO    ][19479] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-07 06:38:52,308 [salt.state       :300 ][INFO    ][19479] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-07 06:38:52,309 [salt.state       :1951][INFO    ][19479] Completed state [maas.process_tags] at time 06:38:52.309338 duration_in_ms=106.766
2019-06-07 06:38:52,313 [salt.minion      :1711][INFO    ][19479] Returning information for job: 20190607063811790699
2019-06-07 06:38:52,819 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607063852813116
2019-06-07 06:38:52,837 [salt.minion      :1432][INFO    ][19998] Starting a new job with PID 19998
2019-06-07 06:38:56,452 [salt.state       :915 ][INFO    ][19998] Loading fresh modules for state activity
2019-06-07 06:38:56,549 [salt.state       :1780][INFO    ][19998] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:56.549563
2019-06-07 06:38:56,550 [salt.state       :1813][INFO    ][19998] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:38:56,552 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19998] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:38:57,935 [salt.state       :300 ][INFO    ][19998] {'pid': 20022, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:38:57,935 [salt.state       :1951][INFO    ][19998] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:57.935541 duration_in_ms=1385.979
2019-06-07 06:38:57,936 [salt.state       :1780][INFO    ][19998] Running state [maas.process_machines] at time 06:38:57.936722
2019-06-07 06:38:57,936 [salt.state       :1813][INFO    ][19998] Executing state module.run for [maas.process_machines]
2019-06-07 06:38:57,937 [salt.utils.decorators:613 ][WARNING ][19998] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:38:58,430 [salt.loaded.ext.module.maas:412 ][WARNING ][19998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:38:58,431 [salt.loaded.ext.module.maas:92  ][INFO    ][19998] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=chwarn architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:38:59,656 [salt.loaded.ext.module.maas:412 ][WARNING ][19998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:38:59,657 [salt.loaded.ext.module.maas:92  ][INFO    ][19998] 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=fsw73e architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:39:00,920 [salt.loaded.ext.module.maas:412 ][WARNING ][19998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:39:00,921 [salt.loaded.ext.module.maas:92  ][INFO    ][19998] 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=phscb6 architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:39:02,136 [salt.loaded.ext.module.maas:412 ][WARNING ][19998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:39:02,137 [salt.loaded.ext.module.maas:92  ][INFO    ][19998] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=n8ks6p architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:39:03,549 [salt.loaded.ext.module.maas:412 ][WARNING ][19998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-07 06:39:03,550 [salt.loaded.ext.module.maas:92  ][INFO    ][19998] 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=rf4b8n architecture=amd64/generic power_parameters_power_user=admin
2019-06-07 06:39:04,814 [salt.state       :300 ][INFO    ][19998] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-07 06:39:04,815 [salt.state       :1951][INFO    ][19998] Completed state [maas.process_machines] at time 06:39:04.815209 duration_in_ms=6878.483
2019-06-07 06:39:04,819 [salt.minion      :1711][INFO    ][19998] Returning information for job: 20190607063852813116
2019-06-07 06:39:38,051 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607063938038980
2019-06-07 06:39:38,072 [salt.minion      :1432][INFO    ][20289] Starting a new job with PID 20289
2019-06-07 06:39:41,769 [salt.state       :915 ][INFO    ][20289] Loading fresh modules for state activity
2019-06-07 06:39:41,858 [salt.state       :1780][INFO    ][20289] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:41.858687
2019-06-07 06:39:41,859 [salt.state       :1813][INFO    ][20289] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:39:41,861 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20289] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:39:43,302 [salt.state       :300 ][INFO    ][20289] {'pid': 20296, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:39:43,303 [salt.state       :1951][INFO    ][20289] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:43.303015 duration_in_ms=1444.328
2019-06-07 06:39:43,304 [salt.state       :1780][INFO    ][20289] Running state [maas.wait_for_machine_status] at time 06:39:43.304520
2019-06-07 06:39:43,304 [salt.state       :1813][INFO    ][20289] Executing state module.run for [maas.wait_for_machine_status]
2019-06-07 06:39:43,305 [salt.utils.decorators:613 ][WARNING ][20289] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:39:45,458 [salt.loaded.ext.module.maas:993 ][INFO    ][20289] Machine phscb6 mark broken
2019-06-07 06:39:46,094 [salt.loaded.ext.module.maas:996 ][INFO    ][20289] Machine phscb6 mark fixed
2019-06-07 06:39:47,344 [salt.loaded.ext.module.maas:684 ][INFO    ][20289] deploymachines hwe_kernel=hwe-16.04 system_id=phscb6 distro_series=xenial
2019-06-07 06:39:51,453 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1491.85878015s left)
2019-06-07 06:39:53,169 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607063953156259
2019-06-07 06:39:53,191 [salt.minion      :1432][INFO    ][20370] Starting a new job with PID 20370
2019-06-07 06:39:53,217 [salt.minion      :1711][INFO    ][20370] Returning information for job: 20190607063953156259
2019-06-07 06:40:23,236 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064023174685
2019-06-07 06:40:23,256 [salt.minion      :1432][INFO    ][20408] Starting a new job with PID 20408
2019-06-07 06:40:23,278 [salt.minion      :1711][INFO    ][20408] Returning information for job: 20190607064023174685
2019-06-07 06:40:24,753 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1458.55867505s left)
2019-06-07 06:40:53,322 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064053309339
2019-06-07 06:40:53,345 [salt.minion      :1432][INFO    ][20447] Starting a new job with PID 20447
2019-06-07 06:40:53,370 [salt.minion      :1711][INFO    ][20447] Returning information for job: 20190607064053309339
2019-06-07 06:40:58,266 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.0456202s left)
2019-06-07 06:41:23,369 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064123356885
2019-06-07 06:41:23,394 [salt.minion      :1432][INFO    ][20486] Starting a new job with PID 20486
2019-06-07 06:41:23,419 [salt.minion      :1711][INFO    ][20486] Returning information for job: 20190607064123356885
2019-06-07 06:41:31,156 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.15515614s left)
2019-06-07 06:41:53,426 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064153413304
2019-06-07 06:41:53,449 [salt.minion      :1432][INFO    ][20580] Starting a new job with PID 20580
2019-06-07 06:41:53,474 [salt.minion      :1711][INFO    ][20580] Returning information for job: 20190607064153413304
2019-06-07 06:42:04,670 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1358.64114809s left)
2019-06-07 06:42:23,472 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064223462958
2019-06-07 06:42:23,491 [salt.minion      :1432][INFO    ][20649] Starting a new job with PID 20649
2019-06-07 06:42:23,507 [salt.minion      :1711][INFO    ][20649] Returning information for job: 20190607064223462958
2019-06-07 06:42:38,327 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1324.98426008s left)
2019-06-07 06:42:53,515 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064253502751
2019-06-07 06:42:53,538 [salt.minion      :1432][INFO    ][20759] Starting a new job with PID 20759
2019-06-07 06:42:53,566 [salt.minion      :1711][INFO    ][20759] Returning information for job: 20190607064253502751
2019-06-07 06:43:11,526 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1291.78529215s left)
2019-06-07 06:43:23,573 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064323565948
2019-06-07 06:43:23,588 [salt.minion      :1432][INFO    ][20830] Starting a new job with PID 20830
2019-06-07 06:43:23,603 [salt.minion      :1711][INFO    ][20830] Returning information for job: 20190607064323565948
2019-06-07 06:43:45,088 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.22312307s left)
2019-06-07 06:43:53,616 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064353602194
2019-06-07 06:43:53,639 [salt.minion      :1432][INFO    ][20872] Starting a new job with PID 20872
2019-06-07 06:43:53,665 [salt.minion      :1711][INFO    ][20872] Returning information for job: 20190607064353602194
2019-06-07 06:44:18,472 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1224.839118s left)
2019-06-07 06:44:23,682 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064423672896
2019-06-07 06:44:23,697 [salt.minion      :1432][INFO    ][20976] Starting a new job with PID 20976
2019-06-07 06:44:23,710 [salt.minion      :1711][INFO    ][20976] Returning information for job: 20190607064423672896
2019-06-07 06:44:52,009 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.30275702s left)
2019-06-07 06:44:53,729 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064453716667
2019-06-07 06:44:53,752 [salt.minion      :1432][INFO    ][21043] Starting a new job with PID 21043
2019-06-07 06:44:53,778 [salt.minion      :1711][INFO    ][21043] Returning information for job: 20190607064453716667
2019-06-07 06:45:23,798 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064523792079
2019-06-07 06:45:23,811 [salt.minion      :1432][INFO    ][21142] Starting a new job with PID 21142
2019-06-07 06:45:23,829 [salt.minion      :1711][INFO    ][21142] Returning information for job: 20190607064523792079
2019-06-07 06:45:24,973 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1158.3384831s left)
2019-06-07 06:45:53,856 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064553843795
2019-06-07 06:45:53,879 [salt.minion      :1432][INFO    ][21175] Starting a new job with PID 21175
2019-06-07 06:45:53,907 [salt.minion      :1711][INFO    ][21175] Returning information for job: 20190607064553843795
2019-06-07 06:45:58,708 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.60314107s left)
2019-06-07 06:46:23,945 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064623932742
2019-06-07 06:46:23,967 [salt.minion      :1432][INFO    ][21229] Starting a new job with PID 21229
2019-06-07 06:46:23,994 [salt.minion      :1711][INFO    ][21229] Returning information for job: 20190607064623932742
2019-06-07 06:46:32,152 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.15941501s left)
2019-06-07 06:46:54,039 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064654026371
2019-06-07 06:46:54,062 [salt.minion      :1432][INFO    ][21255] Starting a new job with PID 21255
2019-06-07 06:46:54,088 [salt.minion      :1711][INFO    ][21255] Returning information for job: 20190607064654026371
2019-06-07 06:47:05,482 [salt.loaded.ext.module.maas:1023][INFO    ][20289] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1057.82949519s left)
2019-06-07 06:47:24,207 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command saltutil.find_job with jid 20190607064724194657
2019-06-07 06:47:24,231 [salt.minion      :1432][INFO    ][21399] Starting a new job with PID 21399
2019-06-07 06:47:24,258 [salt.minion      :1711][INFO    ][21399] Returning information for job: 20190607064724194657
2019-06-07 06:47:38,769 [salt.state       :300 ][INFO    ][20289] {'ret': True}
2019-06-07 06:47:38,769 [salt.state       :1951][INFO    ][20289] Completed state [maas.wait_for_machine_status] at time 06:47:38.769760 duration_in_ms=475465.237
2019-06-07 06:47:38,773 [salt.minion      :1711][INFO    ][20289] Returning information for job: 20190607063938038980
2019-06-07 06:47:39,253 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607064739240322
2019-06-07 06:47:39,272 [salt.minion      :1432][INFO    ][21424] Starting a new job with PID 21424
2019-06-07 06:47:42,856 [salt.state       :915 ][INFO    ][21424] Loading fresh modules for state activity
2019-06-07 06:47:42,998 [salt.state       :1780][INFO    ][21424] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:42.998051
2019-06-07 06:47:42,998 [salt.state       :1813][INFO    ][21424] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:47:43,000 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21424] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:47:44,326 [salt.state       :300 ][INFO    ][21424] {'pid': 21431, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:47:44,327 [salt.state       :1951][INFO    ][21424] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:44.327303 duration_in_ms=1329.252
2019-06-07 06:47:44,328 [salt.state       :1780][INFO    ][21424] Running state [maas_machines_storage_cmp002_lvm] at time 06:47:44.328667
2019-06-07 06:47:44,328 [salt.state       :1813][INFO    ][21424] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-07 06:47:44,766 [salt.state       :300 ][INFO    ][21424] Machine cmp002 is not in Ready state.
2019-06-07 06:47:44,766 [salt.state       :1951][INFO    ][21424] Completed state [maas_machines_storage_cmp002_lvm] at time 06:47:44.766841 duration_in_ms=438.173
2019-06-07 06:47:44,767 [salt.state       :1780][INFO    ][21424] Running state [maas_machines_storage_cmp001_lvm] at time 06:47:44.767084
2019-06-07 06:47:44,767 [salt.state       :1813][INFO    ][21424] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-07 06:47:45,340 [salt.state       :300 ][INFO    ][21424] Machine cmp001 is not in Ready state.
2019-06-07 06:47:45,340 [salt.state       :1951][INFO    ][21424] Completed state [maas_machines_storage_cmp001_lvm] at time 06:47:45.340887 duration_in_ms=573.8
2019-06-07 06:47:45,345 [salt.minion      :1711][INFO    ][21424] Returning information for job: 20190607064739240322
2019-06-07 06:47:45,981 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607064745967775
2019-06-07 06:47:46,004 [salt.minion      :1432][INFO    ][21441] Starting a new job with PID 21441
2019-06-07 06:47:46,701 [salt.state       :915 ][INFO    ][21441] Loading fresh modules for state activity
2019-06-07 06:47:46,784 [salt.state       :1780][INFO    ][21441] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:46.784530
2019-06-07 06:47:46,784 [salt.state       :1813][INFO    ][21441] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:47:46,786 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21441] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:47:48,223 [salt.state       :300 ][INFO    ][21441] {'pid': 21448, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:47:48,224 [salt.state       :1951][INFO    ][21441] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:48.224148 duration_in_ms=1439.619
2019-06-07 06:47:48,225 [salt.state       :1780][INFO    ][21441] Running state [maas.deploy_machines] at time 06:47:48.225341
2019-06-07 06:47:48,225 [salt.state       :1813][INFO    ][21441] Executing state module.run for [maas.deploy_machines]
2019-06-07 06:47:48,226 [salt.utils.decorators:613 ][WARNING ][21441] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:47:48,969 [salt.state       :300 ][INFO    ][21441] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-07 06:47:48,969 [salt.state       :1951][INFO    ][21441] Completed state [maas.deploy_machines] at time 06:47:48.969863 duration_in_ms=744.52
2019-06-07 06:47:48,973 [salt.minion      :1711][INFO    ][21441] Returning information for job: 20190607064745967775
2019-06-07 06:47:49,590 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command state.apply with jid 20190607064749576966
2019-06-07 06:47:49,612 [salt.minion      :1432][INFO    ][21464] Starting a new job with PID 21464
2019-06-07 06:47:50,346 [salt.state       :915 ][INFO    ][21464] Loading fresh modules for state activity
2019-06-07 06:47:50,435 [salt.state       :1780][INFO    ][21464] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:50.434973
2019-06-07 06:47:50,435 [salt.state       :1813][INFO    ][21464] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-07 06:47:50,437 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21464] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-07 06:47:51,885 [salt.state       :300 ][INFO    ][21464] {'pid': 21471, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-07 06:47:51,885 [salt.state       :1951][INFO    ][21464] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:47:51.885545 duration_in_ms=1450.573
2019-06-07 06:47:51,887 [salt.state       :1780][INFO    ][21464] Running state [maas.wait_for_machine_status] at time 06:47:51.887044
2019-06-07 06:47:51,887 [salt.state       :1813][INFO    ][21464] Executing state module.run for [maas.wait_for_machine_status]
2019-06-07 06:47:51,887 [salt.utils.decorators:613 ][WARNING ][21464] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-07 06:47:55,489 [salt.state       :300 ][INFO    ][21464] {'ret': True}
2019-06-07 06:47:55,489 [salt.state       :1951][INFO    ][21464] Completed state [maas.wait_for_machine_status] at time 06:47:55.489624 duration_in_ms=3602.578
2019-06-07 06:47:55,493 [salt.minion      :1711][INFO    ][21464] Returning information for job: 20190607064749576966
2019-06-07 07:06:37,605 [salt.utils.schedule:1377][INFO    ][10613] Running scheduled job: __mine_interval
2019-06-07 08:06:37,605 [salt.utils.schedule:1377][INFO    ][10613] Running scheduled job: __mine_interval
2019-06-07 08:15:49,598 [salt.minion      :1308][INFO    ][10613] User sudo_ubuntu Executing command cp.push_dir with jid 20190607081549585607
2019-06-07 08:15:49,618 [salt.minion      :1432][INFO    ][27762] Starting a new job with PID 27762
