2019-07-10 05:02:38,176 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-10 05:03:28,224 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-10 05:04:18,266 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-10 05:05:08,312 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-10 05:05:58,364 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-10 05:08:07,368 [salt.utils.decorators:613 ][WARNING ][2699] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 05:08:07,918 [salt.utils.decorators:613 ][WARNING ][2699] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 05:08:10,095 [salt.loaded.int.states.file:2298][WARNING ][2843] 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-07-10 05:08:15,317 [salt.state       :2022][WARNING ][2962] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-10 05:08:17,887 [salt.utils.decorators:613 ][WARNING ][2962] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 05:23:25,854 [salt.utils.decorators:613 ][WARNING ][2962] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 05:48:48,400 [salt.utils.decorators:613 ][WARNING ][2962] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:03:48,694 [salt.utils.decorators:613 ][WARNING ][2962] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:03:52,187 [salt.loaded.ext.module.maasng:1008][WARNING ][2962] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-07-10 06:03:52,188 [salt.loaded.ext.module.maasng:1011][WARNING ][2962] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-07-10 06:03:52,911 [salt.loaded.ext.module.maasng:1235][WARNING ][2962] Ignoring parameter vlan:0
2019-07-10 06:03:53,615 [salt.utils.decorators:613 ][WARNING ][2962] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:03:59,421 [salt.utils.decorators:613 ][WARNING ][6379] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:03:59,505 [salt.loaded.ext.module.maas:412 ][WARNING ][6379] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:04:03,615 [salt.loaded.ext.module.maas:412 ][WARNING ][6379] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:04:08,171 [salt.loaded.ext.module.maas:412 ][WARNING ][6379] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:04:12,435 [salt.loaded.ext.module.maas:412 ][WARNING ][6379] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:04:16,746 [salt.loaded.ext.module.maas:412 ][WARNING ][6379] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:04:22,218 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7309] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-10 06:04:22,249 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7309] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-07-10 06:04:22,272 [salt.utils.parsers:1051][WARNING ][363] Minion received a SIGTERM. Exiting.
2019-07-10 06:04:23,331 [salt.cli.daemons :293 ][INFO    ][7359] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-07-10 06:04:23,424 [salt.cli.daemons :82  ][INFO    ][7359] Starting up the Salt Minion
2019-07-10 06:04:23,424 [salt.utils.event :1017][INFO    ][7359] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-07-10 06:04:24,307 [salt.minion      :976 ][INFO    ][7359] Creating minion process manager
2019-07-10 06:04:25,616 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7359] Executing command ['date', '+%z'] in directory '/root'
2019-07-10 06:04:25,635 [salt.utils.schedule:568 ][INFO    ][7359] Updating job settings for scheduled job: __mine_interval
2019-07-10 06:04:25,637 [salt.minion      :1108][INFO    ][7359] Added mine.update to scheduler
2019-07-10 06:04:25,640 [salt.minion      :1975][INFO    ][7359] Minion is starting as user 'root'
2019-07-10 06:04:25,652 [salt.minion      :2336][INFO    ][7359] Minion is ready to receive requests!
2019-07-10 06:04:50,911 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710060450898164
2019-07-10 06:04:50,933 [salt.minion      :1432][INFO    ][7450] Starting a new job with PID 7450
2019-07-10 06:04:54,495 [salt.state       :915 ][INFO    ][7450] Loading fresh modules for state activity
2019-07-10 06:04:54,546 [salt.fileclient  :1219][INFO    ][7450] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-07-10 06:04:54,586 [salt.state       :1780][INFO    ][7450] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:54.586156
2019-07-10 06:04:54,586 [salt.state       :1813][INFO    ][7450] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:04:54,588 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7450] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:04:55,897 [salt.state       :300 ][INFO    ][7450] {'pid': 7457, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:04:55,897 [salt.state       :1951][INFO    ][7450] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:55.897425 duration_in_ms=1311.269
2019-07-10 06:04:55,898 [salt.state       :1780][INFO    ][7450] Running state [maas.wait_for_machine_status] at time 06:04:55.898885
2019-07-10 06:04:55,899 [salt.state       :1813][INFO    ][7450] Executing state module.run for [maas.wait_for_machine_status]
2019-07-10 06:04:55,899 [salt.utils.decorators:613 ][WARNING ][7450] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:04:56,803 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.10028291s left)
2019-07-10 06:05:05,996 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060505983330
2019-07-10 06:05:06,018 [salt.minion      :1432][INFO    ][7470] Starting a new job with PID 7470
2019-07-10 06:05:06,041 [salt.minion      :1711][INFO    ][7470] Returning information for job: 20190710060505983330
2019-07-10 06:05:27,779 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.12477207s left)
2019-07-10 06:05:36,044 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060536032059
2019-07-10 06:05:36,067 [salt.minion      :1432][INFO    ][7524] Starting a new job with PID 7524
2019-07-10 06:05:36,090 [salt.minion      :1711][INFO    ][7524] Returning information for job: 20190710060536032059
2019-07-10 06:05:58,853 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.05069184s left)
2019-07-10 06:06:06,127 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060606115145
2019-07-10 06:06:06,146 [salt.minion      :1432][INFO    ][7691] Starting a new job with PID 7691
2019-07-10 06:06:06,167 [salt.minion      :1711][INFO    ][7691] Returning information for job: 20190710060606115145
2019-07-10 06:06:30,271 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.63206601s left)
2019-07-10 06:06:36,166 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060636153791
2019-07-10 06:06:36,190 [salt.minion      :1432][INFO    ][7946] Starting a new job with PID 7946
2019-07-10 06:06:36,214 [salt.minion      :1711][INFO    ][7946] Returning information for job: 20190710060636153791
2019-07-10 06:07:01,903 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.00022292s left)
2019-07-10 06:07:06,216 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060706204342
2019-07-10 06:07:06,238 [salt.minion      :1432][INFO    ][8080] Starting a new job with PID 8080
2019-07-10 06:07:06,260 [salt.minion      :1711][INFO    ][8080] Returning information for job: 20190710060706204342
2019-07-10 06:07:33,882 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.02100801s left)
2019-07-10 06:07:36,269 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060736255053
2019-07-10 06:07:36,290 [salt.minion      :1432][INFO    ][8618] Starting a new job with PID 8618
2019-07-10 06:07:36,313 [salt.minion      :1711][INFO    ][8618] Returning information for job: 20190710060736255053
2019-07-10 06:08:06,328 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060806315644
2019-07-10 06:08:06,349 [salt.minion      :1432][INFO    ][8805] Starting a new job with PID 8805
2019-07-10 06:08:06,370 [salt.minion      :1711][INFO    ][8805] Returning information for job: 20190710060806315644
2019-07-10 06:08:07,191 [salt.loaded.ext.module.maas:1023][INFO    ][7450] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1308.71275997s left)
2019-07-10 06:08:36,394 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060836379053
2019-07-10 06:08:36,415 [salt.minion      :1432][INFO    ][9132] Starting a new job with PID 9132
2019-07-10 06:08:36,438 [salt.minion      :1711][INFO    ][9132] Returning information for job: 20190710060836379053
2019-07-10 06:09:06,475 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060906467629
2019-07-10 06:09:06,496 [salt.minion      :1432][INFO    ][9194] Starting a new job with PID 9194
2019-07-10 06:09:06,517 [salt.minion      :1711][INFO    ][9194] Returning information for job: 20190710060906467629
2019-07-10 06:09:36,575 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710060936555211
2019-07-10 06:09:36,597 [salt.minion      :1432][INFO    ][9258] Starting a new job with PID 9258
2019-07-10 06:09:36,619 [salt.minion      :1711][INFO    ][9258] Returning information for job: 20190710060936555211
2019-07-10 06:10:06,666 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061006655435
2019-07-10 06:10:06,685 [salt.minion      :1432][INFO    ][9300] Starting a new job with PID 9300
2019-07-10 06:10:06,700 [salt.minion      :1711][INFO    ][9300] Returning information for job: 20190710061006655435
2019-07-10 06:10:36,745 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061036732166
2019-07-10 06:10:36,767 [salt.minion      :1432][INFO    ][9352] Starting a new job with PID 9352
2019-07-10 06:10:36,788 [salt.minion      :1711][INFO    ][9352] Returning information for job: 20190710061036732166
2019-07-10 06:11:06,857 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061106842694
2019-07-10 06:11:06,881 [salt.minion      :1432][INFO    ][9397] Starting a new job with PID 9397
2019-07-10 06:11:06,903 [salt.minion      :1711][INFO    ][9397] Returning information for job: 20190710061106842694
2019-07-10 06:11:36,988 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061136973816
2019-07-10 06:11:37,010 [salt.minion      :1432][INFO    ][9446] Starting a new job with PID 9446
2019-07-10 06:11:37,032 [salt.minion      :1711][INFO    ][9446] Returning information for job: 20190710061136973816
2019-07-10 06:12:07,102 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061207090019
2019-07-10 06:12:07,122 [salt.minion      :1432][INFO    ][9479] Starting a new job with PID 9479
2019-07-10 06:12:07,146 [salt.minion      :1711][INFO    ][9479] Returning information for job: 20190710061207090019
2019-07-10 06:12:37,239 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061237225896
2019-07-10 06:12:37,261 [salt.minion      :1432][INFO    ][9517] Starting a new job with PID 9517
2019-07-10 06:12:37,280 [salt.minion      :1711][INFO    ][9517] Returning information for job: 20190710061237225896
2019-07-10 06:13:07,370 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061307357664
2019-07-10 06:13:07,392 [salt.minion      :1432][INFO    ][9553] Starting a new job with PID 9553
2019-07-10 06:13:07,416 [salt.minion      :1711][INFO    ][9553] Returning information for job: 20190710061307357664
2019-07-10 06:13:37,509 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061337496431
2019-07-10 06:13:37,532 [salt.minion      :1432][INFO    ][9595] Starting a new job with PID 9595
2019-07-10 06:13:37,556 [salt.minion      :1711][INFO    ][9595] Returning information for job: 20190710061337496431
2019-07-10 06:14:07,668 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061407656204
2019-07-10 06:14:07,686 [salt.minion      :1432][INFO    ][9631] Starting a new job with PID 9631
2019-07-10 06:14:07,702 [salt.minion      :1711][INFO    ][9631] Returning information for job: 20190710061407656204
2019-07-10 06:14:35,284 [salt.state       :302 ][ERROR   ][7450] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-07-10 06:14:35,284 [salt.state       :1951][INFO    ][7450] Completed state [maas.wait_for_machine_status] at time 06:14:35.284876 duration_in_ms=579385.989
2019-07-10 06:14:35,289 [salt.minion      :1711][INFO    ][7450] Returning information for job: 20190710060450898164
2019-07-10 06:14:45,954 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command pillar.get with jid 20190710061445942271
2019-07-10 06:14:45,973 [salt.minion      :1432][INFO    ][9860] Starting a new job with PID 9860
2019-07-10 06:14:45,982 [salt.minion      :1711][INFO    ][9860] Returning information for job: 20190710061445942271
2019-07-10 06:14:46,505 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command service.status with jid 20190710061446493149
2019-07-10 06:14:46,526 [salt.minion      :1432][INFO    ][9866] Starting a new job with PID 9866
2019-07-10 06:14:46,918 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9866] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-07-10 06:14:46,951 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9866] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-07-10 06:14:46,966 [salt.minion      :1711][INFO    ][9866] Returning information for job: 20190710061446493149
2019-07-10 06:14:47,459 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061447448399
2019-07-10 06:14:47,480 [salt.minion      :1432][INFO    ][9878] Starting a new job with PID 9878
2019-07-10 06:14:51,244 [salt.state       :915 ][INFO    ][9878] Loading fresh modules for state activity
2019-07-10 06:14:51,560 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'salt-minion --version' in directory '/root'
2019-07-10 06:14:51,916 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'salt-minion --version' in directory '/root'
2019-07-10 06:14:52,694 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'salt-minion --version' in directory '/root'
2019-07-10 06:14:53,051 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'salt-minion --version' in directory '/root'
2019-07-10 06:14:54,461 [salt.state       :1780][INFO    ][9878] Running state [salt-minion] at time 06:14:54.461098
2019-07-10 06:14:54,461 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [salt-minion]
2019-07-10 06:14:54,461 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-10 06:14:54,541 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,542 [salt.state       :1951][INFO    ][9878] Completed state [salt-minion] at time 06:14:54.542085 duration_in_ms=80.986
2019-07-10 06:14:54,542 [salt.state       :1780][INFO    ][9878] Running state [salt_minion_dependency_packages] at time 06:14:54.542379
2019-07-10 06:14:54,542 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-07-10 06:14:54,548 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,548 [salt.state       :1951][INFO    ][9878] Completed state [salt_minion_dependency_packages] at time 06:14:54.548644 duration_in_ms=6.266
2019-07-10 06:14:54,551 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/minion.d/minion.conf] at time 06:14:54.551367
2019-07-10 06:14:54,551 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-07-10 06:14:54,742 [salt.state       :300 ][INFO    ][9878] File /etc/salt/minion.d/minion.conf is in the correct state
2019-07-10 06:14:54,742 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/minion.d/minion.conf] at time 06:14:54.742593 duration_in_ms=191.226
2019-07-10 06:14:54,742 [salt.state       :1780][INFO    ][9878] Running state [python-netaddr] at time 06:14:54.742797
2019-07-10 06:14:54,743 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [python-netaddr]
2019-07-10 06:14:54,748 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,748 [salt.state       :1951][INFO    ][9878] Completed state [python-netaddr] at time 06:14:54.748354 duration_in_ms=5.556
2019-07-10 06:14:54,750 [salt.state       :1780][INFO    ][9878] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:14:54.750789
2019-07-10 06:14:54,751 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-07-10 06:14:54,758 [salt.state       :300 ][INFO    ][9878] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-07-10 06:14:54,759 [salt.state       :1951][INFO    ][9878] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:14:54.759026 duration_in_ms=8.237
2019-07-10 06:14:54,759 [salt.state       :1780][INFO    ][9878] Running state [salt-minion] at time 06:14:54.759793
2019-07-10 06:14:54,760 [salt.state       :1813][INFO    ][9878] Executing state service.running for [salt-minion]
2019-07-10 06:14:54,760 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-10 06:14:54,796 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-07-10 06:14:54,814 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-07-10 06:14:54,830 [salt.state       :300 ][INFO    ][9878] The service salt-minion is already running
2019-07-10 06:14:54,831 [salt.state       :1951][INFO    ][9878] Completed state [salt-minion] at time 06:14:54.830976 duration_in_ms=71.183
2019-07-10 06:14:54,832 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains.d] at time 06:14:54.832933
2019-07-10 06:14:54,833 [salt.state       :1813][INFO    ][9878] Executing state file.directory for [/etc/salt/grains.d]
2019-07-10 06:14:54,834 [salt.state       :300 ][INFO    ][9878] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-07-10 06:14:54,834 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains.d] at time 06:14:54.834859 duration_in_ms=1.926
2019-07-10 06:14:54,835 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains] at time 06:14:54.835738
2019-07-10 06:14:54,836 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/grains]
2019-07-10 06:14:54,836 [salt.state       :300 ][INFO    ][9878] File /etc/salt/grains exists with proper permissions. No changes made.
2019-07-10 06:14:54,837 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains] at time 06:14:54.837111 duration_in_ms=1.372
2019-07-10 06:14:54,837 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains.d/placeholder] at time 06:14:54.837686
2019-07-10 06:14:54,838 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-07-10 06:14:54,838 [salt.state       :300 ][INFO    ][9878] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-07-10 06:14:54,839 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains.d/placeholder] at time 06:14:54.838940 duration_in_ms=1.255
2019-07-10 06:14:54,839 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains.d/sphinx] at time 06:14:54.839513
2019-07-10 06:14:54,839 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-07-10 06:14:54,856 [salt.state       :300 ][INFO    ][9878] File /etc/salt/grains.d/sphinx is in the correct state
2019-07-10 06:14:54,856 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains.d/sphinx] at time 06:14:54.856511 duration_in_ms=16.998
2019-07-10 06:14:54,859 [salt.state       :1780][INFO    ][9878] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.859155
2019-07-10 06:14:54,859 [salt.state       :1813][INFO    ][9878] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-07-10 06:14:54,859 [salt.state       :300 ][INFO    ][9878] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-07-10 06:14:54,860 [salt.state       :1951][INFO    ][9878] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.860228 duration_in_ms=1.072
2019-07-10 06:14:54,860 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains.d/dns_records] at time 06:14:54.860806
2019-07-10 06:14:54,861 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-07-10 06:14:54,874 [salt.state       :300 ][INFO    ][9878] File /etc/salt/grains.d/dns_records is in the correct state
2019-07-10 06:14:54,874 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains.d/dns_records] at time 06:14:54.874393 duration_in_ms=13.587
2019-07-10 06:14:54,875 [salt.state       :1780][INFO    ][9878] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.875515
2019-07-10 06:14:54,875 [salt.state       :1813][INFO    ][9878] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-07-10 06:14:54,876 [salt.state       :300 ][INFO    ][9878] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-07-10 06:14:54,876 [salt.state       :1951][INFO    ][9878] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.876559 duration_in_ms=1.045
2019-07-10 06:14:54,877 [salt.state       :1780][INFO    ][9878] Running state [/etc/salt/grains.d/salt] at time 06:14:54.877139
2019-07-10 06:14:54,877 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-07-10 06:14:54,892 [salt.state       :300 ][INFO    ][9878] File /etc/salt/grains.d/salt is in the correct state
2019-07-10 06:14:54,892 [salt.state       :1951][INFO    ][9878] Completed state [/etc/salt/grains.d/salt] at time 06:14:54.892259 duration_in_ms=15.12
2019-07-10 06:14:54,893 [salt.state       :1780][INFO    ][9878] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.893331
2019-07-10 06:14:54,893 [salt.state       :1813][INFO    ][9878] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-07-10 06:14:54,894 [salt.state       :300 ][INFO    ][9878] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-07-10 06:14:54,894 [salt.state       :1951][INFO    ][9878] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:14:54.894353 duration_in_ms=1.022
2019-07-10 06:14:54,896 [salt.state       :1780][INFO    ][9878] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:14:54.896557
2019-07-10 06:14:54,896 [salt.state       :1813][INFO    ][9878] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-07-10 06:14:54,897 [salt.state       :300 ][INFO    ][9878] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-07-10 06:14:54,897 [salt.state       :1951][INFO    ][9878] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:14:54.897563 duration_in_ms=1.006
2019-07-10 06:14:54,898 [salt.state       :1780][INFO    ][9878] Running state [mine.update] at time 06:14:54.898342
2019-07-10 06:14:54,898 [salt.state       :1813][INFO    ][9878] Executing state module.wait for [mine.update]
2019-07-10 06:14:54,899 [salt.state       :300 ][INFO    ][9878] No changes made for mine.update
2019-07-10 06:14:54,899 [salt.state       :1951][INFO    ][9878] Completed state [mine.update] at time 06:14:54.899266 duration_in_ms=0.925
2019-07-10 06:14:54,899 [salt.state       :1780][INFO    ][9878] Running state [ca-certificates] at time 06:14:54.899566
2019-07-10 06:14:54,899 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [ca-certificates]
2019-07-10 06:14:54,908 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,908 [salt.state       :1951][INFO    ][9878] Completed state [ca-certificates] at time 06:14:54.908468 duration_in_ms=8.902
2019-07-10 06:14:54,909 [salt.state       :1780][INFO    ][9878] Running state [update-ca-certificates] at time 06:14:54.909262
2019-07-10 06:14:54,909 [salt.state       :1813][INFO    ][9878] Executing state cmd.wait for [update-ca-certificates]
2019-07-10 06:14:54,910 [salt.state       :300 ][INFO    ][9878] No changes made for update-ca-certificates
2019-07-10 06:14:54,910 [salt.state       :1951][INFO    ][9878] Completed state [update-ca-certificates] at time 06:14:54.910199 duration_in_ms=0.938
2019-07-10 06:14:54,910 [salt.state       :1780][INFO    ][9878] Running state [iptables] at time 06:14:54.910480
2019-07-10 06:14:54,910 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [iptables]
2019-07-10 06:14:54,918 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,918 [salt.state       :1951][INFO    ][9878] Completed state [iptables] at time 06:14:54.918738 duration_in_ms=8.257
2019-07-10 06:14:54,919 [salt.state       :1780][INFO    ][9878] Running state [iptables-persistent] at time 06:14:54.919003
2019-07-10 06:14:54,919 [salt.state       :1813][INFO    ][9878] Executing state pkg.installed for [iptables-persistent]
2019-07-10 06:14:54,926 [salt.state       :300 ][INFO    ][9878] All specified packages are already installed
2019-07-10 06:14:54,926 [salt.state       :1951][INFO    ][9878] Completed state [iptables-persistent] at time 06:14:54.926862 duration_in_ms=7.858
2019-07-10 06:14:54,928 [salt.state       :1780][INFO    ][9878] Running state [iptables_modules_v4_load] at time 06:14:54.927963
2019-07-10 06:14:54,928 [salt.state       :1813][INFO    ][9878] Executing state kmod.present for [iptables_modules_v4_load]
2019-07-10 06:14:54,928 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'lsmod' in directory '/root'
2019-07-10 06:14:54,953 [salt.state       :300 ][INFO    ][9878] Kernel modules iptable_filter, ip_tables are already present
2019-07-10 06:14:54,953 [salt.state       :1951][INFO    ][9878] Completed state [iptables_modules_v4_load] at time 06:14:54.953547 duration_in_ms=25.584
2019-07-10 06:14:54,954 [salt.state       :1780][INFO    ][9878] Running state [/etc/iptables/rules.v4] at time 06:14:54.954195
2019-07-10 06:14:54,954 [salt.state       :1813][INFO    ][9878] Executing state file.managed for [/etc/iptables/rules.v4]
2019-07-10 06:14:55,042 [salt.state       :300 ][INFO    ][9878] File /etc/iptables/rules.v4 is in the correct state
2019-07-10 06:14:55,042 [salt.state       :1951][INFO    ][9878] Completed state [/etc/iptables/rules.v4] at time 06:14:55.042855 duration_in_ms=88.659
2019-07-10 06:14:55,044 [salt.state       :1780][INFO    ][9878] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:14:55.044706
2019-07-10 06:14:55,045 [salt.state       :1813][INFO    ][9878] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-07-10 06:14:55,046 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-07-10 06:14:55,066 [salt.state       :300 ][INFO    ][9878] onlyif execution failed
2019-07-10 06:14:55,067 [salt.state       :1951][INFO    ][9878] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:14:55.067449 duration_in_ms=22.744
2019-07-10 06:14:55,069 [salt.state       :1780][INFO    ][9878] Running state [netfilter-persistent] at time 06:14:55.069132
2019-07-10 06:14:55,069 [salt.state       :1813][INFO    ][9878] Executing state service.running for [netfilter-persistent]
2019-07-10 06:14:55,070 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-07-10 06:14:55,092 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-07-10 06:14:55,110 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-07-10 06:14:55,128 [salt.state       :300 ][INFO    ][9878] The service netfilter-persistent is already running
2019-07-10 06:14:55,129 [salt.state       :1951][INFO    ][9878] Completed state [netfilter-persistent] at time 06:14:55.129127 duration_in_ms=59.995
2019-07-10 06:14:55,130 [salt.state       :1780][INFO    ][9878] Running state [iptables_extra.remove_stale_tables] at time 06:14:55.130515
2019-07-10 06:14:55,131 [salt.state       :1813][INFO    ][9878] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-07-10 06:14:55,131 [salt.state       :300 ][INFO    ][9878] No changes made for iptables_extra.remove_stale_tables
2019-07-10 06:14:55,132 [salt.state       :1951][INFO    ][9878] Completed state [iptables_extra.remove_stale_tables] at time 06:14:55.131951 duration_in_ms=1.437
2019-07-10 06:14:55,132 [salt.state       :1780][INFO    ][9878] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:14:55.132344
2019-07-10 06:14:55,132 [salt.state       :1813][INFO    ][9878] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-07-10 06:14:55,133 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9878] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-07-10 06:14:55,149 [salt.state       :300 ][INFO    ][9878] onlyif execution failed
2019-07-10 06:14:55,149 [salt.state       :1951][INFO    ][9878] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:14:55.149863 duration_in_ms=17.519
2019-07-10 06:14:55,151 [salt.state       :1780][INFO    ][9878] Running state [/etc/iptables/rules.v6] at time 06:14:55.151416
2019-07-10 06:14:55,152 [salt.state       :1813][INFO    ][9878] Executing state file.absent for [/etc/iptables/rules.v6]
2019-07-10 06:14:55,152 [salt.state       :300 ][INFO    ][9878] File /etc/iptables/rules.v6 is not present
2019-07-10 06:14:55,153 [salt.state       :1951][INFO    ][9878] Completed state [/etc/iptables/rules.v6] at time 06:14:55.153043 duration_in_ms=1.627
2019-07-10 06:14:55,154 [salt.state       :1780][INFO    ][9878] Running state [iptables_extra.flush_all] at time 06:14:55.154153
2019-07-10 06:14:55,154 [salt.state       :1813][INFO    ][9878] Executing state module.wait for [iptables_extra.flush_all]
2019-07-10 06:14:55,155 [salt.state       :300 ][INFO    ][9878] No changes made for iptables_extra.flush_all
2019-07-10 06:14:55,155 [salt.state       :1951][INFO    ][9878] Completed state [iptables_extra.flush_all] at time 06:14:55.155431 duration_in_ms=1.278
2019-07-10 06:14:55,160 [salt.minion      :1711][INFO    ][9878] Returning information for job: 20190710061447448399
2019-07-10 06:14:55,795 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061455782939
2019-07-10 06:14:55,817 [salt.minion      :1432][INFO    ][9953] Starting a new job with PID 9953
2019-07-10 06:14:56,548 [salt.state       :915 ][INFO    ][9953] Loading fresh modules for state activity
2019-07-10 06:14:57,139 [salt.state       :1780][INFO    ][9953] Running state [maas-rack-controller] at time 06:14:57.139293
2019-07-10 06:14:57,139 [salt.state       :1813][INFO    ][9953] Executing state pkg.installed for [maas-rack-controller]
2019-07-10 06:14:57,140 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9953] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-10 06:14:57,221 [salt.state       :300 ][INFO    ][9953] All specified packages are already installed
2019-07-10 06:14:57,221 [salt.state       :1951][INFO    ][9953] Completed state [maas-rack-controller] at time 06:14:57.221536 duration_in_ms=82.244
2019-07-10 06:14:57,221 [salt.state       :1780][INFO    ][9953] Running state [ipmitool] at time 06:14:57.221797
2019-07-10 06:14:57,222 [salt.state       :1813][INFO    ][9953] Executing state pkg.installed for [ipmitool]
2019-07-10 06:14:57,227 [salt.state       :300 ][INFO    ][9953] All specified packages are already installed
2019-07-10 06:14:57,227 [salt.state       :1951][INFO    ][9953] Completed state [ipmitool] at time 06:14:57.227175 duration_in_ms=5.379
2019-07-10 06:14:57,229 [salt.state       :1780][INFO    ][9953] Running state [/etc/maas/rackd.conf] at time 06:14:57.229562
2019-07-10 06:14:57,229 [salt.state       :1813][INFO    ][9953] Executing state file.line for [/etc/maas/rackd.conf]
2019-07-10 06:14:57,230 [salt.state       :300 ][INFO    ][9953] No changes needed to be made
2019-07-10 06:14:57,230 [salt.state       :1951][INFO    ][9953] Completed state [/etc/maas/rackd.conf] at time 06:14:57.230751 duration_in_ms=1.19
2019-07-10 06:14:57,230 [salt.state       :1780][INFO    ][9953] Running state [/etc/maas/rackd.conf] at time 06:14:57.230932
2019-07-10 06:14:57,231 [salt.state       :1813][INFO    ][9953] Executing state file.managed for [/etc/maas/rackd.conf]
2019-07-10 06:14:57,231 [salt.loaded.int.states.file:2298][WARNING ][9953] 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-07-10 06:14:57,231 [salt.state       :300 ][INFO    ][9953] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-07-10 06:14:57,231 [salt.state       :1951][INFO    ][9953] Completed state [/etc/maas/rackd.conf] at time 06:14:57.231901 duration_in_ms=0.969
2019-07-10 06:14:57,232 [salt.state       :1780][INFO    ][9953] Running state [maas-rackd] at time 06:14:57.232670
2019-07-10 06:14:57,232 [salt.state       :1813][INFO    ][9953] Executing state service.running for [maas-rackd]
2019-07-10 06:14:57,233 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9953] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-07-10 06:14:57,266 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9953] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-07-10 06:14:57,282 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9953] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-07-10 06:14:57,297 [salt.state       :300 ][INFO    ][9953] The service maas-rackd is already running
2019-07-10 06:14:57,298 [salt.state       :1951][INFO    ][9953] Completed state [maas-rackd] at time 06:14:57.298214 duration_in_ms=65.544
2019-07-10 06:14:57,299 [salt.minion      :1711][INFO    ][9953] Returning information for job: 20190710061455782939
2019-07-10 06:14:57,801 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061457788455
2019-07-10 06:14:57,821 [salt.minion      :1432][INFO    ][9977] Starting a new job with PID 9977
2019-07-10 06:14:58,544 [salt.state       :915 ][INFO    ][9977] Loading fresh modules for state activity
2019-07-10 06:14:59,248 [salt.state       :1780][INFO    ][9977] Running state [maas-region-controller] at time 06:14:59.248790
2019-07-10 06:14:59,249 [salt.state       :1813][INFO    ][9977] Executing state pkg.installed for [maas-region-controller]
2019-07-10 06:14:59,249 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-10 06:14:59,328 [salt.state       :300 ][INFO    ][9977] All specified packages are already installed
2019-07-10 06:14:59,328 [salt.state       :1951][INFO    ][9977] Completed state [maas-region-controller] at time 06:14:59.328725 duration_in_ms=79.934
2019-07-10 06:14:59,329 [salt.state       :1780][INFO    ][9977] Running state [python-oauth] at time 06:14:59.328994
2019-07-10 06:14:59,329 [salt.state       :1813][INFO    ][9977] Executing state pkg.installed for [python-oauth]
2019-07-10 06:14:59,334 [salt.state       :300 ][INFO    ][9977] All specified packages are already installed
2019-07-10 06:14:59,334 [salt.state       :1951][INFO    ][9977] Completed state [python-oauth] at time 06:14:59.334523 duration_in_ms=5.528
2019-07-10 06:14:59,337 [salt.state       :1780][INFO    ][9977] Running state [/etc/maas/regiond.conf] at time 06:14:59.337012
2019-07-10 06:14:59,337 [salt.state       :1813][INFO    ][9977] Executing state file.replace for [/etc/maas/regiond.conf]
2019-07-10 06:14:59,390 [salt.state       :300 ][INFO    ][9977] No changes needed to be made
2019-07-10 06:14:59,390 [salt.state       :1951][INFO    ][9977] Completed state [/etc/maas/regiond.conf] at time 06:14:59.390576 duration_in_ms=53.564
2019-07-10 06:14:59,391 [salt.state       :1780][INFO    ][9977] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:14:59.391142
2019-07-10 06:14:59,391 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-07-10 06:14:59,455 [salt.state       :300 ][INFO    ][9977] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-07-10 06:14:59,455 [salt.state       :1951][INFO    ][9977] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:14:59.455572 duration_in_ms=64.429
2019-07-10 06:14:59,456 [salt.state       :1780][INFO    ][9977] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:59.456057
2019-07-10 06:14:59,456 [salt.state       :1813][INFO    ][9977] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-10 06:14:59,468 [salt.state       :300 ][INFO    ][9977] No changes needed to be made
2019-07-10 06:14:59,469 [salt.state       :1951][INFO    ][9977] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:59.469053 duration_in_ms=12.996
2019-07-10 06:14:59,469 [salt.state       :1780][INFO    ][9977] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:59.469550
2019-07-10 06:14:59,469 [salt.state       :1813][INFO    ][9977] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-10 06:14:59,492 [salt.state       :300 ][INFO    ][9977] No changes needed to be made
2019-07-10 06:14:59,492 [salt.state       :1951][INFO    ][9977] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:59.492911 duration_in_ms=23.361
2019-07-10 06:14:59,493 [salt.state       :1780][INFO    ][9977] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:14:59.493403
2019-07-10 06:14:59,493 [salt.state       :1813][INFO    ][9977] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-07-10 06:14:59,517 [salt.state       :300 ][INFO    ][9977] No changes needed to be made
2019-07-10 06:14:59,517 [salt.state       :1951][INFO    ][9977] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:14:59.517346 duration_in_ms=23.943
2019-07-10 06:14:59,517 [salt.state       :1780][INFO    ][9977] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:14:59.517821
2019-07-10 06:14:59,518 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-07-10 06:14:59,529 [salt.state       :300 ][INFO    ][9977] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-07-10 06:14:59,529 [salt.state       :1951][INFO    ][9977] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:14:59.529521 duration_in_ms=11.7
2019-07-10 06:14:59,530 [salt.state       :1780][INFO    ][9977] Running state [a2enmod headers] at time 06:14:59.530708
2019-07-10 06:14:59,531 [salt.state       :1813][INFO    ][9977] Executing state cmd.run for [a2enmod headers]
2019-07-10 06:14:59,531 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command 'a2enmod headers' in directory '/root'
2019-07-10 06:14:59,606 [salt.state       :300 ][INFO    ][9977] {'pid': 9996, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-07-10 06:14:59,607 [salt.state       :1951][INFO    ][9977] Completed state [a2enmod headers] at time 06:14:59.607098 duration_in_ms=76.389
2019-07-10 06:14:59,607 [salt.state       :1780][INFO    ][9977] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:14:59.607629
2019-07-10 06:14:59,608 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-07-10 06:14:59,625 [salt.state       :300 ][INFO    ][9977] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-07-10 06:14:59,625 [salt.state       :1951][INFO    ][9977] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:14:59.625853 duration_in_ms=18.223
2019-07-10 06:14:59,626 [salt.state       :1780][INFO    ][9977] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:14:59.626643
2019-07-10 06:14:59,627 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-07-10 06:14:59,714 [salt.state       :300 ][INFO    ][9977] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-07-10 06:14:59,714 [salt.state       :1951][INFO    ][9977] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:14:59.714853 duration_in_ms=88.208
2019-07-10 06:14:59,716 [salt.state       :1780][INFO    ][9977] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:14:59.715965
2019-07-10 06:14:59,716 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-07-10 06:14:59,791 [salt.state       :300 ][INFO    ][9977] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-07-10 06:14:59,791 [salt.state       :1951][INFO    ][9977] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:14:59.791435 duration_in_ms=75.47
2019-07-10 06:14:59,792 [salt.state       :1780][INFO    ][9977] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:14:59.792110
2019-07-10 06:14:59,792 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-07-10 06:14:59,861 [salt.state       :300 ][INFO    ][9977] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-07-10 06:14:59,861 [salt.state       :1951][INFO    ][9977] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:14:59.861531 duration_in_ms=69.421
2019-07-10 06:14:59,861 [salt.state       :1780][INFO    ][9977] Running state [/root/.pgpass] at time 06:14:59.861871
2019-07-10 06:14:59,862 [salt.state       :1813][INFO    ][9977] Executing state file.managed for [/root/.pgpass]
2019-07-10 06:14:59,909 [salt.state       :300 ][INFO    ][9977] File /root/.pgpass is in the correct state
2019-07-10 06:14:59,909 [salt.state       :1951][INFO    ][9977] Completed state [/root/.pgpass] at time 06:14:59.909302 duration_in_ms=47.43
2019-07-10 06:14:59,915 [salt.state       :1780][INFO    ][9977] Running state [maas-region syncdb --noinput] at time 06:14:59.915113
2019-07-10 06:14:59,915 [salt.state       :1813][INFO    ][9977] Executing state cmd.run for [maas-region syncdb --noinput]
2019-07-10 06:14:59,916 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-07-10 06:15:01,884 [salt.state       :300 ][INFO    ][9977] {'pid': 10009, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, piston3, sites, maasserver, contenttypes, metadataserver, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-07-10 06:15:01,885 [salt.state       :1951][INFO    ][9977] Completed state [maas-region syncdb --noinput] at time 06:15:01.885078 duration_in_ms=1969.966
2019-07-10 06:15:01,885 [salt.state       :2022][WARNING ][9977] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-10 06:15:01,886 [salt.state       :1780][INFO    ][9977] Running state [maas-regiond] at time 06:15:01.886343
2019-07-10 06:15:01,886 [salt.state       :1813][INFO    ][9977] Executing state service.running for [maas-regiond]
2019-07-10 06:15:01,887 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-07-10 06:15:01,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-07-10 06:15:01,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-07-10 06:15:01,949 [salt.state       :300 ][INFO    ][9977] The service maas-regiond is already running
2019-07-10 06:15:01,950 [salt.state       :1951][INFO    ][9977] Completed state [maas-regiond] at time 06:15:01.949986 duration_in_ms=63.643
2019-07-10 06:15:01,951 [salt.state       :1780][INFO    ][9977] Running state [bind9] at time 06:15:01.951060
2019-07-10 06:15:01,951 [salt.state       :1813][INFO    ][9977] Executing state service.running for [bind9]
2019-07-10 06:15:01,951 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-07-10 06:15:01,967 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-07-10 06:15:01,982 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-07-10 06:15:01,996 [salt.state       :300 ][INFO    ][9977] The service bind9 is already running
2019-07-10 06:15:01,996 [salt.state       :1951][INFO    ][9977] Completed state [bind9] at time 06:15:01.996569 duration_in_ms=45.51
2019-07-10 06:15:01,997 [salt.state       :1780][INFO    ][9977] Running state [apache2] at time 06:15:01.997656
2019-07-10 06:15:01,997 [salt.state       :1813][INFO    ][9977] Executing state service.running for [apache2]
2019-07-10 06:15:01,998 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-07-10 06:15:02,014 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-07-10 06:15:02,028 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-07-10 06:15:02,046 [salt.state       :300 ][INFO    ][9977] The service apache2 is already running
2019-07-10 06:15:02,046 [salt.state       :1951][INFO    ][9977] Completed state [apache2] at time 06:15:02.046782 duration_in_ms=49.126
2019-07-10 06:15:02,047 [salt.state       :1780][INFO    ][9977] Running state [maasng.wait_for_http_code] at time 06:15:02.047854
2019-07-10 06:15:02,048 [salt.state       :1813][INFO    ][9977] Executing state module.run for [maasng.wait_for_http_code]
2019-07-10 06:15:02,048 [salt.utils.decorators:613 ][WARNING ][9977] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:02,140 [salt.state       :300 ][INFO    ][9977] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-07-10 06:15:02,140 [salt.state       :1951][INFO    ][9977] Completed state [maasng.wait_for_http_code] at time 06:15:02.140927 duration_in_ms=93.072
2019-07-10 06:15:02,141 [salt.state       :1780][INFO    ][9977] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:15:02.141592
2019-07-10 06:15:02,141 [salt.state       :1813][INFO    ][9977] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-07-10 06:15:02,142 [salt.state       :300 ][INFO    ][9977] /var/lib/maas/.setup_admin exists
2019-07-10 06:15:02,143 [salt.state       :1951][INFO    ][9977] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:15:02.143090 duration_in_ms=1.496
2019-07-10 06:15:02,144 [salt.state       :1780][INFO    ][9977] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:02.144396
2019-07-10 06:15:02,144 [salt.state       :1813][INFO    ][9977] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:15:02,145 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9977] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:15:03,592 [salt.state       :300 ][INFO    ][9977] {'pid': 10030, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:15:03,593 [salt.state       :1951][INFO    ][9977] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:03.593458 duration_in_ms=1449.061
2019-07-10 06:15:03,605 [salt.state       :1780][INFO    ][9977] Running state [maas_region_boot_source_resources_mirror] at time 06:15:03.605025
2019-07-10 06:15:03,605 [salt.state       :1813][INFO    ][9977] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-07-10 06:15:03,716 [salt.state       :300 ][INFO    ][9977] {'changes': {}}
2019-07-10 06:15:03,717 [salt.state       :1951][INFO    ][9977] Completed state [maas_region_boot_source_resources_mirror] at time 06:15:03.717273 duration_in_ms=112.247
2019-07-10 06:15:03,718 [salt.state       :1780][INFO    ][9977] Running state [maasng.boot_resources_import] at time 06:15:03.718476
2019-07-10 06:15:03,719 [salt.state       :1813][INFO    ][9977] Executing state module.run for [maasng.boot_resources_import]
2019-07-10 06:15:03,719 [salt.utils.decorators:613 ][WARNING ][9977] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:06,851 [salt.loaded.ext.module.maasng:1600][INFO    ][9977] Waiting boot-resources import done
sleep for:5s Left:897.0/900s
2019-07-10 06:15:11,905 [salt.loaded.ext.module.maasng:1600][INFO    ][9977] Waiting boot-resources import done
sleep for:5s Left:892.0/900s
2019-07-10 06:15:12,821 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061512805437
2019-07-10 06:15:12,843 [salt.minion      :1432][INFO    ][10073] Starting a new job with PID 10073
2019-07-10 06:15:12,867 [salt.minion      :1711][INFO    ][10073] Returning information for job: 20190710061512805437
2019-07-10 06:15:17,020 [salt.state       :300 ][INFO    ][9977] {'ret': True}
2019-07-10 06:15:17,020 [salt.state       :1951][INFO    ][9977] Completed state [maasng.boot_resources_import] at time 06:15:17.020761 duration_in_ms=13302.284
2019-07-10 06:15:17,022 [salt.state       :1780][INFO    ][9977] Running state [maas_region_boot_sources_selection_xenial] at time 06:15:17.021998
2019-07-10 06:15:17,022 [salt.state       :1813][INFO    ][9977] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-07-10 06:15:17,303 [salt.state       :300 ][INFO    ][9977] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-07-10 06:15:17,304 [salt.state       :1951][INFO    ][9977] Completed state [maas_region_boot_sources_selection_xenial] at time 06:15:17.304122 duration_in_ms=282.122
2019-07-10 06:15:17,305 [salt.state       :1780][INFO    ][9977] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:15:17.305709
2019-07-10 06:15:17,306 [salt.state       :1813][INFO    ][9977] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-07-10 06:15:17,307 [salt.utils.decorators:613 ][WARNING ][9977] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:17,307 [salt.loaded.ext.module.maasng:1771][INFO    ][9977] boot-sources sync initiated for ALL Rack's
2019-07-10 06:15:18,186 [salt.state       :300 ][INFO    ][9977] {'ret': True}
2019-07-10 06:15:18,187 [salt.state       :1951][INFO    ][9977] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:15:18.187133 duration_in_ms=881.425
2019-07-10 06:15:18,189 [salt.state       :1780][INFO    ][9977] Running state [maas.process_maas_config] at time 06:15:18.189514
2019-07-10 06:15:18,190 [salt.state       :1813][INFO    ][9977] Executing state module.run for [maas.process_maas_config]
2019-07-10 06:15:18,190 [salt.utils.decorators:613 ][WARNING ][9977] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:18,191 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=enable_http_proxy value=True
2019-07-10 06:15:18,248 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=upstream_dns value=8.8.8.8
2019-07-10 06:15:18,357 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=commissioning_distro_series value=xenial
2019-07-10 06:15:21,399 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=default_osystem value=ubuntu
2019-07-10 06:15:21,467 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=active_discovery_interval value=600
2019-07-10 06:15:21,527 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=dnssec_validation value=no
2019-07-10 06:15:21,585 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=maas_name value=mas01
2019-07-10 06:15:21,625 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=network_discovery value=enabled
2019-07-10 06:15:21,747 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=enable_third_party_drivers value=True
2019-07-10 06:15:21,793 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=default_storage_layout value=lvm
2019-07-10 06:15:21,841 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=ntp_external_only value=True
2019-07-10 06:15:21,882 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=disk_erase_with_secure_erase value=False
2019-07-10 06:15:21,937 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=default_distro_series value=xenial
2019-07-10 06:15:22,017 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-07-10 06:15:22,152 [salt.state       :300 ][INFO    ][9977] {'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-07-10 06:15:22,152 [salt.state       :1951][INFO    ][9977] Completed state [maas.process_maas_config] at time 06:15:22.152853 duration_in_ms=3963.34
2019-07-10 06:15:22,153 [salt.state       :1780][INFO    ][9977] Running state [pxe_admin] at time 06:15:22.153844
2019-07-10 06:15:22,154 [salt.state       :1813][INFO    ][9977] Executing state maasng.fabric_present for [pxe_admin]
2019-07-10 06:15:22,213 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', 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-07-10 06:15:22,273 [salt.loaded.ext.module.maasng:1008][WARNING ][9977] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-07-10 06:15:22,274 [salt.loaded.ext.module.maasng:1011][WARNING ][9977] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-07-10 06:15:22,340 [salt.state       :300 ][INFO    ][9977] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-07-10 06:15:22,340 [salt.state       :1951][INFO    ][9977] Completed state [pxe_admin] at time 06:15:22.340805 duration_in_ms=186.959
2019-07-10 06:15:22,341 [salt.state       :1780][INFO    ][9977] Running state [vlan 0] at time 06:15:22.341301
2019-07-10 06:15:22,341 [salt.state       :1813][INFO    ][9977] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-10 06:15:22,410 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'b4we86', 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'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-07-10 06:15:22,529 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', 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-07-10 06:15:22,795 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'b4we86', 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'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-07-10 06:15:22,885 [salt.state       :300 ][INFO    ][9977] {'new': 'Vlan untagged was updated'}
2019-07-10 06:15:22,886 [salt.state       :1951][INFO    ][9977] Completed state [vlan 0] at time 06:15:22.885979 duration_in_ms=544.678
2019-07-10 06:15:22,887 [salt.state       :1780][INFO    ][9977] Running state [192.168.11.0/24] at time 06:15:22.887503
2019-07-10 06:15:22,888 [salt.state       :1813][INFO    ][9977] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-07-10 06:15:23,098 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', 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-07-10 06:15:23,099 [salt.loaded.ext.module.maasng:1235][WARNING ][9977] Ignoring parameter vlan:0
2019-07-10 06:15:23,196 [salt.state       :300 ][INFO    ][9977] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-07-10 06:15:23,197 [salt.state       :1951][INFO    ][9977] Completed state [192.168.11.0/24] at time 06:15:23.196896 duration_in_ms=309.392
2019-07-10 06:15:23,198 [salt.state       :1780][INFO    ][9977] Running state [maas_create_iprange_1] at time 06:15:23.198213
2019-07-10 06:15:23,198 [salt.state       :1813][INFO    ][9977] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-07-10 06:15:23,254 [salt.state       :300 ][INFO    ][9977] Iprange maas_create_iprange_1 already exist.
2019-07-10 06:15:23,255 [salt.state       :1951][INFO    ][9977] Completed state [maas_create_iprange_1] at time 06:15:23.255196 duration_in_ms=56.982
2019-07-10 06:15:23,255 [salt.state       :1780][INFO    ][9977] Running state [vlan 0] at time 06:15:23.255756
2019-07-10 06:15:23,256 [salt.state       :1813][INFO    ][9977] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-10 06:15:23,326 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-07-10 06:15:23,442 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-07-10 06:15:23,633 [salt.loaded.ext.module.maasng:945 ][INFO    ][9977] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', 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-07-10 06:15:23,724 [salt.state       :300 ][INFO    ][9977] {'new': 'Vlan untagged was updated'}
2019-07-10 06:15:23,724 [salt.state       :1951][INFO    ][9977] Completed state [vlan 0] at time 06:15:23.724364 duration_in_ms=468.608
2019-07-10 06:15:23,725 [salt.state       :1780][INFO    ][9977] Running state [opnfv] at time 06:15:23.725228
2019-07-10 06:15:23,725 [salt.state       :1813][INFO    ][9977] Executing state maasng.sshkey_present for [opnfv]
2019-07-10 06:15:23,769 [salt.loaded.ext.module.maasng:1903][INFO    ][9977] [{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-07-10 06:15:23,770 [salt.state       :300 ][INFO    ][9977] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-07-10 06:15:23,770 [salt.state       :1951][INFO    ][9977] Completed state [opnfv] at time 06:15:23.770390 duration_in_ms=45.162
2019-07-10 06:15:23,771 [salt.state       :1780][INFO    ][9977] Running state [maas.process_tags] at time 06:15:23.771399
2019-07-10 06:15:23,771 [salt.state       :1813][INFO    ][9977] Executing state module.run for [maas.process_tags]
2019-07-10 06:15:23,772 [salt.utils.decorators:613 ][WARNING ][9977] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:23,811 [salt.loaded.ext.module.maas:92  ][INFO    ][9977] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-07-10 06:15:23,892 [salt.state       :300 ][INFO    ][9977] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-07-10 06:15:23,892 [salt.state       :1951][INFO    ][9977] Completed state [maas.process_tags] at time 06:15:23.892564 duration_in_ms=121.166
2019-07-10 06:15:23,897 [salt.minion      :1711][INFO    ][9977] Returning information for job: 20190710061457788455
2019-07-10 06:15:24,424 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061524412413
2019-07-10 06:15:24,442 [salt.minion      :1432][INFO    ][10459] Starting a new job with PID 10459
2019-07-10 06:15:28,102 [salt.state       :915 ][INFO    ][10459] Loading fresh modules for state activity
2019-07-10 06:15:28,201 [salt.state       :1780][INFO    ][10459] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:28.201046
2019-07-10 06:15:28,201 [salt.state       :1813][INFO    ][10459] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:15:28,203 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10459] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:15:29,663 [salt.state       :300 ][INFO    ][10459] {'pid': 10483, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:15:29,664 [salt.state       :1951][INFO    ][10459] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:29.663986 duration_in_ms=1462.939
2019-07-10 06:15:29,666 [salt.state       :1780][INFO    ][10459] Running state [maas.process_machines] at time 06:15:29.666626
2019-07-10 06:15:29,667 [salt.state       :1813][INFO    ][10459] Executing state module.run for [maas.process_machines]
2019-07-10 06:15:29,668 [salt.utils.decorators:613 ][WARNING ][10459] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:15:30,182 [salt.loaded.ext.module.maas:412 ][WARNING ][10459] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:15:30,182 [salt.loaded.ext.module.maas:92  ][INFO    ][10459] 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=xqw7wm architecture=amd64/generic power_parameters_power_user=admin
2019-07-10 06:15:31,294 [salt.loaded.ext.module.maas:412 ][WARNING ][10459] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:15:31,295 [salt.loaded.ext.module.maas:92  ][INFO    ][10459] 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=hgsk4w architecture=amd64/generic power_parameters_power_user=admin
2019-07-10 06:15:32,629 [salt.loaded.ext.module.maas:412 ][WARNING ][10459] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:15:32,630 [salt.loaded.ext.module.maas:92  ][INFO    ][10459] 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=8kegfc architecture=amd64/generic power_parameters_power_user=admin
2019-07-10 06:15:33,862 [salt.loaded.ext.module.maas:412 ][WARNING ][10459] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:15:33,864 [salt.loaded.ext.module.maas:92  ][INFO    ][10459] 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=4xf8ye architecture=amd64/generic power_parameters_power_user=admin
2019-07-10 06:15:35,180 [salt.loaded.ext.module.maas:412 ][WARNING ][10459] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-10 06:15:35,181 [salt.loaded.ext.module.maas:92  ][INFO    ][10459] 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=x63xp8 architecture=amd64/generic power_parameters_power_user=admin
2019-07-10 06:15:36,300 [salt.state       :300 ][INFO    ][10459] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-07-10 06:15:36,301 [salt.state       :1951][INFO    ][10459] Completed state [maas.process_machines] at time 06:15:36.301081 duration_in_ms=6634.454
2019-07-10 06:15:36,304 [salt.minion      :1711][INFO    ][10459] Returning information for job: 20190710061524412413
2019-07-10 06:16:07,378 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061607365745
2019-07-10 06:16:07,399 [salt.minion      :1432][INFO    ][10715] Starting a new job with PID 10715
2019-07-10 06:16:11,120 [salt.state       :915 ][INFO    ][10715] Loading fresh modules for state activity
2019-07-10 06:16:11,166 [salt.state       :1780][INFO    ][10715] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:11.166833
2019-07-10 06:16:11,167 [salt.state       :1813][INFO    ][10715] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:16:11,168 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10715] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:16:12,556 [salt.state       :300 ][INFO    ][10715] {'pid': 10722, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:16:12,557 [salt.state       :1951][INFO    ][10715] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:12.557403 duration_in_ms=1390.568
2019-07-10 06:16:12,559 [salt.state       :1780][INFO    ][10715] Running state [maas.wait_for_machine_status] at time 06:16:12.559819
2019-07-10 06:16:12,560 [salt.state       :1813][INFO    ][10715] Executing state module.run for [maas.wait_for_machine_status]
2019-07-10 06:16:12,560 [salt.utils.decorators:613 ][WARNING ][10715] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:16:15,118 [salt.state       :300 ][INFO    ][10715] {'ret': True}
2019-07-10 06:16:15,119 [salt.state       :1951][INFO    ][10715] Completed state [maas.wait_for_machine_status] at time 06:16:15.119304 duration_in_ms=2559.482
2019-07-10 06:16:15,122 [salt.minion      :1711][INFO    ][10715] Returning information for job: 20190710061607365745
2019-07-10 06:16:15,711 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061615699037
2019-07-10 06:16:15,734 [salt.minion      :1432][INFO    ][10757] Starting a new job with PID 10757
2019-07-10 06:16:16,483 [salt.state       :915 ][INFO    ][10757] Loading fresh modules for state activity
2019-07-10 06:16:16,536 [salt.fileclient  :1219][INFO    ][10757] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-07-10 06:16:16,641 [salt.state       :1780][INFO    ][10757] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:16.641461
2019-07-10 06:16:16,641 [salt.state       :1813][INFO    ][10757] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:16:16,643 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10757] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:16:17,949 [salt.state       :300 ][INFO    ][10757] {'pid': 10768, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:16:17,950 [salt.state       :1951][INFO    ][10757] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:17.950580 duration_in_ms=1309.118
2019-07-10 06:16:17,953 [salt.state       :1780][INFO    ][10757] Running state [maas_machines_storage_cmp002_lvm] at time 06:16:17.953878
2019-07-10 06:16:17,954 [salt.state       :1813][INFO    ][10757] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-07-10 06:16:19,270 [salt.loaded.ext.module.maasng:610 ][INFO    ][10757] xqw7wm
2019-07-10 06:16:19,271 [salt.loaded.ext.module.maasng:626 ][INFO    ][10757] sda
2019-07-10 06:16:20,066 [salt.loaded.ext.module.maasng:361 ][INFO    ][10757] xqw7wm
2019-07-10 06:16:20,199 [salt.loaded.ext.module.maasng:367 ][INFO    ][10757] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'xqw7wm', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'size': 2397992648704, u'uuid': u'40d13ddc-f8c9-430a-8b25-c9621ccd0894', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xqw7wm', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'505470a5-85ab-4d58-9259-b7dbeda2fa19', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/partition/3', u'type': u'partition', u'id': 3, u'device_id': 3}]}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/8/', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'uuid': u'60380be8-5b5c-4ed3-ae7a-9afc093cef2d', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'xqw7wm', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'bfc3cc31-e3e2-4bc0-848f-bdbef4539836', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 8, u'serial': None, u'partitions': []}]
2019-07-10 06:16:20,200 [salt.loaded.ext.module.maasng:632 ][INFO    ][10757] vgroot
2019-07-10 06:16:20,200 [salt.loaded.ext.module.maasng:635 ][INFO    ][10757] lvroot
2019-07-10 06:16:20,201 [salt.loaded.ext.module.maasng:639 ][INFO    ][10757] 107374182400
2019-07-10 06:16:20,859 [salt.loaded.ext.module.maasng:645 ][INFO    ][10757] {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'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 26}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [], u'system_id': u'xqw7wm', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/interfaces/4/'}, u'fqdn': u'cmp002.maas', 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'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'xqw7wm', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/', u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'd5b038cc-d8e7-4999-8538-5001f5974e2d', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xqw7wm', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'c5f17d4c-8b20-4ac0-8f69-863b36d750a3', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 6, u'size': 2397992648704}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/xqw7wm/', u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'xqw7wm', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'uuid': None, u'id': 3, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'xqw7wm', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/', u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'd5b038cc-d8e7-4999-8538-5001f5974e2d', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xqw7wm', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'c5f17d4c-8b20-4ac0-8f69-863b36d750a3', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 6, u'size': 2397992648704}]}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'uuid': u'cdf60799-5b5c-445d-b74d-353b36e1c654', u'id': 11, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'xqw7wm', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'f6ae58d0-1134-4eb8-8fd8-506bc4635c22', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/11/', u'used_size': 107374182400, u'model': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'xqw7wm', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'xqw7wm', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/', u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'd5b038cc-d8e7-4999-8538-5001f5974e2d', u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xqw7wm', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'c5f17d4c-8b20-4ac0-8f69-863b36d750a3', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 6, u'size': 2397992648704}]}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 11, u'uuid': u'cdf60799-5b5c-445d-b74d-353b36e1c654', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'xqw7wm', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'f6ae58d0-1134-4eb8-8fd8-506bc4635c22', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/blockdevices/11/', u'used_size': 107374182400, u'model': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'min_hwe_kernel': u'hwe-16.04', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'b4we86', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 26}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [], u'system_id': u'xqw7wm', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/interfaces/4/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 15, u'discovered': None, u'system_id': u'xqw7wm', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/interfaces/15/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 28}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 16, u'discovered': None, u'system_id': u'xqw7wm', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/interfaces/16/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 29}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 17, u'discovered': None, u'system_id': u'xqw7wm', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xqw7wm/interfaces/17/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-07-10 06:16:20,861 [salt.state       :300 ][INFO    ][10757] {'new': {'storage_layout': 'lvm'}}
2019-07-10 06:16:20,862 [salt.state       :1951][INFO    ][10757] Completed state [maas_machines_storage_cmp002_lvm] at time 06:16:20.862182 duration_in_ms=2908.302
2019-07-10 06:16:20,862 [salt.state       :1780][INFO    ][10757] Running state [maas_machines_storage_cmp001_lvm] at time 06:16:20.862826
2019-07-10 06:16:20,863 [salt.state       :1813][INFO    ][10757] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-07-10 06:16:21,981 [salt.loaded.ext.module.maasng:610 ][INFO    ][10757] hgsk4w
2019-07-10 06:16:21,982 [salt.loaded.ext.module.maasng:626 ][INFO    ][10757] sda
2019-07-10 06:16:22,406 [salt.loaded.ext.module.maasng:361 ][INFO    ][10757] hgsk4w
2019-07-10 06:16:22,522 [salt.loaded.ext.module.maasng:367 ][INFO    ][10757] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hgsk4w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'e226973a-7a99-4c1e-a234-9824aeac9785', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hgsk4w', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'465ab6bc-7120-4a2b-bdb1-1e600e1fd337', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/partition/1'}]}, {u'size': 2397988454400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/6/', u'type': u'virtual', u'tags': [], u'uuid': u'1c72a62e-47e8-4b49-9804-9401d00a0772', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'hgsk4w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'a9e73f41-4966-4494-9341-6945833c5064', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 6, u'partitions': []}]
2019-07-10 06:16:22,523 [salt.loaded.ext.module.maasng:632 ][INFO    ][10757] vgroot
2019-07-10 06:16:22,523 [salt.loaded.ext.module.maasng:635 ][INFO    ][10757] lvroot
2019-07-10 06:16:22,523 [salt.loaded.ext.module.maasng:639 ][INFO    ][10757] 107374182400
2019-07-10 06:16:23,159 [salt.loaded.ext.module.maasng:645 ][INFO    ][10757] {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'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hgsk4w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'7b3f428b-4de4-4f0c-b7c5-2ef845b2dd52', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hgsk4w', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'd8ee6352-df37-4a09-9e37-77ab0a65ffce', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/partition/7'}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/hgsk4w/', u'disable_ipv4': False, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'owner_data': {}, u'system_id': u'hgsk4w', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'36669f9c-5ee6-4777-9589-63c8b904a400', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/12/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'hgsk4w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'76d58876-3718-458b-80e8-628d4ae3517a', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hgsk4w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'7b3f428b-4de4-4f0c-b7c5-2ef845b2dd52', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hgsk4w', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'd8ee6352-df37-4a09-9e37-77ab0a65ffce', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/partition/7'}]}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'36669f9c-5ee6-4777-9589-63c8b904a400', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'hgsk4w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'76d58876-3718-458b-80e8-628d4ae3517a', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hgsk4w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'7b3f428b-4de4-4f0c-b7c5-2ef845b2dd52', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hgsk4w', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'd8ee6352-df37-4a09-9e37-77ab0a65ffce', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/blockdevices/1/partition/7'}]}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'hgsk4w', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 16, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'hgsk4w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/interfaces/5/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 16, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'b4we86', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'hgsk4w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 9, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'hgsk4w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 10, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'hgsk4w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'hgsk4w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/hgsk4w/interfaces/11/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-07-10 06:16:23,161 [salt.state       :300 ][INFO    ][10757] {'new': {'storage_layout': 'lvm'}}
2019-07-10 06:16:23,162 [salt.state       :1951][INFO    ][10757] Completed state [maas_machines_storage_cmp001_lvm] at time 06:16:23.161923 duration_in_ms=2299.097
2019-07-10 06:16:23,165 [salt.minion      :1711][INFO    ][10757] Returning information for job: 20190710061615699037
2019-07-10 06:16:23,597 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061623586436
2019-07-10 06:16:23,613 [salt.minion      :1432][INFO    ][10826] Starting a new job with PID 10826
2019-07-10 06:16:24,274 [salt.state       :915 ][INFO    ][10826] Loading fresh modules for state activity
2019-07-10 06:16:24,321 [salt.fileclient  :1219][INFO    ][10826] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-07-10 06:16:24,355 [salt.state       :1780][INFO    ][10826] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:24.355526
2019-07-10 06:16:24,355 [salt.state       :1813][INFO    ][10826] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:16:24,357 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10826] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:16:25,889 [salt.state       :300 ][INFO    ][10826] {'pid': 10833, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:16:25,889 [salt.state       :1951][INFO    ][10826] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:25.889839 duration_in_ms=1534.312
2019-07-10 06:16:25,891 [salt.state       :1780][INFO    ][10826] Running state [maas.deploy_machines] at time 06:16:25.891699
2019-07-10 06:16:25,892 [salt.state       :1813][INFO    ][10826] Executing state module.run for [maas.deploy_machines]
2019-07-10 06:16:25,893 [salt.utils.decorators:613 ][WARNING ][10826] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:16:26,299 [salt.loaded.ext.module.maas:684 ][INFO    ][10826] deploymachines hwe_kernel=hwe-16.04 system_id=xqw7wm distro_series=xenial
2019-07-10 06:16:28,718 [salt.loaded.ext.module.maas:684 ][INFO    ][10826] deploymachines hwe_kernel=hwe-16.04 system_id=hgsk4w distro_series=xenial
2019-07-10 06:16:31,184 [salt.loaded.ext.module.maas:684 ][INFO    ][10826] deploymachines hwe_kernel=hwe-16.04 system_id=8kegfc distro_series=xenial
2019-07-10 06:16:33,896 [salt.loaded.ext.module.maas:684 ][INFO    ][10826] deploymachines hwe_kernel=hwe-16.04 system_id=4xf8ye distro_series=xenial
2019-07-10 06:16:36,621 [salt.loaded.ext.module.maas:684 ][INFO    ][10826] deploymachines hwe_kernel=hwe-16.04 system_id=x63xp8 distro_series=xenial
2019-07-10 06:16:38,653 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061638641904
2019-07-10 06:16:38,672 [salt.minion      :1432][INFO    ][11102] Starting a new job with PID 11102
2019-07-10 06:16:38,695 [salt.minion      :1711][INFO    ][11102] Returning information for job: 20190710061638641904
2019-07-10 06:16:38,868 [salt.state       :300 ][INFO    ][10826] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-07-10 06:16:38,869 [salt.state       :1951][INFO    ][10826] Completed state [maas.deploy_machines] at time 06:16:38.869080 duration_in_ms=12977.38
2019-07-10 06:16:38,872 [salt.minion      :1711][INFO    ][10826] Returning information for job: 20190710061623586436
2019-07-10 06:16:39,502 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command state.apply with jid 20190710061639488856
2019-07-10 06:16:39,524 [salt.minion      :1432][INFO    ][11117] Starting a new job with PID 11117
2019-07-10 06:16:43,238 [salt.state       :915 ][INFO    ][11117] Loading fresh modules for state activity
2019-07-10 06:16:43,290 [salt.fileclient  :1219][INFO    ][11117] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-07-10 06:16:43,335 [salt.state       :1780][INFO    ][11117] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:43.335261
2019-07-10 06:16:43,335 [salt.state       :1813][INFO    ][11117] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-10 06:16:43,337 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11117] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-10 06:16:44,789 [salt.state       :300 ][INFO    ][11117] {'pid': 11139, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-10 06:16:44,790 [salt.state       :1951][INFO    ][11117] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:16:44.789910 duration_in_ms=1454.648
2019-07-10 06:16:44,793 [salt.state       :1780][INFO    ][11117] Running state [maas.wait_for_machine_status] at time 06:16:44.793072
2019-07-10 06:16:44,793 [salt.state       :1813][INFO    ][11117] Executing state module.run for [maas.wait_for_machine_status]
2019-07-10 06:16:44,794 [salt.utils.decorators:613 ][WARNING ][11117] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-10 06:16:47,812 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.99156189s left)
2019-07-10 06:16:54,521 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061654508860
2019-07-10 06:16:54,544 [salt.minion      :1432][INFO    ][11151] Starting a new job with PID 11151
2019-07-10 06:16:54,568 [salt.minion      :1711][INFO    ][11151] Returning information for job: 20190710061654508860
2019-07-10 06:17:20,786 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.01810598s left)
2019-07-10 06:17:24,572 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061724560663
2019-07-10 06:17:24,595 [salt.minion      :1432][INFO    ][11209] Starting a new job with PID 11209
2019-07-10 06:17:24,618 [salt.minion      :1711][INFO    ][11209] Returning information for job: 20190710061724560663
2019-07-10 06:17:53,832 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.97182703s left)
2019-07-10 06:17:54,661 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061754648600
2019-07-10 06:17:54,683 [salt.minion      :1432][INFO    ][11229] Starting a new job with PID 11229
2019-07-10 06:17:54,707 [salt.minion      :1711][INFO    ][11229] Returning information for job: 20190710061754648600
2019-07-10 06:18:24,706 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061824697882
2019-07-10 06:18:24,723 [salt.minion      :1432][INFO    ][11422] Starting a new job with PID 11422
2019-07-10 06:18:24,745 [salt.minion      :1711][INFO    ][11422] Returning information for job: 20190710061824697882
2019-07-10 06:18:27,077 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.72706389s left)
2019-07-10 06:18:54,752 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061854737078
2019-07-10 06:18:54,774 [salt.minion      :1432][INFO    ][11579] Starting a new job with PID 11579
2019-07-10 06:18:54,799 [salt.minion      :1711][INFO    ][11579] Returning information for job: 20190710061854737078
2019-07-10 06:19:00,378 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.42570996s left)
2019-07-10 06:19:24,805 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061924791849
2019-07-10 06:19:24,828 [salt.minion      :1432][INFO    ][12306] Starting a new job with PID 12306
2019-07-10 06:19:24,852 [salt.minion      :1711][INFO    ][12306] Returning information for job: 20190710061924791849
2019-07-10 06:19:33,770 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.03387499s left)
2019-07-10 06:19:54,861 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710061954848371
2019-07-10 06:19:54,883 [salt.minion      :1432][INFO    ][12329] Starting a new job with PID 12329
2019-07-10 06:19:54,906 [salt.minion      :1711][INFO    ][12329] Returning information for job: 20190710061954848371
2019-07-10 06:20:07,375 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.42907906s left)
2019-07-10 06:20:24,920 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062024907730
2019-07-10 06:20:24,943 [salt.minion      :1432][INFO    ][12442] Starting a new job with PID 12442
2019-07-10 06:20:24,967 [salt.minion      :1711][INFO    ][12442] Returning information for job: 20190710062024907730
2019-07-10 06:20:40,370 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.434026s left)
2019-07-10 06:20:54,987 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062054974929
2019-07-10 06:20:55,010 [salt.minion      :1432][INFO    ][12468] Starting a new job with PID 12468
2019-07-10 06:20:55,030 [salt.minion      :1711][INFO    ][12468] Returning information for job: 20190710062054974929
2019-07-10 06:21:13,332 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.47221494s left)
2019-07-10 06:21:25,050 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062125038241
2019-07-10 06:21:25,073 [salt.minion      :1432][INFO    ][13085] Starting a new job with PID 13085
2019-07-10 06:21:25,097 [salt.minion      :1711][INFO    ][13085] Returning information for job: 20190710062125038241
2019-07-10 06:21:46,477 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1948.32643199s left)
2019-07-10 06:21:55,116 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062155104404
2019-07-10 06:21:55,138 [salt.minion      :1432][INFO    ][13112] Starting a new job with PID 13112
2019-07-10 06:21:55,159 [salt.minion      :1711][INFO    ][13112] Returning information for job: 20190710062155104404
2019-07-10 06:22:19,471 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1915.33290601s left)
2019-07-10 06:22:25,189 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062225176410
2019-07-10 06:22:25,212 [salt.minion      :1432][INFO    ][13467] Starting a new job with PID 13467
2019-07-10 06:22:25,235 [salt.minion      :1711][INFO    ][13467] Returning information for job: 20190710062225176410
2019-07-10 06:22:52,557 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1882.246912s left)
2019-07-10 06:22:55,272 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062255259652
2019-07-10 06:22:55,295 [salt.minion      :1432][INFO    ][13486] Starting a new job with PID 13486
2019-07-10 06:22:55,321 [salt.minion      :1711][INFO    ][13486] Returning information for job: 20190710062255259652
2019-07-10 06:23:25,365 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062325352025
2019-07-10 06:23:25,386 [salt.minion      :1432][INFO    ][13543] Starting a new job with PID 13543
2019-07-10 06:23:25,409 [salt.minion      :1711][INFO    ][13543] Returning information for job: 20190710062325352025
2019-07-10 06:23:26,053 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1848.75076604s left)
2019-07-10 06:23:55,465 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062355452702
2019-07-10 06:23:55,485 [salt.minion      :1432][INFO    ][13685] Starting a new job with PID 13685
2019-07-10 06:23:55,504 [salt.minion      :1711][INFO    ][13685] Returning information for job: 20190710062355452702
2019-07-10 06:23:59,197 [salt.loaded.ext.module.maas:1023][INFO    ][11117] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1815.60644007s left)
2019-07-10 06:24:25,609 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command saltutil.find_job with jid 20190710062425596264
2019-07-10 06:24:25,632 [salt.minion      :1432][INFO    ][14242] Starting a new job with PID 14242
2019-07-10 06:24:25,655 [salt.minion      :1711][INFO    ][14242] Returning information for job: 20190710062425596264
2019-07-10 06:24:32,840 [salt.state       :300 ][INFO    ][11117] {'ret': True}
2019-07-10 06:24:32,841 [salt.state       :1951][INFO    ][11117] Completed state [maas.wait_for_machine_status] at time 06:24:32.841212 duration_in_ms=468048.138
2019-07-10 06:24:32,845 [salt.minion      :1711][INFO    ][11117] Returning information for job: 20190710061639488856
2019-07-10 07:04:26,654 [salt.utils.schedule:1377][INFO    ][7359] Running scheduled job: __mine_interval
2019-07-10 07:53:30,023 [salt.minion      :1308][INFO    ][7359] User sudo_ubuntu Executing command cp.push_dir with jid 20190710075330010676
2019-07-10 07:53:30,044 [salt.minion      :1432][INFO    ][20531] Starting a new job with PID 20531
