2019-06-26 02:04:11,593 [salt.utils.decorators:613 ][WARNING ][2079] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:04:12,550 [salt.utils.decorators:613 ][WARNING ][2079] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:04:15,510 [salt.loaded.int.states.file:2298][WARNING ][2554] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-26 02:04:35,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3058] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-26 02:04:35,646 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3058] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-26 02:04:35,684 [salt.utils.parsers:1051][WARNING ][379] Minion received a SIGTERM. Exiting.
2019-06-26 02:04:36,687 [salt.cli.daemons :293 ][INFO    ][3172] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-06-26 02:04:36,809 [salt.cli.daemons :82  ][INFO    ][3172] Starting up the Salt Minion
2019-06-26 02:04:36,810 [salt.utils.event :1017][INFO    ][3172] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-06-26 02:04:37,866 [salt.minion      :976 ][INFO    ][3172] Creating minion process manager
2019-06-26 02:04:39,779 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3172] Executing command ['date', '+%z'] in directory '/root'
2019-06-26 02:04:39,797 [salt.utils.schedule:568 ][INFO    ][3172] Updating job settings for scheduled job: __mine_interval
2019-06-26 02:04:39,799 [salt.minion      :1108][INFO    ][3172] Added mine.update to scheduler
2019-06-26 02:04:39,804 [salt.minion      :1975][INFO    ][3172] Minion is starting as user 'root'
2019-06-26 02:04:39,820 [salt.minion      :2336][INFO    ][3172] Minion is ready to receive requests!
2019-06-26 02:04:44,604 [salt.state       :2022][WARNING ][3061] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-26 02:04:47,743 [salt.utils.decorators:613 ][WARNING ][3061] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:04:48,392 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020448372105
2019-06-26 02:04:48,416 [salt.minion      :1432][INFO    ][3710] Starting a new job with PID 3710
2019-06-26 02:04:48,443 [salt.minion      :1711][INFO    ][3710] Returning information for job: 20190626020448372105
2019-06-26 02:05:01,295 [salt.utils.decorators:613 ][WARNING ][3061] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:05:18,514 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020518502355
2019-06-26 02:05:18,537 [salt.minion      :1432][INFO    ][4023] Starting a new job with PID 4023
2019-06-26 02:05:18,559 [salt.minion      :1711][INFO    ][4023] Returning information for job: 20190626020518502355
2019-06-26 02:05:28,340 [salt.utils.decorators:613 ][WARNING ][3061] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:05:29,199 [salt.utils.decorators:613 ][WARNING ][3061] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:05:31,350 [salt.loaded.ext.module.maasng:1008][WARNING ][3061] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-06-26 02:05:31,351 [salt.loaded.ext.module.maasng:1011][WARNING ][3061] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-06-26 02:05:32,056 [salt.loaded.ext.module.maasng:1235][WARNING ][3061] Ignoring parameter vlan:0
2019-06-26 02:05:33,587 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626020533577094
2019-06-26 02:05:33,607 [salt.minion      :1432][INFO    ][4556] Starting a new job with PID 4556
2019-06-26 02:05:40,101 [salt.state       :915 ][INFO    ][4556] Loading fresh modules for state activity
2019-06-26 02:05:40,174 [salt.fileclient  :1219][INFO    ][4556] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-06-26 02:05:40,222 [salt.state       :1780][INFO    ][4556] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:05:40.222573
2019-06-26 02:05:40,222 [salt.state       :1813][INFO    ][4556] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:05:40,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4556] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:05:42,044 [salt.state       :300 ][INFO    ][4556] {'pid': 4601, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:05:42,046 [salt.state       :1951][INFO    ][4556] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:05:42.045550 duration_in_ms=1822.977
2019-06-26 02:05:42,049 [salt.state       :1780][INFO    ][4556] Running state [maas.process_machines] at time 02:05:42.048979
2019-06-26 02:05:42,049 [salt.state       :1813][INFO    ][4556] Executing state module.run for [maas.process_machines]
2019-06-26 02:05:42,052 [salt.utils.decorators:613 ][WARNING ][4556] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:05:42,126 [salt.loaded.ext.module.maas:412 ][WARNING ][4556] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:05:42,127 [salt.loaded.ext.module.maas:92  ][INFO    ][4556] machine hostname=cmp002 power_type=ipmi mac_addresses=9c:b6:54:8a:10:18 power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:05:43,584 [salt.loaded.ext.module.maas:412 ][WARNING ][4556] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:05:43,584 [salt.loaded.ext.module.maas:92  ][INFO    ][4556] machine hostname=cmp001 power_type=ipmi mac_addresses=9c:b6:54:8a:95:a0 power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:05:44,900 [salt.loaded.ext.module.maas:412 ][WARNING ][4556] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:05:44,901 [salt.loaded.ext.module.maas:92  ][INFO    ][4556] machine hostname=kvm01 power_type=ipmi mac_addresses=14:58:d0:54:e7:88 power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:05:46,151 [salt.loaded.ext.module.maas:412 ][WARNING ][4556] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:05:46,152 [salt.loaded.ext.module.maas:92  ][INFO    ][4556] machine hostname=kvm03 power_type=ipmi mac_addresses=14:58:d0:54:7a:28 power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:05:47,326 [salt.loaded.ext.module.maas:412 ][WARNING ][4556] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:05:47,327 [salt.loaded.ext.module.maas:92  ][INFO    ][4556] machine hostname=kvm02 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:05:48,613 [salt.state       :300 ][INFO    ][4556] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-26 02:05:48,618 [salt.state       :1951][INFO    ][4556] Completed state [maas.process_machines] at time 02:05:48.618097 duration_in_ms=6569.117
2019-06-26 02:05:48,620 [salt.minion      :1711][INFO    ][4556] Returning information for job: 20190626020533577094
2019-06-26 02:06:19,649 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626020619632678
2019-06-26 02:06:19,668 [salt.minion      :1432][INFO    ][4936] Starting a new job with PID 4936
2019-06-26 02:06:25,548 [salt.state       :915 ][INFO    ][4936] Loading fresh modules for state activity
2019-06-26 02:06:25,612 [salt.fileclient  :1219][INFO    ][4936] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-26 02:06:25,656 [salt.state       :1780][INFO    ][4936] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:06:25.656606
2019-06-26 02:06:25,656 [salt.state       :1813][INFO    ][4936] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:06:25,659 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4936] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:06:27,363 [salt.state       :300 ][INFO    ][4936] {'pid': 4944, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:06:27,364 [salt.state       :1951][INFO    ][4936] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:06:27.363860 duration_in_ms=1707.254
2019-06-26 02:06:27,367 [salt.state       :1780][INFO    ][4936] Running state [maas.wait_for_machine_status] at time 02:06:27.367439
2019-06-26 02:06:27,368 [salt.state       :1813][INFO    ][4936] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 02:06:27,368 [salt.utils.decorators:613 ][WARNING ][4936] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:06:28,591 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.78798509s left)
2019-06-26 02:06:34,728 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020634719332
2019-06-26 02:06:34,744 [salt.minion      :1432][INFO    ][4979] Starting a new job with PID 4979
2019-06-26 02:06:34,762 [salt.minion      :1711][INFO    ][4979] Returning information for job: 20190626020634719332
2019-06-26 02:06:59,411 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1467.96793699s left)
2019-06-26 02:07:04,782 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020704767616
2019-06-26 02:07:04,805 [salt.minion      :1432][INFO    ][5040] Starting a new job with PID 5040
2019-06-26 02:07:04,827 [salt.minion      :1711][INFO    ][5040] Returning information for job: 20190626020704767616
2019-06-26 02:07:30,216 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.16261005s left)
2019-06-26 02:07:34,860 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020734848665
2019-06-26 02:07:34,880 [salt.minion      :1432][INFO    ][5070] Starting a new job with PID 5070
2019-06-26 02:07:34,901 [salt.minion      :1711][INFO    ][5070] Returning information for job: 20190626020734848665
2019-06-26 02:08:00,946 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.43323302s left)
2019-06-26 02:08:04,926 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020804917669
2019-06-26 02:08:04,951 [salt.minion      :1432][INFO    ][5116] Starting a new job with PID 5116
2019-06-26 02:08:04,972 [salt.minion      :1711][INFO    ][5116] Returning information for job: 20190626020804917669
2019-06-26 02:08:32,025 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.35395312s left)
2019-06-26 02:08:35,010 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020834998948
2019-06-26 02:08:35,033 [salt.minion      :1432][INFO    ][5183] Starting a new job with PID 5183
2019-06-26 02:08:35,052 [salt.minion      :1711][INFO    ][5183] Returning information for job: 20190626020834998948
2019-06-26 02:09:02,973 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.40607309s left)
2019-06-26 02:09:05,104 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020905092574
2019-06-26 02:09:05,118 [salt.minion      :1432][INFO    ][5361] Starting a new job with PID 5361
2019-06-26 02:09:05,139 [salt.minion      :1711][INFO    ][5361] Returning information for job: 20190626020905092574
2019-06-26 02:09:34,733 [salt.loaded.ext.module.maas:981 ][INFO    ][4936] Machine faswx8 deleted
2019-06-26 02:09:35,220 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626020935196917
2019-06-26 02:09:35,232 [salt.loaded.ext.module.maas:412 ][WARNING ][4936] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:09:35,232 [salt.loaded.ext.module.maas:92  ][INFO    ][4936] machine hostname=cmp002 power_type=ipmi mac_addresses=[u'9c:b6:54:8a:10:18'] power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 system_id=cm63ft architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:09:35,266 [salt.minion      :1432][INFO    ][5489] Starting a new job with PID 5489
2019-06-26 02:09:35,293 [salt.minion      :1711][INFO    ][5489] Returning information for job: 20190626020935196917
2019-06-26 02:09:36,306 [salt.loaded.ext.module.maas:412 ][WARNING ][4936] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:09:36,307 [salt.loaded.ext.module.maas:92  ][INFO    ][4936] machine hostname=cmp001 power_type=ipmi mac_addresses=[u'9c:b6:54:8a:95:a0'] power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 system_id=kmkt4b architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:09:37,319 [salt.loaded.ext.module.maas:412 ][WARNING ][4936] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:09:37,320 [salt.loaded.ext.module.maas:92  ][INFO    ][4936] machine hostname=kvm01 power_type=ipmi mac_addresses=[u'14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=6c78ng architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:09:38,320 [salt.loaded.ext.module.maas:412 ][WARNING ][4936] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:09:38,321 [salt.loaded.ext.module.maas:92  ][INFO    ][4936] machine hostname=kvm03 power_type=ipmi mac_addresses=[u'14:58:d0:54:7a:28'] power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 system_id=tksabk architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:09:39,232 [salt.loaded.ext.module.maas:412 ][WARNING ][4936] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:09:39,232 [salt.loaded.ext.module.maas:92  ][INFO    ][4936] machine hostname=kvm02 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:09:56,449 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1290.92975712s left)
2019-06-26 02:10:05,244 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021005231621
2019-06-26 02:10:05,260 [salt.minion      :1432][INFO    ][5945] Starting a new job with PID 5945
2019-06-26 02:10:05,280 [salt.minion      :1711][INFO    ][5945] Returning information for job: 20190626021005231621
2019-06-26 02:10:28,162 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1259.21755505s left)
2019-06-26 02:10:35,337 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021035326508
2019-06-26 02:10:35,362 [salt.minion      :1432][INFO    ][6063] Starting a new job with PID 6063
2019-06-26 02:10:35,383 [salt.minion      :1711][INFO    ][6063] Returning information for job: 20190626021035326508
2019-06-26 02:11:00,507 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1226.87208509s left)
2019-06-26 02:11:05,479 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021105463004
2019-06-26 02:11:05,506 [salt.minion      :1432][INFO    ][6358] Starting a new job with PID 6358
2019-06-26 02:11:05,527 [salt.minion      :1711][INFO    ][6358] Returning information for job: 20190626021105463004
2019-06-26 02:11:32,705 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1194.67356205s left)
2019-06-26 02:11:35,595 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021135581477
2019-06-26 02:11:35,621 [salt.minion      :1432][INFO    ][6465] Starting a new job with PID 6465
2019-06-26 02:11:35,644 [salt.minion      :1711][INFO    ][6465] Returning information for job: 20190626021135581477
2019-06-26 02:12:05,441 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1161.93760514s left)
2019-06-26 02:12:05,724 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021205716535
2019-06-26 02:12:05,743 [salt.minion      :1432][INFO    ][6602] Starting a new job with PID 6602
2019-06-26 02:12:05,763 [salt.minion      :1711][INFO    ][6602] Returning information for job: 20190626021205716535
2019-06-26 02:12:35,823 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021235813775
2019-06-26 02:12:35,848 [salt.minion      :1432][INFO    ][6672] Starting a new job with PID 6672
2019-06-26 02:12:35,871 [salt.minion      :1711][INFO    ][6672] Returning information for job: 20190626021235813775
2019-06-26 02:12:38,015 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1129.36354208s left)
2019-06-26 02:13:05,948 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021305936320
2019-06-26 02:13:05,975 [salt.minion      :1432][INFO    ][6716] Starting a new job with PID 6716
2019-06-26 02:13:05,993 [salt.minion      :1711][INFO    ][6716] Returning information for job: 20190626021305936320
2019-06-26 02:13:10,700 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1096.67899799s left)
2019-06-26 02:13:36,067 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021336054540
2019-06-26 02:13:36,095 [salt.minion      :1432][INFO    ][6749] Starting a new job with PID 6749
2019-06-26 02:13:36,114 [salt.minion      :1711][INFO    ][6749] Returning information for job: 20190626021336054540
2019-06-26 02:13:43,295 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1064.08399296s left)
2019-06-26 02:14:06,211 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021406202652
2019-06-26 02:14:06,233 [salt.minion      :1432][INFO    ][6821] Starting a new job with PID 6821
2019-06-26 02:14:06,252 [salt.minion      :1711][INFO    ][6821] Returning information for job: 20190626021406202652
2019-06-26 02:14:15,810 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1031.56867909s left)
2019-06-26 02:14:36,347 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021436330675
2019-06-26 02:14:36,375 [salt.minion      :1432][INFO    ][6877] Starting a new job with PID 6877
2019-06-26 02:14:36,396 [salt.minion      :1711][INFO    ][6877] Returning information for job: 20190626021436330675
2019-06-26 02:14:48,792 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (998.587183952s left)
2019-06-26 02:15:06,535 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021506522145
2019-06-26 02:15:06,563 [salt.minion      :1432][INFO    ][7030] Starting a new job with PID 7030
2019-06-26 02:15:06,586 [salt.minion      :1711][INFO    ][7030] Returning information for job: 20190626021506522145
2019-06-26 02:15:21,611 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (965.767692089s left)
2019-06-26 02:15:36,691 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021536681243
2019-06-26 02:15:36,714 [salt.minion      :1432][INFO    ][7099] Starting a new job with PID 7099
2019-06-26 02:15:36,737 [salt.minion      :1711][INFO    ][7099] Returning information for job: 20190626021536681243
2019-06-26 02:15:54,403 [salt.loaded.ext.module.maas:1023][INFO    ][4936] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (932.976021051s left)
2019-06-26 02:16:06,848 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021606835058
2019-06-26 02:16:06,875 [salt.minion      :1432][INFO    ][7205] Starting a new job with PID 7205
2019-06-26 02:16:06,894 [salt.minion      :1711][INFO    ][7205] Returning information for job: 20190626021606835058
2019-06-26 02:16:27,250 [salt.state       :300 ][INFO    ][4936] {'ret': True}
2019-06-26 02:16:27,250 [salt.state       :1951][INFO    ][4936] Completed state [maas.wait_for_machine_status] at time 02:16:27.250704 duration_in_ms=599883.264
2019-06-26 02:16:27,256 [salt.minion      :1711][INFO    ][4936] Returning information for job: 20190626020619632678
2019-06-26 02:16:27,928 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626021627912630
2019-06-26 02:16:27,955 [salt.minion      :1432][INFO    ][7233] Starting a new job with PID 7233
2019-06-26 02:16:34,354 [salt.state       :915 ][INFO    ][7233] Loading fresh modules for state activity
2019-06-26 02:16:34,417 [salt.fileclient  :1219][INFO    ][7233] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-26 02:16:34,516 [salt.state       :1780][INFO    ][7233] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:34.516666
2019-06-26 02:16:34,516 [salt.state       :1813][INFO    ][7233] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:16:34,519 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7233] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:16:36,540 [salt.state       :300 ][INFO    ][7233] {'pid': 7260, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:16:36,542 [salt.state       :1951][INFO    ][7233] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:36.542120 duration_in_ms=2025.453
2019-06-26 02:16:36,546 [salt.state       :1780][INFO    ][7233] Running state [maas_machines_storage_cmp002_lvm] at time 02:16:36.546081
2019-06-26 02:16:36,546 [salt.state       :1813][INFO    ][7233] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-26 02:16:37,714 [salt.loaded.ext.module.maasng:610 ][INFO    ][7233] cm63ft
2019-06-26 02:16:37,715 [salt.loaded.ext.module.maasng:626 ][INFO    ][7233] sda
2019-06-26 02:16:38,291 [salt.loaded.ext.module.maasng:361 ][INFO    ][7233] cm63ft
2019-06-26 02:16:38,385 [salt.loaded.ext.module.maasng:367 ][INFO    ][7233] [{u'size': 800109715456, u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'cm63ft', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'partitions': [{u'uuid': u'2980b009-3819-4774-a998-242d66b5183e', u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/partition/1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm63ft', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'302a964d-0450-46e7-b0da-3a88bcc09751', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 1, u'type': u'partition', u'id': 1, u'size': 800101236736}], u'used_size': 800106479616, u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/'}, {u'size': 800097042432, u'block_size': 4096, u'available_size': 0, u'uuid': u'd85a76af-fef4-4b3f-add0-da560409bd18', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'cm63ft', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'23683ea8-35fc-4040-91c5-6e36b24c006e', u'fstype': u'ext4'}, u'id': 3, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'used_size': 800097042432, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/3/'}]
2019-06-26 02:16:38,386 [salt.loaded.ext.module.maasng:632 ][INFO    ][7233] vgroot
2019-06-26 02:16:38,386 [salt.loaded.ext.module.maasng:635 ][INFO    ][7233] lvroot
2019-06-26 02:16:38,386 [salt.loaded.ext.module.maasng:639 ][INFO    ][7233] 107374182400
2019-06-26 02:16:38,982 [salt.loaded.ext.module.maasng:645 ][INFO    ][7233] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 40, 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'children': [], u'name': u'eno1', 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'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/4/'}, u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'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/cm63ft/', u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'cm63ft', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'model': None, u'uuid': u'c604e3e0-180c-48b9-a1c6-ad3062c7b383', u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/11/', u'used_size': 107374182400, u'id': 11, u'tags': [], u'partitions': [], u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'cm63ft', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'79ae8266-508f-4be4-9856-734ca540b5fb', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'size': 107374182400}], u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/', u'used_size': 800106479616, u'partitions': [{u'uuid': u'ff245f7f-fec1-45a3-bd7e-bc32286a8b15', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm63ft', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'8eac0b74-2c17-4270-bd06-e2f2189553d6', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/partition/6'}], u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cm63ft', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'id': 1, u'size': 800109715456}, {u'model': None, u'uuid': u'c604e3e0-180c-48b9-a1c6-ad3062c7b383', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/11/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'cm63ft', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'79ae8266-508f-4be4-9856-734ca540b5fb', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/', u'used_size': 800106479616, u'id': 1, u'tags': [u'ssd'], u'partitions': [{u'uuid': u'ff245f7f-fec1-45a3-bd7e-bc32286a8b15', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm63ft', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'8eac0b74-2c17-4270-bd06-e2f2189553d6', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/partition/6'}], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cm63ft', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'size': 800109715456}], u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cm63ft', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'model': u'LOGICAL VOLUME', u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/', u'used_size': 800106479616, u'id': 1, u'tags': [u'ssd'], u'partitions': [{u'uuid': u'ff245f7f-fec1-45a3-bd7e-bc32286a8b15', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm63ft', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'8eac0b74-2c17-4270-bd06-e2f2189553d6', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/blockdevices/1/partition/6'}], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cm63ft', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'size': 800109715456}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'min_hwe_kernel': u'ga-16.04', u'interface_set': [{u'children': [], u'name': u'eno1', 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'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/4/'}, {u'children': [], u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:51', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/12/'}, {u'children': [], u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:50', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/16/'}, {u'children': [], u'name': u'ens2f1', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:49', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/13/'}, {u'children': [], u'name': u'ens2f0', u'links': [{u'id': 20, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:48', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/14/'}, {u'children': [], u'name': u'eno2', 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'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'id': 21, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.40'}], u'mac_address': u'9c:b6:54:8a:10:1c', u'system_id': u'cm63ft', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/cm63ft/interfaces/15/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-06-26 02:16:38,984 [salt.state       :300 ][INFO    ][7233] {'new': {'storage_layout': 'lvm'}}
2019-06-26 02:16:38,984 [salt.state       :1951][INFO    ][7233] Completed state [maas_machines_storage_cmp002_lvm] at time 02:16:38.984779 duration_in_ms=2438.698
2019-06-26 02:16:38,985 [salt.state       :1780][INFO    ][7233] Running state [maas_machines_storage_cmp001_lvm] at time 02:16:38.985363
2019-06-26 02:16:38,985 [salt.state       :1813][INFO    ][7233] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-26 02:16:40,121 [salt.loaded.ext.module.maasng:610 ][INFO    ][7233] kmkt4b
2019-06-26 02:16:40,122 [salt.loaded.ext.module.maasng:626 ][INFO    ][7233] sda
2019-06-26 02:16:40,699 [salt.loaded.ext.module.maasng:361 ][INFO    ][7233] kmkt4b
2019-06-26 02:16:40,793 [salt.loaded.ext.module.maasng:367 ][INFO    ][7233] [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/', u'used_size': 800106479616, u'partitions': [{u'uuid': u'5e272220-d617-43bc-991f-7dc631db436b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kmkt4b', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'71beb4d2-2f14-4e2f-8028-a9fca09bd2f9', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/partition/2'}], u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'kmkt4b', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'id': 2, u'size': 800109715456}, {u'model': None, u'uuid': u'f4498a09-8357-4df9-99a3-e2a89b259dd7', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/4/', u'used_size': 800097042432, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'kmkt4b', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'9711f259-563e-4a4c-8e21-b753078802b9', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 4, u'size': 800097042432}]
2019-06-26 02:16:40,793 [salt.loaded.ext.module.maasng:632 ][INFO    ][7233] vgroot
2019-06-26 02:16:40,793 [salt.loaded.ext.module.maasng:635 ][INFO    ][7233] lvroot
2019-06-26 02:16:40,793 [salt.loaded.ext.module.maasng:639 ][INFO    ][7233] 107374182400
2019-06-26 02:16:41,377 [salt.loaded.ext.module.maasng:645 ][INFO    ][7233] {u'hwe_kernel': u'', u'status_action': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.39', u'192.168.11.41'], u'cpu_count': 40, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'd84c0d2a-7a57-463c-8261-b579463ce953', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kmkt4b', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'b9f1ea6c-53c3-44ad-ad57-41aef8c5ebfa', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'kmkt4b', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}, u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'current_commissioning_result_id': 4, u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'kmkt4b', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'physicalblockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'd84c0d2a-7a57-463c-8261-b579463ce953', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kmkt4b', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'b9f1ea6c-53c3-44ad-ad57-41aef8c5ebfa', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'kmkt4b', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}], u'blockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'd84c0d2a-7a57-463c-8261-b579463ce953', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kmkt4b', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'b9f1ea6c-53c3-44ad-ad57-41aef8c5ebfa', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'kmkt4b', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/12/', u'uuid': u'f38f4040-8a89-428d-bad8-5903d53c2f93', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'6c288633-0d4d-404f-a66e-aa4993d39440', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id': 12, u'system_id': u'kmkt4b', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}], 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'kmkt4b', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', 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'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/blockdevices/12/', u'uuid': u'f38f4040-8a89-428d-bad8-5903d53c2f93', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'6c288633-0d4d-404f-a66e-aa4993d39440', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id': 12, u'system_id': u'kmkt4b', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'boot_interface': {u'name': u'eno1', 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': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/5/'}, u'interface_set': [{u'name': u'eno1', 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': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/5/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:1f:d4', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/17/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:1f:d5', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/21/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 25}], u'tags': [u'sriov'], 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:52:cd', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/18/'}, {u'name': u'eno2', 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': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'mode': u'link_up', u'id': 26}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nb4xax', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'9c:b6:54:8a:95:a4', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/19/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [u'sriov'], 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:52:cc', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'kmkt4b', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/kmkt4b/interfaces/20/'}], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/kmkt4b/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-06-26 02:16:41,379 [salt.state       :300 ][INFO    ][7233] {'new': {'storage_layout': 'lvm'}}
2019-06-26 02:16:41,380 [salt.state       :1951][INFO    ][7233] Completed state [maas_machines_storage_cmp001_lvm] at time 02:16:41.380022 duration_in_ms=2394.659
2019-06-26 02:16:41,382 [salt.minion      :1711][INFO    ][7233] Returning information for job: 20190626021627912630
2019-06-26 02:16:41,932 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626021641920023
2019-06-26 02:16:41,951 [salt.minion      :1432][INFO    ][7278] Starting a new job with PID 7278
2019-06-26 02:16:42,930 [salt.state       :915 ][INFO    ][7278] Loading fresh modules for state activity
2019-06-26 02:16:42,982 [salt.fileclient  :1219][INFO    ][7278] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-26 02:16:43,028 [salt.state       :1780][INFO    ][7278] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:43.028544
2019-06-26 02:16:43,028 [salt.state       :1813][INFO    ][7278] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:16:43,030 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7278] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:16:44,835 [salt.state       :300 ][INFO    ][7278] {'pid': 7285, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:16:44,836 [salt.state       :1951][INFO    ][7278] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:44.836611 duration_in_ms=1808.065
2019-06-26 02:16:44,840 [salt.state       :1780][INFO    ][7278] Running state [maas.deploy_machines] at time 02:16:44.840634
2019-06-26 02:16:44,841 [salt.state       :1813][INFO    ][7278] Executing state module.run for [maas.deploy_machines]
2019-06-26 02:16:44,842 [salt.utils.decorators:613 ][WARNING ][7278] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:16:45,524 [salt.loaded.ext.module.maas:684 ][INFO    ][7278] deploymachines hwe_kernel=ga-16.04 system_id=cm63ft distro_series=xenial
2019-06-26 02:16:48,163 [salt.loaded.ext.module.maas:684 ][INFO    ][7278] deploymachines hwe_kernel=ga-16.04 system_id=kmkt4b distro_series=xenial
2019-06-26 02:16:50,683 [salt.loaded.ext.module.maas:684 ][INFO    ][7278] deploymachines hwe_kernel=ga-16.04 system_id=6c78ng distro_series=xenial
2019-06-26 02:16:53,196 [salt.loaded.ext.module.maas:684 ][INFO    ][7278] deploymachines hwe_kernel=ga-16.04 system_id=tksabk distro_series=xenial
2019-06-26 02:16:55,700 [salt.loaded.ext.module.maas:684 ][INFO    ][7278] deploymachines hwe_kernel=ga-16.04 system_id=w3frpd distro_series=xenial
2019-06-26 02:16:57,006 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021656989681
2019-06-26 02:16:57,034 [salt.minion      :1432][INFO    ][7571] Starting a new job with PID 7571
2019-06-26 02:16:57,057 [salt.minion      :1711][INFO    ][7571] Returning information for job: 20190626021656989681
2019-06-26 02:16:58,204 [salt.state       :300 ][INFO    ][7278] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-26 02:16:58,205 [salt.state       :1951][INFO    ][7278] Completed state [maas.deploy_machines] at time 02:16:58.205341 duration_in_ms=13364.706
2019-06-26 02:16:58,208 [salt.minion      :1711][INFO    ][7278] Returning information for job: 20190626021641920023
2019-06-26 02:16:58,784 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626021658768833
2019-06-26 02:16:58,811 [salt.minion      :1432][INFO    ][7587] Starting a new job with PID 7587
2019-06-26 02:17:04,861 [salt.state       :915 ][INFO    ][7587] Loading fresh modules for state activity
2019-06-26 02:17:04,925 [salt.fileclient  :1219][INFO    ][7587] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-26 02:17:04,972 [salt.state       :1780][INFO    ][7587] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:17:04.971987
2019-06-26 02:17:04,972 [salt.state       :1813][INFO    ][7587] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:17:04,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7587] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:17:06,703 [salt.state       :300 ][INFO    ][7587] {'pid': 7607, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:17:06,705 [salt.state       :1951][INFO    ][7587] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:17:06.704926 duration_in_ms=1732.938
2019-06-26 02:17:06,709 [salt.state       :1780][INFO    ][7587] Running state [maas.wait_for_machine_status] at time 02:17:06.708939
2019-06-26 02:17:06,709 [salt.state       :1813][INFO    ][7587] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 02:17:06,711 [salt.utils.decorators:613 ][WARNING ][7587] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:17:09,701 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.01775622s left)
2019-06-26 02:17:13,829 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021713813375
2019-06-26 02:17:13,859 [salt.minion      :1432][INFO    ][7618] Starting a new job with PID 7618
2019-06-26 02:17:13,882 [salt.minion      :1711][INFO    ][7618] Returning information for job: 20190626021713813375
2019-06-26 02:17:42,552 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.16626906s left)
2019-06-26 02:17:43,915 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021743903081
2019-06-26 02:17:43,942 [salt.minion      :1432][INFO    ][7654] Starting a new job with PID 7654
2019-06-26 02:17:43,960 [salt.minion      :1711][INFO    ][7654] Returning information for job: 20190626021743903081
2019-06-26 02:18:13,984 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021813974100
2019-06-26 02:18:14,008 [salt.minion      :1432][INFO    ][7699] Starting a new job with PID 7699
2019-06-26 02:18:14,031 [salt.minion      :1711][INFO    ][7699] Returning information for job: 20190626021813974100
2019-06-26 02:18:15,675 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2181.04537821s left)
2019-06-26 02:18:44,069 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021844053740
2019-06-26 02:18:44,097 [salt.minion      :1432][INFO    ][7744] Starting a new job with PID 7744
2019-06-26 02:18:44,118 [salt.minion      :1711][INFO    ][7744] Returning information for job: 20190626021844053740
2019-06-26 02:18:48,872 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.84665608s left)
2019-06-26 02:19:14,157 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021914136328
2019-06-26 02:19:14,185 [salt.minion      :1432][INFO    ][7800] Starting a new job with PID 7800
2019-06-26 02:19:14,220 [salt.minion      :1711][INFO    ][7800] Returning information for job: 20190626021914136328
2019-06-26 02:19:21,803 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.91596508s left)
2019-06-26 02:19:44,263 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626021944248132
2019-06-26 02:19:44,287 [salt.minion      :1432][INFO    ][7881] Starting a new job with PID 7881
2019-06-26 02:19:44,308 [salt.minion      :1711][INFO    ][7881] Returning information for job: 20190626021944248132
2019-06-26 02:19:54,681 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2082.03774405s left)
2019-06-26 02:20:14,348 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022014334133
2019-06-26 02:20:14,371 [salt.minion      :1432][INFO    ][8032] Starting a new job with PID 8032
2019-06-26 02:20:14,391 [salt.minion      :1711][INFO    ][8032] Returning information for job: 20190626022014334133
2019-06-26 02:20:27,608 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2049.11108708s left)
2019-06-26 02:20:44,437 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022044426436
2019-06-26 02:20:44,467 [salt.minion      :1432][INFO    ][8135] Starting a new job with PID 8135
2019-06-26 02:20:44,487 [salt.minion      :1711][INFO    ][8135] Returning information for job: 20190626022044426436
2019-06-26 02:21:00,581 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2016.13807607s left)
2019-06-26 02:21:14,548 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022114539109
2019-06-26 02:21:14,567 [salt.minion      :1432][INFO    ][8350] Starting a new job with PID 8350
2019-06-26 02:21:14,595 [salt.minion      :1711][INFO    ][8350] Returning information for job: 20190626022114539109
2019-06-26 02:21:34,455 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1982.26324701s left)
2019-06-26 02:21:44,669 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022144652779
2019-06-26 02:21:44,699 [salt.minion      :1432][INFO    ][8470] Starting a new job with PID 8470
2019-06-26 02:21:44,720 [salt.minion      :1711][INFO    ][8470] Returning information for job: 20190626022144652779
2019-06-26 02:22:07,425 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1949.29363418s left)
2019-06-26 02:22:14,795 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022214780780
2019-06-26 02:22:14,824 [salt.minion      :1432][INFO    ][8646] Starting a new job with PID 8646
2019-06-26 02:22:14,847 [salt.minion      :1711][INFO    ][8646] Returning information for job: 20190626022214780780
2019-06-26 02:22:40,445 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1916.27414107s left)
2019-06-26 02:22:44,933 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022244917247
2019-06-26 02:22:44,961 [salt.minion      :1432][INFO    ][8783] Starting a new job with PID 8783
2019-06-26 02:22:44,984 [salt.minion      :1711][INFO    ][8783] Returning information for job: 20190626022244917247
2019-06-26 02:23:13,444 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1883.27498102s left)
2019-06-26 02:23:15,095 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022315086522
2019-06-26 02:23:15,116 [salt.minion      :1432][INFO    ][9100] Starting a new job with PID 9100
2019-06-26 02:23:15,140 [salt.minion      :1711][INFO    ][9100] Returning information for job: 20190626022315086522
2019-06-26 02:23:45,224 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022345216415
2019-06-26 02:23:45,259 [salt.minion      :1432][INFO    ][9200] Starting a new job with PID 9200
2019-06-26 02:23:45,292 [salt.minion      :1711][INFO    ][9200] Returning information for job: 20190626022345216415
2019-06-26 02:23:46,402 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1850.31670403s left)
2019-06-26 02:24:15,445 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022415430773
2019-06-26 02:24:15,476 [salt.minion      :1432][INFO    ][9572] Starting a new job with PID 9572
2019-06-26 02:24:15,501 [salt.minion      :1711][INFO    ][9572] Returning information for job: 20190626022415430773
2019-06-26 02:24:19,840 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1816.87861609s left)
2019-06-26 02:24:45,573 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022445563394
2019-06-26 02:24:45,603 [salt.minion      :1432][INFO    ][9849] Starting a new job with PID 9849
2019-06-26 02:24:45,627 [salt.minion      :1711][INFO    ][9849] Returning information for job: 20190626022445563394
2019-06-26 02:24:53,033 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1783.68561602s left)
2019-06-26 02:25:15,755 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022515738884
2019-06-26 02:25:15,785 [salt.minion      :1432][INFO    ][10007] Starting a new job with PID 10007
2019-06-26 02:25:15,807 [salt.minion      :1711][INFO    ][10007] Returning information for job: 20190626022515738884
2019-06-26 02:25:25,900 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1750.81817222s left)
2019-06-26 02:25:45,919 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022545903324
2019-06-26 02:25:45,947 [salt.minion      :1432][INFO    ][10093] Starting a new job with PID 10093
2019-06-26 02:25:45,971 [salt.minion      :1711][INFO    ][10093] Returning information for job: 20190626022545903324
2019-06-26 02:25:59,035 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1717.68340111s left)
2019-06-26 02:26:16,103 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022616090460
2019-06-26 02:26:16,128 [salt.minion      :1432][INFO    ][10248] Starting a new job with PID 10248
2019-06-26 02:26:16,151 [salt.minion      :1711][INFO    ][10248] Returning information for job: 20190626022616090460
2019-06-26 02:26:31,957 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1684.76168799s left)
2019-06-26 02:26:46,165 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022646152085
2019-06-26 02:26:46,192 [salt.minion      :1432][INFO    ][10327] Starting a new job with PID 10327
2019-06-26 02:26:46,212 [salt.minion      :1711][INFO    ][10327] Returning information for job: 20190626022646152085
2019-06-26 02:27:05,201 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1651.517349s left)
2019-06-26 02:27:16,244 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022716231765
2019-06-26 02:27:16,274 [salt.minion      :1432][INFO    ][10500] Starting a new job with PID 10500
2019-06-26 02:27:16,296 [salt.minion      :1711][INFO    ][10500] Returning information for job: 20190626022716231765
2019-06-26 02:27:38,048 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1618.67064905s left)
2019-06-26 02:27:46,412 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022746395578
2019-06-26 02:27:46,441 [salt.minion      :1432][INFO    ][10596] Starting a new job with PID 10596
2019-06-26 02:27:46,464 [salt.minion      :1711][INFO    ][10596] Returning information for job: 20190626022746395578
2019-06-26 02:28:10,937 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1585.78214407s left)
2019-06-26 02:28:16,591 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022816578491
2019-06-26 02:28:16,617 [salt.minion      :1432][INFO    ][10703] Starting a new job with PID 10703
2019-06-26 02:28:16,640 [salt.minion      :1711][INFO    ][10703] Returning information for job: 20190626022816578491
2019-06-26 02:28:43,840 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1552.87905812s left)
2019-06-26 02:28:46,772 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022846764669
2019-06-26 02:28:46,792 [salt.minion      :1432][INFO    ][10732] Starting a new job with PID 10732
2019-06-26 02:28:46,813 [salt.minion      :1711][INFO    ][10732] Returning information for job: 20190626022846764669
2019-06-26 02:29:16,952 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022916940991
2019-06-26 02:29:16,975 [salt.minion      :1432][INFO    ][10821] Starting a new job with PID 10821
2019-06-26 02:29:16,986 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1519.73259115s left)
2019-06-26 02:29:17,001 [salt.minion      :1711][INFO    ][10821] Returning information for job: 20190626022916940991
2019-06-26 02:29:46,977 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626022946965397
2019-06-26 02:29:47,005 [salt.minion      :1432][INFO    ][10889] Starting a new job with PID 10889
2019-06-26 02:29:47,029 [salt.minion      :1711][INFO    ][10889] Returning information for job: 20190626022946965397
2019-06-26 02:29:50,957 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1485.76203203s left)
2019-06-26 02:30:17,012 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023016997926
2019-06-26 02:30:17,039 [salt.minion      :1432][INFO    ][11076] Starting a new job with PID 11076
2019-06-26 02:30:17,065 [salt.minion      :1711][INFO    ][11076] Returning information for job: 20190626023016997926
2019-06-26 02:30:24,000 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1452.71886706s left)
2019-06-26 02:30:47,028 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023047020209
2019-06-26 02:30:47,058 [salt.minion      :1432][INFO    ][11159] Starting a new job with PID 11159
2019-06-26 02:30:47,079 [salt.minion      :1711][INFO    ][11159] Returning information for job: 20190626023047020209
2019-06-26 02:30:56,883 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1419.83553815s left)
2019-06-26 02:31:17,057 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023117040403
2019-06-26 02:31:17,083 [salt.minion      :1432][INFO    ][11218] Starting a new job with PID 11218
2019-06-26 02:31:17,106 [salt.minion      :1711][INFO    ][11218] Returning information for job: 20190626023117040403
2019-06-26 02:31:29,797 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1386.92184019s left)
2019-06-26 02:31:47,095 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023147083612
2019-06-26 02:31:47,122 [salt.minion      :1432][INFO    ][11250] Starting a new job with PID 11250
2019-06-26 02:31:47,146 [salt.minion      :1711][INFO    ][11250] Returning information for job: 20190626023147083612
2019-06-26 02:32:02,675 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1354.04407907s left)
2019-06-26 02:32:17,153 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023217139676
2019-06-26 02:32:17,182 [salt.minion      :1432][INFO    ][11300] Starting a new job with PID 11300
2019-06-26 02:32:17,205 [salt.minion      :1711][INFO    ][11300] Returning information for job: 20190626023217139676
2019-06-26 02:32:35,811 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1320.90736723s left)
2019-06-26 02:32:47,220 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023247209280
2019-06-26 02:32:47,245 [salt.minion      :1432][INFO    ][11329] Starting a new job with PID 11329
2019-06-26 02:32:47,266 [salt.minion      :1711][INFO    ][11329] Returning information for job: 20190626023247209280
2019-06-26 02:33:08,586 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1288.13275719s left)
2019-06-26 02:33:17,274 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023317260572
2019-06-26 02:33:17,303 [salt.minion      :1432][INFO    ][11385] Starting a new job with PID 11385
2019-06-26 02:33:17,327 [salt.minion      :1711][INFO    ][11385] Returning information for job: 20190626023317260572
2019-06-26 02:33:41,394 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1255.32513905s left)
2019-06-26 02:33:47,358 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023347346916
2019-06-26 02:33:47,385 [salt.minion      :1432][INFO    ][11415] Starting a new job with PID 11415
2019-06-26 02:33:47,413 [salt.minion      :1711][INFO    ][11415] Returning information for job: 20190626023347346916
2019-06-26 02:34:14,098 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1222.62138319s left)
2019-06-26 02:34:17,452 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023417439319
2019-06-26 02:34:17,470 [salt.minion      :1432][INFO    ][11471] Starting a new job with PID 11471
2019-06-26 02:34:17,492 [salt.minion      :1711][INFO    ][11471] Returning information for job: 20190626023417439319
2019-06-26 02:34:47,148 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1189.57072902s left)
2019-06-26 02:34:47,540 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023447528388
2019-06-26 02:34:47,568 [salt.minion      :1432][INFO    ][11520] Starting a new job with PID 11520
2019-06-26 02:34:47,603 [salt.minion      :1711][INFO    ][11520] Returning information for job: 20190626023447528388
2019-06-26 02:35:17,683 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023517673928
2019-06-26 02:35:17,699 [salt.minion      :1432][INFO    ][11575] Starting a new job with PID 11575
2019-06-26 02:35:17,727 [salt.minion      :1711][INFO    ][11575] Returning information for job: 20190626023517673928
2019-06-26 02:35:19,840 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1156.87876415s left)
2019-06-26 02:35:47,811 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023547797172
2019-06-26 02:35:47,836 [salt.minion      :1432][INFO    ][11616] Starting a new job with PID 11616
2019-06-26 02:35:47,865 [salt.minion      :1711][INFO    ][11616] Returning information for job: 20190626023547797172
2019-06-26 02:35:52,806 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1123.91256618s left)
2019-06-26 02:36:17,964 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023617951567
2019-06-26 02:36:17,992 [salt.minion      :1432][INFO    ][11658] Starting a new job with PID 11658
2019-06-26 02:36:18,014 [salt.minion      :1711][INFO    ][11658] Returning information for job: 20190626023617951567
2019-06-26 02:36:25,691 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1091.0276022s left)
2019-06-26 02:36:48,121 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023648112059
2019-06-26 02:36:48,142 [salt.minion      :1432][INFO    ][11703] Starting a new job with PID 11703
2019-06-26 02:36:48,165 [salt.minion      :1711][INFO    ][11703] Returning information for job: 20190626023648112059
2019-06-26 02:36:58,570 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1058.14823103s left)
2019-06-26 02:37:18,305 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023718288406
2019-06-26 02:37:18,332 [salt.minion      :1432][INFO    ][11734] Starting a new job with PID 11734
2019-06-26 02:37:18,354 [salt.minion      :1711][INFO    ][11734] Returning information for job: 20190626023718288406
2019-06-26 02:37:31,262 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1025.45739603s left)
2019-06-26 02:37:48,483 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023748470752
2019-06-26 02:37:48,511 [salt.minion      :1432][INFO    ][11785] Starting a new job with PID 11785
2019-06-26 02:37:48,534 [salt.minion      :1711][INFO    ][11785] Returning information for job: 20190626023748470752
2019-06-26 02:38:04,028 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (992.690777063s left)
2019-06-26 02:38:18,712 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023818696839
2019-06-26 02:38:18,742 [salt.minion      :1432][INFO    ][11815] Starting a new job with PID 11815
2019-06-26 02:38:18,765 [salt.minion      :1711][INFO    ][11815] Returning information for job: 20190626023818696839
2019-06-26 02:38:36,892 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (959.826625109s left)
2019-06-26 02:38:48,932 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023848921481
2019-06-26 02:38:48,955 [salt.minion      :1432][INFO    ][11866] Starting a new job with PID 11866
2019-06-26 02:38:48,977 [salt.minion      :1711][INFO    ][11866] Returning information for job: 20190626023848921481
2019-06-26 02:39:09,776 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (926.942625999s left)
2019-06-26 02:39:18,965 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023918952787
2019-06-26 02:39:18,994 [salt.minion      :1432][INFO    ][11896] Starting a new job with PID 11896
2019-06-26 02:39:19,023 [salt.minion      :1711][INFO    ][11896] Returning information for job: 20190626023918952787
2019-06-26 02:39:42,436 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (894.282531023s left)
2019-06-26 02:39:48,988 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626023948974914
2019-06-26 02:39:49,011 [salt.minion      :1432][INFO    ][11947] Starting a new job with PID 11947
2019-06-26 02:39:49,033 [salt.minion      :1711][INFO    ][11947] Returning information for job: 20190626023948974914
2019-06-26 02:40:15,349 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (861.369531155s left)
2019-06-26 02:40:19,056 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024019042420
2019-06-26 02:40:19,084 [salt.minion      :1432][INFO    ][11975] Starting a new job with PID 11975
2019-06-26 02:40:19,110 [salt.minion      :1711][INFO    ][11975] Returning information for job: 20190626024019042420
2019-06-26 02:40:48,137 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (828.58172822s left)
2019-06-26 02:40:49,160 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024049150699
2019-06-26 02:40:49,183 [salt.minion      :1432][INFO    ][12030] Starting a new job with PID 12030
2019-06-26 02:40:49,218 [salt.minion      :1711][INFO    ][12030] Returning information for job: 20190626024049150699
2019-06-26 02:41:19,265 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024119253446
2019-06-26 02:41:19,290 [salt.minion      :1432][INFO    ][12055] Starting a new job with PID 12055
2019-06-26 02:41:19,313 [salt.minion      :1711][INFO    ][12055] Returning information for job: 20190626024119253446
2019-06-26 02:41:21,083 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (795.635765076s left)
2019-06-26 02:41:49,391 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024149376154
2019-06-26 02:41:49,416 [salt.minion      :1432][INFO    ][12102] Starting a new job with PID 12102
2019-06-26 02:41:49,439 [salt.minion      :1711][INFO    ][12102] Returning information for job: 20190626024149376154
2019-06-26 02:41:53,900 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (762.818603992s left)
2019-06-26 02:42:19,494 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024219481482
2019-06-26 02:42:19,524 [salt.minion      :1432][INFO    ][12132] Starting a new job with PID 12132
2019-06-26 02:42:19,547 [salt.minion      :1711][INFO    ][12132] Returning information for job: 20190626024219481482
2019-06-26 02:42:26,840 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (729.878811121s left)
2019-06-26 02:42:49,661 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024249651927
2019-06-26 02:42:49,684 [salt.minion      :1432][INFO    ][12185] Starting a new job with PID 12185
2019-06-26 02:42:49,711 [salt.minion      :1711][INFO    ][12185] Returning information for job: 20190626024249651927
2019-06-26 02:42:59,683 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (697.035987139s left)
2019-06-26 02:43:19,800 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024319786835
2019-06-26 02:43:19,828 [salt.minion      :1432][INFO    ][12212] Starting a new job with PID 12212
2019-06-26 02:43:19,852 [salt.minion      :1711][INFO    ][12212] Returning information for job: 20190626024319786835
2019-06-26 02:43:32,540 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (664.17890501s left)
2019-06-26 02:43:49,963 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024349950906
2019-06-26 02:43:49,989 [salt.minion      :1432][INFO    ][12269] Starting a new job with PID 12269
2019-06-26 02:43:50,014 [salt.minion      :1711][INFO    ][12269] Returning information for job: 20190626024349950906
2019-06-26 02:44:05,332 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (631.386383057s left)
2019-06-26 02:44:20,145 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024420131757
2019-06-26 02:44:20,172 [salt.minion      :1432][INFO    ][12293] Starting a new job with PID 12293
2019-06-26 02:44:20,198 [salt.minion      :1711][INFO    ][12293] Returning information for job: 20190626024420131757
2019-06-26 02:44:38,107 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (598.611527205s left)
2019-06-26 02:44:50,189 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024450175151
2019-06-26 02:44:50,214 [salt.minion      :1432][INFO    ][12485] Starting a new job with PID 12485
2019-06-26 02:44:50,240 [salt.minion      :1711][INFO    ][12485] Returning information for job: 20190626024450175151
2019-06-26 02:45:10,878 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (565.840489149s left)
2019-06-26 02:45:20,421 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024520408085
2019-06-26 02:45:20,452 [salt.minion      :1432][INFO    ][12519] Starting a new job with PID 12519
2019-06-26 02:45:20,485 [salt.minion      :1711][INFO    ][12519] Returning information for job: 20190626024520408085
2019-06-26 02:45:43,601 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (533.118000031s left)
2019-06-26 02:45:50,509 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024550495100
2019-06-26 02:45:50,532 [salt.minion      :1432][INFO    ][12573] Starting a new job with PID 12573
2019-06-26 02:45:50,554 [salt.minion      :1711][INFO    ][12573] Returning information for job: 20190626024550495100
2019-06-26 02:46:16,475 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (500.243571997s left)
2019-06-26 02:46:20,567 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024620551718
2019-06-26 02:46:20,595 [salt.minion      :1432][INFO    ][12601] Starting a new job with PID 12601
2019-06-26 02:46:20,618 [salt.minion      :1711][INFO    ][12601] Returning information for job: 20190626024620551718
2019-06-26 02:46:49,640 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (467.078216076s left)
2019-06-26 02:46:50,687 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024650673545
2019-06-26 02:46:50,710 [salt.minion      :1432][INFO    ][12656] Starting a new job with PID 12656
2019-06-26 02:46:50,735 [salt.minion      :1711][INFO    ][12656] Returning information for job: 20190626024650673545
2019-06-26 02:47:20,824 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024720815125
2019-06-26 02:47:20,841 [salt.minion      :1432][INFO    ][12677] Starting a new job with PID 12677
2019-06-26 02:47:20,863 [salt.minion      :1711][INFO    ][12677] Returning information for job: 20190626024720815125
2019-06-26 02:47:22,348 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (434.370613098s left)
2019-06-26 02:47:50,975 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024750967481
2019-06-26 02:47:51,000 [salt.minion      :1432][INFO    ][12728] Starting a new job with PID 12728
2019-06-26 02:47:51,021 [salt.minion      :1711][INFO    ][12728] Returning information for job: 20190626024750967481
2019-06-26 02:47:55,100 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (401.618936062s left)
2019-06-26 02:48:21,173 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024821156434
2019-06-26 02:48:21,197 [salt.minion      :1432][INFO    ][12754] Starting a new job with PID 12754
2019-06-26 02:48:21,220 [salt.minion      :1711][INFO    ][12754] Returning information for job: 20190626024821156434
2019-06-26 02:48:27,824 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (368.894288063s left)
2019-06-26 02:48:51,320 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024851304911
2019-06-26 02:48:51,347 [salt.minion      :1432][INFO    ][12808] Starting a new job with PID 12808
2019-06-26 02:48:51,368 [salt.minion      :1711][INFO    ][12808] Returning information for job: 20190626024851304911
2019-06-26 02:49:00,832 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (335.886671066s left)
2019-06-26 02:49:21,521 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024921507730
2019-06-26 02:49:21,543 [salt.minion      :1432][INFO    ][12831] Starting a new job with PID 12831
2019-06-26 02:49:21,569 [salt.minion      :1711][INFO    ][12831] Returning information for job: 20190626024921507730
2019-06-26 02:49:33,501 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (303.2171731s left)
2019-06-26 02:49:51,751 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626024951742437
2019-06-26 02:49:51,776 [salt.minion      :1432][INFO    ][12887] Starting a new job with PID 12887
2019-06-26 02:49:51,798 [salt.minion      :1711][INFO    ][12887] Returning information for job: 20190626024951742437
2019-06-26 02:50:06,292 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (270.426470995s left)
2019-06-26 02:50:21,793 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025021775049
2019-06-26 02:50:21,826 [salt.minion      :1432][INFO    ][12913] Starting a new job with PID 12913
2019-06-26 02:50:21,848 [salt.minion      :1711][INFO    ][12913] Returning information for job: 20190626025021775049
2019-06-26 02:50:39,223 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (237.495845079s left)
2019-06-26 02:50:51,860 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025051848456
2019-06-26 02:50:51,889 [salt.minion      :1432][INFO    ][12967] Starting a new job with PID 12967
2019-06-26 02:50:51,912 [salt.minion      :1711][INFO    ][12967] Returning information for job: 20190626025051848456
2019-06-26 02:51:12,077 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (204.641560078s left)
2019-06-26 02:51:21,942 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025121925334
2019-06-26 02:51:21,971 [salt.minion      :1432][INFO    ][12991] Starting a new job with PID 12991
2019-06-26 02:51:21,996 [salt.minion      :1711][INFO    ][12991] Returning information for job: 20190626025121925334
2019-06-26 02:51:44,744 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (171.974984169s left)
2019-06-26 02:51:52,016 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025152003943
2019-06-26 02:51:52,043 [salt.minion      :1432][INFO    ][13043] Starting a new job with PID 13043
2019-06-26 02:51:52,065 [salt.minion      :1711][INFO    ][13043] Returning information for job: 20190626025152003943
2019-06-26 02:52:17,625 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (139.093350172s left)
2019-06-26 02:52:22,159 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025222145495
2019-06-26 02:52:22,186 [salt.minion      :1432][INFO    ][13069] Starting a new job with PID 13069
2019-06-26 02:52:22,208 [salt.minion      :1711][INFO    ][13069] Returning information for job: 20190626025222145495
2019-06-26 02:52:50,493 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (106.225474119s left)
2019-06-26 02:52:52,273 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025252265202
2019-06-26 02:52:52,295 [salt.minion      :1432][INFO    ][13124] Starting a new job with PID 13124
2019-06-26 02:52:52,319 [salt.minion      :1711][INFO    ][13124] Returning information for job: 20190626025252265202
2019-06-26 02:53:22,412 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025322399676
2019-06-26 02:53:22,433 [salt.minion      :1432][INFO    ][13149] Starting a new job with PID 13149
2019-06-26 02:53:22,458 [salt.minion      :1711][INFO    ][13149] Returning information for job: 20190626025322399676
2019-06-26 02:53:23,304 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (73.4145200253s left)
2019-06-26 02:53:52,584 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025352570581
2019-06-26 02:53:52,614 [salt.minion      :1432][INFO    ][13196] Starting a new job with PID 13196
2019-06-26 02:53:52,635 [salt.minion      :1711][INFO    ][13196] Returning information for job: 20190626025352570581
2019-06-26 02:53:56,213 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (40.5060520172s left)
2019-06-26 02:54:22,739 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025422732148
2019-06-26 02:54:22,768 [salt.minion      :1432][INFO    ][13222] Starting a new job with PID 13222
2019-06-26 02:54:22,788 [salt.minion      :1711][INFO    ][13222] Returning information for job: 20190626025422732148
2019-06-26 02:54:29,108 [salt.loaded.ext.module.maas:1023][INFO    ][7587] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (7.61036205292s left)
2019-06-26 02:54:52,936 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025452924703
2019-06-26 02:54:52,960 [salt.minion      :1432][INFO    ][13289] Starting a new job with PID 13289
2019-06-26 02:54:52,981 [salt.minion      :1711][INFO    ][13289] Returning information for job: 20190626025452924703
2019-06-26 02:55:01,866 [salt.state       :302 ][ERROR   ][7587] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['kvm02']not in Deployed state
2019-06-26 02:55:01,866 [salt.state       :1951][INFO    ][7587] Completed state [maas.wait_for_machine_status] at time 02:55:01.866686 duration_in_ms=2275157.743
2019-06-26 02:55:01,872 [salt.minion      :1711][INFO    ][7587] Returning information for job: 20190626021658768833
2019-06-26 02:55:12,748 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command pillar.get with jid 20190626025512732303
2019-06-26 02:55:12,772 [salt.minion      :1432][INFO    ][13313] Starting a new job with PID 13313
2019-06-26 02:55:12,780 [salt.minion      :1711][INFO    ][13313] Returning information for job: 20190626025512732303
2019-06-26 02:55:13,340 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command service.status with jid 20190626025513324780
2019-06-26 02:55:13,363 [salt.minion      :1432][INFO    ][13318] Starting a new job with PID 13318
2019-06-26 02:55:13,956 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13318] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:13,996 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13318] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-26 02:55:14,015 [salt.minion      :1711][INFO    ][13318] Returning information for job: 20190626025513324780
2019-06-26 02:55:14,587 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025514573339
2019-06-26 02:55:14,617 [salt.minion      :1432][INFO    ][13329] Starting a new job with PID 13329
2019-06-26 02:55:20,803 [salt.state       :915 ][INFO    ][13329] Loading fresh modules for state activity
2019-06-26 02:55:21,391 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 02:55:21,717 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 02:55:22,740 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 02:55:23,035 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 02:55:24,843 [salt.state       :1780][INFO    ][13329] Running state [salt-minion] at time 02:55:24.843463
2019-06-26 02:55:24,843 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [salt-minion]
2019-06-26 02:55:24,844 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 02:55:24,965 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:24,966 [salt.state       :1951][INFO    ][13329] Completed state [salt-minion] at time 02:55:24.966223 duration_in_ms=122.761
2019-06-26 02:55:24,966 [salt.state       :1780][INFO    ][13329] Running state [salt_minion_dependency_packages] at time 02:55:24.966542
2019-06-26 02:55:24,967 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-26 02:55:24,977 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:24,977 [salt.state       :1951][INFO    ][13329] Completed state [salt_minion_dependency_packages] at time 02:55:24.977192 duration_in_ms=10.65
2019-06-26 02:55:24,980 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/minion.d/minion.conf] at time 02:55:24.980105
2019-06-26 02:55:24,980 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-26 02:55:25,246 [salt.state       :300 ][INFO    ][13329] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-26 02:55:25,246 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/minion.d/minion.conf] at time 02:55:25.246900 duration_in_ms=266.795
2019-06-26 02:55:25,247 [salt.state       :1780][INFO    ][13329] Running state [python-netaddr] at time 02:55:25.247150
2019-06-26 02:55:25,247 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [python-netaddr]
2019-06-26 02:55:25,256 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:25,256 [salt.state       :1951][INFO    ][13329] Completed state [python-netaddr] at time 02:55:25.256521 duration_in_ms=9.371
2019-06-26 02:55:25,259 [salt.state       :1780][INFO    ][13329] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:55:25.259840
2019-06-26 02:55:25,260 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-26 02:55:25,271 [salt.state       :300 ][INFO    ][13329] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-26 02:55:25,272 [salt.state       :1951][INFO    ][13329] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:55:25.272089 duration_in_ms=12.249
2019-06-26 02:55:25,273 [salt.state       :1780][INFO    ][13329] Running state [salt-minion] at time 02:55:25.273177
2019-06-26 02:55:25,273 [salt.state       :1813][INFO    ][13329] Executing state service.running for [salt-minion]
2019-06-26 02:55:25,275 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:25,319 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-26 02:55:25,341 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-26 02:55:25,362 [salt.state       :300 ][INFO    ][13329] The service salt-minion is already running
2019-06-26 02:55:25,363 [salt.state       :1951][INFO    ][13329] Completed state [salt-minion] at time 02:55:25.363046 duration_in_ms=89.868
2019-06-26 02:55:25,366 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains.d] at time 02:55:25.366513
2019-06-26 02:55:25,367 [salt.state       :1813][INFO    ][13329] Executing state file.directory for [/etc/salt/grains.d]
2019-06-26 02:55:25,369 [salt.state       :300 ][INFO    ][13329] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-26 02:55:25,369 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains.d] at time 02:55:25.369460 duration_in_ms=2.947
2019-06-26 02:55:25,372 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains] at time 02:55:25.372689
2019-06-26 02:55:25,372 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/grains]
2019-06-26 02:55:25,373 [salt.state       :300 ][INFO    ][13329] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-26 02:55:25,373 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains] at time 02:55:25.373682 duration_in_ms=0.993
2019-06-26 02:55:25,374 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains.d/placeholder] at time 02:55:25.374171
2019-06-26 02:55:25,374 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-26 02:55:25,374 [salt.state       :300 ][INFO    ][13329] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-26 02:55:25,375 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains.d/placeholder] at time 02:55:25.375136 duration_in_ms=0.965
2019-06-26 02:55:25,375 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains.d/sphinx] at time 02:55:25.375618
2019-06-26 02:55:25,375 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-26 02:55:25,377 [salt.state       :300 ][INFO    ][13329] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-26 02:55:25,377 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains.d/sphinx] at time 02:55:25.377225 duration_in_ms=1.607
2019-06-26 02:55:25,379 [salt.state       :1780][INFO    ][13329] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.379620
2019-06-26 02:55:25,379 [salt.state       :1813][INFO    ][13329] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 02:55:25,380 [salt.state       :300 ][INFO    ][13329] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-26 02:55:25,380 [salt.state       :1951][INFO    ][13329] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.380406 duration_in_ms=0.785
2019-06-26 02:55:25,380 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains.d/dns_records] at time 02:55:25.380897
2019-06-26 02:55:25,381 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-26 02:55:25,383 [salt.state       :300 ][INFO    ][13329] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-26 02:55:25,384 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains.d/dns_records] at time 02:55:25.384098 duration_in_ms=3.202
2019-06-26 02:55:25,385 [salt.state       :1780][INFO    ][13329] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.385013
2019-06-26 02:55:25,385 [salt.state       :1813][INFO    ][13329] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 02:55:25,385 [salt.state       :300 ][INFO    ][13329] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-26 02:55:25,386 [salt.state       :1951][INFO    ][13329] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.386097 duration_in_ms=1.084
2019-06-26 02:55:25,386 [salt.state       :1780][INFO    ][13329] Running state [/etc/salt/grains.d/salt] at time 02:55:25.386570
2019-06-26 02:55:25,386 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-26 02:55:25,387 [salt.state       :300 ][INFO    ][13329] File /etc/salt/grains.d/salt is in the correct state
2019-06-26 02:55:25,387 [salt.state       :1951][INFO    ][13329] Completed state [/etc/salt/grains.d/salt] at time 02:55:25.387911 duration_in_ms=1.341
2019-06-26 02:55:25,388 [salt.state       :1780][INFO    ][13329] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.388781
2019-06-26 02:55:25,389 [salt.state       :1813][INFO    ][13329] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 02:55:25,389 [salt.state       :300 ][INFO    ][13329] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-26 02:55:25,389 [salt.state       :1951][INFO    ][13329] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:55:25.389516 duration_in_ms=0.736
2019-06-26 02:55:25,391 [salt.state       :1780][INFO    ][13329] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:55:25.391435
2019-06-26 02:55:25,391 [salt.state       :1813][INFO    ][13329] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-26 02:55:25,392 [salt.state       :300 ][INFO    ][13329] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-26 02:55:25,392 [salt.state       :1951][INFO    ][13329] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:55:25.392198 duration_in_ms=0.763
2019-06-26 02:55:25,392 [salt.state       :1780][INFO    ][13329] Running state [mine.update] at time 02:55:25.392850
2019-06-26 02:55:25,393 [salt.state       :1813][INFO    ][13329] Executing state module.wait for [mine.update]
2019-06-26 02:55:25,393 [salt.state       :300 ][INFO    ][13329] No changes made for mine.update
2019-06-26 02:55:25,393 [salt.state       :1951][INFO    ][13329] Completed state [mine.update] at time 02:55:25.393541 duration_in_ms=0.69
2019-06-26 02:55:25,395 [salt.state       :1780][INFO    ][13329] Running state [ca-certificates] at time 02:55:25.395006
2019-06-26 02:55:25,395 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [ca-certificates]
2019-06-26 02:55:25,403 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:25,404 [salt.state       :1951][INFO    ][13329] Completed state [ca-certificates] at time 02:55:25.404125 duration_in_ms=9.119
2019-06-26 02:55:25,404 [salt.state       :1780][INFO    ][13329] Running state [update-ca-certificates] at time 02:55:25.404814
2019-06-26 02:55:25,405 [salt.state       :1813][INFO    ][13329] Executing state cmd.wait for [update-ca-certificates]
2019-06-26 02:55:25,405 [salt.state       :300 ][INFO    ][13329] No changes made for update-ca-certificates
2019-06-26 02:55:25,405 [salt.state       :1951][INFO    ][13329] Completed state [update-ca-certificates] at time 02:55:25.405538 duration_in_ms=0.724
2019-06-26 02:55:25,406 [salt.state       :1780][INFO    ][13329] Running state [iptables] at time 02:55:25.406427
2019-06-26 02:55:25,406 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [iptables]
2019-06-26 02:55:25,415 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:25,415 [salt.state       :1951][INFO    ][13329] Completed state [iptables] at time 02:55:25.415336 duration_in_ms=8.909
2019-06-26 02:55:25,415 [salt.state       :1780][INFO    ][13329] Running state [iptables-persistent] at time 02:55:25.415572
2019-06-26 02:55:25,415 [salt.state       :1813][INFO    ][13329] Executing state pkg.installed for [iptables-persistent]
2019-06-26 02:55:25,424 [salt.state       :300 ][INFO    ][13329] All specified packages are already installed
2019-06-26 02:55:25,425 [salt.state       :1951][INFO    ][13329] Completed state [iptables-persistent] at time 02:55:25.425109 duration_in_ms=9.537
2019-06-26 02:55:25,426 [salt.state       :1780][INFO    ][13329] Running state [iptables_modules_v4_load] at time 02:55:25.426318
2019-06-26 02:55:25,426 [salt.state       :1813][INFO    ][13329] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-26 02:55:25,427 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'lsmod' in directory '/root'
2019-06-26 02:55:25,447 [salt.state       :300 ][INFO    ][13329] Kernel modules iptable_filter, ip_tables are already present
2019-06-26 02:55:25,448 [salt.state       :1951][INFO    ][13329] Completed state [iptables_modules_v4_load] at time 02:55:25.448412 duration_in_ms=22.093
2019-06-26 02:55:25,450 [salt.state       :1780][INFO    ][13329] Running state [/etc/iptables/rules.v4] at time 02:55:25.449663
2019-06-26 02:55:25,450 [salt.state       :1813][INFO    ][13329] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-26 02:55:25,554 [salt.state       :300 ][INFO    ][13329] File /etc/iptables/rules.v4 is in the correct state
2019-06-26 02:55:25,554 [salt.state       :1951][INFO    ][13329] Completed state [/etc/iptables/rules.v4] at time 02:55:25.554664 duration_in_ms=105.001
2019-06-26 02:55:25,555 [salt.state       :1780][INFO    ][13329] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:55:25.555728
2019-06-26 02:55:25,556 [salt.state       :1813][INFO    ][13329] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-26 02:55:25,556 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-26 02:55:25,576 [salt.state       :300 ][INFO    ][13329] onlyif execution failed
2019-06-26 02:55:25,577 [salt.state       :1951][INFO    ][13329] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:55:25.577297 duration_in_ms=21.568
2019-06-26 02:55:25,580 [salt.state       :1780][INFO    ][13329] Running state [netfilter-persistent] at time 02:55:25.580765
2019-06-26 02:55:25,581 [salt.state       :1813][INFO    ][13329] Executing state service.running for [netfilter-persistent]
2019-06-26 02:55:25,582 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:25,607 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-26 02:55:25,628 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-26 02:55:25,649 [salt.state       :300 ][INFO    ][13329] The service netfilter-persistent is already running
2019-06-26 02:55:25,650 [salt.state       :1951][INFO    ][13329] Completed state [netfilter-persistent] at time 02:55:25.650133 duration_in_ms=69.368
2019-06-26 02:55:25,651 [salt.state       :1780][INFO    ][13329] Running state [iptables_extra.remove_stale_tables] at time 02:55:25.651699
2019-06-26 02:55:25,652 [salt.state       :1813][INFO    ][13329] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-26 02:55:25,652 [salt.state       :300 ][INFO    ][13329] No changes made for iptables_extra.remove_stale_tables
2019-06-26 02:55:25,653 [salt.state       :1951][INFO    ][13329] Completed state [iptables_extra.remove_stale_tables] at time 02:55:25.653156 duration_in_ms=1.457
2019-06-26 02:55:25,653 [salt.state       :1780][INFO    ][13329] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:55:25.653608
2019-06-26 02:55:25,654 [salt.state       :1813][INFO    ][13329] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-26 02:55:25,655 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13329] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-26 02:55:25,673 [salt.state       :300 ][INFO    ][13329] onlyif execution failed
2019-06-26 02:55:25,674 [salt.state       :1951][INFO    ][13329] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:55:25.674417 duration_in_ms=20.808
2019-06-26 02:55:25,676 [salt.state       :1780][INFO    ][13329] Running state [/etc/iptables/rules.v6] at time 02:55:25.676226
2019-06-26 02:55:25,676 [salt.state       :1813][INFO    ][13329] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-26 02:55:25,677 [salt.state       :300 ][INFO    ][13329] File /etc/iptables/rules.v6 is not present
2019-06-26 02:55:25,678 [salt.state       :1951][INFO    ][13329] Completed state [/etc/iptables/rules.v6] at time 02:55:25.678023 duration_in_ms=1.797
2019-06-26 02:55:25,679 [salt.state       :1780][INFO    ][13329] Running state [iptables_extra.flush_all] at time 02:55:25.679382
2019-06-26 02:55:25,679 [salt.state       :1813][INFO    ][13329] Executing state module.wait for [iptables_extra.flush_all]
2019-06-26 02:55:25,680 [salt.state       :300 ][INFO    ][13329] No changes made for iptables_extra.flush_all
2019-06-26 02:55:25,680 [salt.state       :1951][INFO    ][13329] Completed state [iptables_extra.flush_all] at time 02:55:25.680825 duration_in_ms=1.443
2019-06-26 02:55:25,687 [salt.minion      :1711][INFO    ][13329] Returning information for job: 20190626025514573339
2019-06-26 02:55:26,253 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025526242670
2019-06-26 02:55:26,277 [salt.minion      :1432][INFO    ][13414] Starting a new job with PID 13414
2019-06-26 02:55:27,353 [salt.state       :915 ][INFO    ][13414] Loading fresh modules for state activity
2019-06-26 02:55:28,287 [salt.state       :1780][INFO    ][13414] Running state [maas-rack-controller] at time 02:55:28.286940
2019-06-26 02:55:28,287 [salt.state       :1813][INFO    ][13414] Executing state pkg.installed for [maas-rack-controller]
2019-06-26 02:55:28,288 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13414] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 02:55:28,397 [salt.state       :300 ][INFO    ][13414] All specified packages are already installed
2019-06-26 02:55:28,398 [salt.state       :1951][INFO    ][13414] Completed state [maas-rack-controller] at time 02:55:28.398233 duration_in_ms=111.294
2019-06-26 02:55:28,398 [salt.state       :1780][INFO    ][13414] Running state [ipmitool] at time 02:55:28.398567
2019-06-26 02:55:28,398 [salt.state       :1813][INFO    ][13414] Executing state pkg.installed for [ipmitool]
2019-06-26 02:55:28,408 [salt.state       :300 ][INFO    ][13414] All specified packages are already installed
2019-06-26 02:55:28,408 [salt.state       :1951][INFO    ][13414] Completed state [ipmitool] at time 02:55:28.408175 duration_in_ms=9.608
2019-06-26 02:55:28,411 [salt.state       :1780][INFO    ][13414] Running state [/etc/maas/rackd.conf] at time 02:55:28.411166
2019-06-26 02:55:28,411 [salt.state       :1813][INFO    ][13414] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-26 02:55:28,412 [salt.state       :300 ][INFO    ][13414] No changes needed to be made
2019-06-26 02:55:28,412 [salt.state       :1951][INFO    ][13414] Completed state [/etc/maas/rackd.conf] at time 02:55:28.412478 duration_in_ms=1.312
2019-06-26 02:55:28,412 [salt.state       :1780][INFO    ][13414] Running state [/etc/maas/rackd.conf] at time 02:55:28.412710
2019-06-26 02:55:28,412 [salt.state       :1813][INFO    ][13414] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-26 02:55:28,413 [salt.loaded.int.states.file:2298][WARNING ][13414] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-26 02:55:28,413 [salt.state       :300 ][INFO    ][13414] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-26 02:55:28,414 [salt.state       :1951][INFO    ][13414] Completed state [/etc/maas/rackd.conf] at time 02:55:28.414138 duration_in_ms=1.428
2019-06-26 02:55:28,415 [salt.state       :1780][INFO    ][13414] Running state [maas-rackd] at time 02:55:28.415108
2019-06-26 02:55:28,415 [salt.state       :1813][INFO    ][13414] Executing state service.running for [maas-rackd]
2019-06-26 02:55:28,415 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13414] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:28,456 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13414] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-26 02:55:28,476 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13414] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-26 02:55:28,499 [salt.state       :300 ][INFO    ][13414] The service maas-rackd is already running
2019-06-26 02:55:28,500 [salt.state       :1951][INFO    ][13414] Completed state [maas-rackd] at time 02:55:28.500236 duration_in_ms=85.127
2019-06-26 02:55:28,504 [salt.minion      :1711][INFO    ][13414] Returning information for job: 20190626025526242670
2019-06-26 02:55:29,073 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025529059519
2019-06-26 02:55:29,097 [salt.minion      :1432][INFO    ][13437] Starting a new job with PID 13437
2019-06-26 02:55:30,066 [salt.state       :915 ][INFO    ][13437] Loading fresh modules for state activity
2019-06-26 02:55:31,110 [salt.state       :1780][INFO    ][13437] Running state [maas-region-controller] at time 02:55:31.110750
2019-06-26 02:55:31,111 [salt.state       :1813][INFO    ][13437] Executing state pkg.installed for [maas-region-controller]
2019-06-26 02:55:31,111 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 02:55:31,222 [salt.state       :300 ][INFO    ][13437] All specified packages are already installed
2019-06-26 02:55:31,223 [salt.state       :1951][INFO    ][13437] Completed state [maas-region-controller] at time 02:55:31.222989 duration_in_ms=112.24
2019-06-26 02:55:31,223 [salt.state       :1780][INFO    ][13437] Running state [python-oauth] at time 02:55:31.223302
2019-06-26 02:55:31,223 [salt.state       :1813][INFO    ][13437] Executing state pkg.installed for [python-oauth]
2019-06-26 02:55:31,232 [salt.state       :300 ][INFO    ][13437] All specified packages are already installed
2019-06-26 02:55:31,233 [salt.state       :1951][INFO    ][13437] Completed state [python-oauth] at time 02:55:31.233053 duration_in_ms=9.751
2019-06-26 02:55:31,236 [salt.state       :1780][INFO    ][13437] Running state [/etc/maas/regiond.conf] at time 02:55:31.235981
2019-06-26 02:55:31,236 [salt.state       :1813][INFO    ][13437] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-26 02:55:31,241 [salt.state       :300 ][INFO    ][13437] No changes needed to be made
2019-06-26 02:55:31,241 [salt.state       :1951][INFO    ][13437] Completed state [/etc/maas/regiond.conf] at time 02:55:31.241574 duration_in_ms=5.594
2019-06-26 02:55:31,242 [salt.state       :1780][INFO    ][13437] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:55:31.242059
2019-06-26 02:55:31,242 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-26 02:55:31,291 [salt.state       :300 ][INFO    ][13437] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-26 02:55:31,291 [salt.state       :1951][INFO    ][13437] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:55:31.291679 duration_in_ms=49.619
2019-06-26 02:55:31,292 [salt.state       :1780][INFO    ][13437] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:55:31.292185
2019-06-26 02:55:31,292 [salt.state       :1813][INFO    ][13437] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-26 02:55:31,296 [salt.state       :300 ][INFO    ][13437] No changes needed to be made
2019-06-26 02:55:31,296 [salt.state       :1951][INFO    ][13437] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:55:31.296682 duration_in_ms=4.497
2019-06-26 02:55:31,297 [salt.state       :1780][INFO    ][13437] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:55:31.297185
2019-06-26 02:55:31,297 [salt.state       :1813][INFO    ][13437] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-26 02:55:31,301 [salt.state       :300 ][INFO    ][13437] No changes needed to be made
2019-06-26 02:55:31,302 [salt.state       :1951][INFO    ][13437] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:55:31.301950 duration_in_ms=4.765
2019-06-26 02:55:31,302 [salt.state       :1780][INFO    ][13437] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:55:31.302425
2019-06-26 02:55:31,302 [salt.state       :1813][INFO    ][13437] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-26 02:55:31,333 [salt.state       :300 ][INFO    ][13437] No changes needed to be made
2019-06-26 02:55:31,335 [salt.state       :1951][INFO    ][13437] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:55:31.335477 duration_in_ms=33.051
2019-06-26 02:55:31,336 [salt.state       :1780][INFO    ][13437] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:55:31.336030
2019-06-26 02:55:31,336 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-26 02:55:31,351 [salt.state       :300 ][INFO    ][13437] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-26 02:55:31,352 [salt.state       :1951][INFO    ][13437] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:55:31.352076 duration_in_ms=16.046
2019-06-26 02:55:31,353 [salt.state       :1780][INFO    ][13437] Running state [a2enmod headers] at time 02:55:31.353624
2019-06-26 02:55:31,354 [salt.state       :1813][INFO    ][13437] Executing state cmd.run for [a2enmod headers]
2019-06-26 02:55:31,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command 'a2enmod headers' in directory '/root'
2019-06-26 02:55:31,426 [salt.state       :300 ][INFO    ][13437] {'pid': 13456, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-26 02:55:31,427 [salt.state       :1951][INFO    ][13437] Completed state [a2enmod headers] at time 02:55:31.427274 duration_in_ms=73.65
2019-06-26 02:55:31,428 [salt.state       :1780][INFO    ][13437] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:55:31.427933
2019-06-26 02:55:31,428 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-26 02:55:31,459 [salt.state       :300 ][INFO    ][13437] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-26 02:55:31,459 [salt.state       :1951][INFO    ][13437] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:55:31.459423 duration_in_ms=31.491
2019-06-26 02:55:31,460 [salt.state       :1780][INFO    ][13437] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:55:31.459997
2019-06-26 02:55:31,460 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-26 02:55:31,520 [salt.state       :300 ][INFO    ][13437] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-26 02:55:31,520 [salt.state       :1951][INFO    ][13437] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:55:31.520519 duration_in_ms=60.521
2019-06-26 02:55:31,521 [salt.state       :1780][INFO    ][13437] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:55:31.521525
2019-06-26 02:55:31,522 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-26 02:55:31,587 [salt.state       :300 ][INFO    ][13437] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-26 02:55:31,588 [salt.state       :1951][INFO    ][13437] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:55:31.588133 duration_in_ms=66.608
2019-06-26 02:55:31,588 [salt.state       :1780][INFO    ][13437] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:55:31.588640
2019-06-26 02:55:31,588 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-26 02:55:31,656 [salt.state       :300 ][INFO    ][13437] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-26 02:55:31,656 [salt.state       :1951][INFO    ][13437] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:55:31.656407 duration_in_ms=67.766
2019-06-26 02:55:31,656 [salt.state       :1780][INFO    ][13437] Running state [/root/.pgpass] at time 02:55:31.656850
2019-06-26 02:55:31,657 [salt.state       :1813][INFO    ][13437] Executing state file.managed for [/root/.pgpass]
2019-06-26 02:55:31,709 [salt.state       :300 ][INFO    ][13437] File /root/.pgpass is in the correct state
2019-06-26 02:55:31,709 [salt.state       :1951][INFO    ][13437] Completed state [/root/.pgpass] at time 02:55:31.709254 duration_in_ms=52.404
2019-06-26 02:55:31,714 [salt.state       :1780][INFO    ][13437] Running state [maas-region syncdb --noinput] at time 02:55:31.714329
2019-06-26 02:55:31,714 [salt.state       :1813][INFO    ][13437] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-26 02:55:31,715 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-26 02:55:34,235 [salt.state       :300 ][INFO    ][13437] {'pid': 13469, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, sites, maasserver, piston3, contenttypes, auth, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-26 02:55:34,236 [salt.state       :1951][INFO    ][13437] Completed state [maas-region syncdb --noinput] at time 02:55:34.236289 duration_in_ms=2521.959
2019-06-26 02:55:34,236 [salt.state       :2022][WARNING ][13437] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-26 02:55:34,240 [salt.state       :1780][INFO    ][13437] Running state [maas-regiond] at time 02:55:34.240889
2019-06-26 02:55:34,241 [salt.state       :1813][INFO    ][13437] Executing state service.running for [maas-regiond]
2019-06-26 02:55:34,242 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:34,282 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-26 02:55:34,301 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-26 02:55:34,320 [salt.state       :300 ][INFO    ][13437] The service maas-regiond is already running
2019-06-26 02:55:34,320 [salt.state       :1951][INFO    ][13437] Completed state [maas-regiond] at time 02:55:34.320734 duration_in_ms=79.844
2019-06-26 02:55:34,325 [salt.state       :1780][INFO    ][13437] Running state [bind9] at time 02:55:34.325447
2019-06-26 02:55:34,325 [salt.state       :1813][INFO    ][13437] Executing state service.running for [bind9]
2019-06-26 02:55:34,326 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:34,345 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-26 02:55:34,366 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-26 02:55:34,385 [salt.state       :300 ][INFO    ][13437] The service bind9 is already running
2019-06-26 02:55:34,386 [salt.state       :1951][INFO    ][13437] Completed state [bind9] at time 02:55:34.385952 duration_in_ms=60.505
2019-06-26 02:55:34,387 [salt.state       :1780][INFO    ][13437] Running state [apache2] at time 02:55:34.387670
2019-06-26 02:55:34,388 [salt.state       :1813][INFO    ][13437] Executing state service.running for [apache2]
2019-06-26 02:55:34,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-26 02:55:34,410 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-26 02:55:34,427 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-26 02:55:34,459 [salt.state       :300 ][INFO    ][13437] The service apache2 is already running
2019-06-26 02:55:34,459 [salt.state       :1951][INFO    ][13437] Completed state [apache2] at time 02:55:34.459634 duration_in_ms=71.963
2019-06-26 02:55:34,461 [salt.state       :1780][INFO    ][13437] Running state [maasng.wait_for_http_code] at time 02:55:34.461468
2019-06-26 02:55:34,462 [salt.state       :1813][INFO    ][13437] Executing state module.run for [maasng.wait_for_http_code]
2019-06-26 02:55:34,462 [salt.utils.decorators:613 ][WARNING ][13437] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:55:34,583 [salt.state       :300 ][INFO    ][13437] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-26 02:55:34,583 [salt.state       :1951][INFO    ][13437] Completed state [maasng.wait_for_http_code] at time 02:55:34.583533 duration_in_ms=122.064
2019-06-26 02:55:34,584 [salt.state       :1780][INFO    ][13437] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:55:34.584686
2019-06-26 02:55:34,585 [salt.state       :1813][INFO    ][13437] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-26 02:55:34,586 [salt.state       :300 ][INFO    ][13437] /var/lib/maas/.setup_admin exists
2019-06-26 02:55:34,586 [salt.state       :1951][INFO    ][13437] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:55:34.586848 duration_in_ms=2.163
2019-06-26 02:55:34,588 [salt.state       :1780][INFO    ][13437] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:55:34.587973
2019-06-26 02:55:34,588 [salt.state       :1813][INFO    ][13437] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:55:34,589 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13437] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:55:36,305 [salt.state       :300 ][INFO    ][13437] {'pid': 13505, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:55:36,306 [salt.state       :1951][INFO    ][13437] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:55:36.306497 duration_in_ms=1718.524
2019-06-26 02:55:36,315 [salt.state       :1780][INFO    ][13437] Running state [maas_region_boot_source_resources_mirror] at time 02:55:36.315897
2019-06-26 02:55:36,316 [salt.state       :1813][INFO    ][13437] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-26 02:55:36,405 [salt.state       :300 ][INFO    ][13437] {'changes': {}}
2019-06-26 02:55:36,405 [salt.state       :1951][INFO    ][13437] Completed state [maas_region_boot_source_resources_mirror] at time 02:55:36.405594 duration_in_ms=89.696
2019-06-26 02:55:36,407 [salt.state       :1780][INFO    ][13437] Running state [maasng.boot_resources_import] at time 02:55:36.407167
2019-06-26 02:55:36,407 [salt.state       :1813][INFO    ][13437] Executing state module.run for [maasng.boot_resources_import]
2019-06-26 02:55:36,408 [salt.utils.decorators:613 ][WARNING ][13437] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:55:36,505 [salt.loaded.ext.module.maasng:1600][INFO    ][13437] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-26 02:55:41,561 [salt.loaded.ext.module.maasng:1600][INFO    ][13437] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-26 02:55:44,129 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025544117091
2019-06-26 02:55:44,155 [salt.minion      :1432][INFO    ][13540] Starting a new job with PID 13540
2019-06-26 02:55:44,179 [salt.minion      :1711][INFO    ][13540] Returning information for job: 20190626025544117091
2019-06-26 02:55:46,668 [salt.state       :300 ][INFO    ][13437] {'ret': True}
2019-06-26 02:55:46,669 [salt.state       :1951][INFO    ][13437] Completed state [maasng.boot_resources_import] at time 02:55:46.669276 duration_in_ms=10262.109
2019-06-26 02:55:46,671 [salt.state       :1780][INFO    ][13437] Running state [maas_region_boot_sources_selection_xenial] at time 02:55:46.671541
2019-06-26 02:55:46,672 [salt.state       :1813][INFO    ][13437] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-26 02:55:46,858 [salt.state       :300 ][INFO    ][13437] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-26 02:55:46,858 [salt.state       :1951][INFO    ][13437] Completed state [maas_region_boot_sources_selection_xenial] at time 02:55:46.858719 duration_in_ms=187.177
2019-06-26 02:55:46,860 [salt.state       :1780][INFO    ][13437] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 02:55:46.860149
2019-06-26 02:55:46,860 [salt.state       :1813][INFO    ][13437] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-26 02:55:46,863 [salt.utils.decorators:613 ][WARNING ][13437] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:55:46,864 [salt.loaded.ext.module.maasng:1771][INFO    ][13437] boot-sources sync initiated for ALL Rack's
2019-06-26 02:55:48,006 [salt.state       :300 ][INFO    ][13437] {'ret': True}
2019-06-26 02:55:48,007 [salt.state       :1951][INFO    ][13437] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 02:55:48.007053 duration_in_ms=1146.905
2019-06-26 02:55:48,009 [salt.state       :1780][INFO    ][13437] Running state [maas.process_maas_config] at time 02:55:48.009139
2019-06-26 02:55:48,009 [salt.state       :1813][INFO    ][13437] Executing state module.run for [maas.process_maas_config]
2019-06-26 02:55:48,010 [salt.utils.decorators:613 ][WARNING ][13437] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:55:48,011 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=enable_http_proxy value=True
2019-06-26 02:55:48,065 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=upstream_dns value=8.8.8.8
2019-06-26 02:55:48,124 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=commissioning_distro_series value=xenial
2019-06-26 02:55:48,184 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=default_osystem value=ubuntu
2019-06-26 02:55:49,931 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=active_discovery_interval value=600
2019-06-26 02:55:50,004 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=dnssec_validation value=no
2019-06-26 02:55:50,052 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=maas_name value=mas01
2019-06-26 02:55:50,110 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=network_discovery value=enabled
2019-06-26 02:55:50,208 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=enable_third_party_drivers value=True
2019-06-26 02:55:50,259 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=default_storage_layout value=lvm
2019-06-26 02:55:50,309 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=ntp_external_only value=True
2019-06-26 02:55:50,355 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-26 02:55:50,406 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=default_distro_series value=xenial
2019-06-26 02:55:50,465 [salt.loaded.ext.module.maas:92  ][INFO    ][13437] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-06-26 02:55:50,581 [salt.state       :300 ][INFO    ][13437] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-06-26 02:55:50,581 [salt.state       :1951][INFO    ][13437] Completed state [maas.process_maas_config] at time 02:55:50.581349 duration_in_ms=2572.21
2019-06-26 02:55:50,584 [salt.state       :1780][INFO    ][13437] Running state [pxe_admin] at time 02:55:50.584904
2019-06-26 02:55:50,585 [salt.state       :1813][INFO    ][13437] Executing state maasng.fabric_present for [pxe_admin]
2019-06-26 02:55:50,664 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 02:55:50,729 [salt.loaded.ext.module.maasng:1008][WARNING ][13437] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-26 02:55:50,729 [salt.loaded.ext.module.maasng:1011][WARNING ][13437] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-26 02:55:50,793 [salt.state       :300 ][INFO    ][13437] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-26 02:55:50,793 [salt.state       :1951][INFO    ][13437] Completed state [pxe_admin] at time 02:55:50.793407 duration_in_ms=208.502
2019-06-26 02:55:50,794 [salt.state       :1780][INFO    ][13437] Running state [vlan 0] at time 02:55:50.794690
2019-06-26 02:55:50,795 [salt.state       :1813][INFO    ][13437] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-26 02:55:50,859 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 02:55:50,986 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 02:55:51,231 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-06-26 02:55:51,318 [salt.state       :300 ][INFO    ][13437] {'new': 'Vlan untagged was updated'}
2019-06-26 02:55:51,318 [salt.state       :1951][INFO    ][13437] Completed state [vlan 0] at time 02:55:51.318702 duration_in_ms=524.012
2019-06-26 02:55:51,320 [salt.state       :1780][INFO    ][13437] Running state [192.168.11.0/24] at time 02:55:51.320135
2019-06-26 02:55:51,320 [salt.state       :1813][INFO    ][13437] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-26 02:55:51,503 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-06-26 02:55:51,503 [salt.loaded.ext.module.maasng:1235][WARNING ][13437] Ignoring parameter vlan:0
2019-06-26 02:55:51,567 [salt.state       :300 ][INFO    ][13437] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-26 02:55:51,567 [salt.state       :1951][INFO    ][13437] Completed state [192.168.11.0/24] at time 02:55:51.567699 duration_in_ms=247.563
2019-06-26 02:55:51,568 [salt.state       :1780][INFO    ][13437] Running state [maas_create_iprange_1] at time 02:55:51.568531
2019-06-26 02:55:51,568 [salt.state       :1813][INFO    ][13437] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-26 02:55:51,622 [salt.state       :300 ][INFO    ][13437] Iprange maas_create_iprange_1 already exist.
2019-06-26 02:55:51,623 [salt.state       :1951][INFO    ][13437] Completed state [maas_create_iprange_1] at time 02:55:51.622970 duration_in_ms=54.439
2019-06-26 02:55:51,623 [salt.state       :1780][INFO    ][13437] Running state [vlan 0] at time 02:55:51.623221
2019-06-26 02:55:51,623 [salt.state       :1813][INFO    ][13437] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-26 02:55:51,674 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 02:55:51,789 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/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'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'fabric-2', 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': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'fabric-2', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'pxe_admin', 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': u'nb4xax', u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'pxe_admin', u'class_type': u''}]
2019-06-26 02:55:52,062 [salt.loaded.ext.module.maasng:945 ][INFO    ][13437] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'nb4xax', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-06-26 02:55:52,182 [salt.state       :300 ][INFO    ][13437] {'new': 'Vlan untagged was updated'}
2019-06-26 02:55:52,183 [salt.state       :1951][INFO    ][13437] Completed state [vlan 0] at time 02:55:52.183265 duration_in_ms=560.043
2019-06-26 02:55:52,183 [salt.state       :1780][INFO    ][13437] Running state [opnfv] at time 02:55:52.183886
2019-06-26 02:55:52,184 [salt.state       :1813][INFO    ][13437] Executing state maasng.sshkey_present for [opnfv]
2019-06-26 02:55:52,224 [salt.loaded.ext.module.maasng:1903][INFO    ][13437] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b', u'keysource': u''}]
2019-06-26 02:55:52,224 [salt.state       :300 ][INFO    ][13437] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-06-26 02:55:52,224 [salt.state       :1951][INFO    ][13437] Completed state [opnfv] at time 02:55:52.224727 duration_in_ms=40.841
2019-06-26 02:55:52,229 [salt.minion      :1711][INFO    ][13437] Returning information for job: 20190626025529059519
2019-06-26 02:55:52,847 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025552836539
2019-06-26 02:55:52,869 [salt.minion      :1432][INFO    ][13919] Starting a new job with PID 13919
2019-06-26 02:55:59,033 [salt.state       :915 ][INFO    ][13919] Loading fresh modules for state activity
2019-06-26 02:55:59,138 [salt.state       :1780][INFO    ][13919] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:55:59.137640
2019-06-26 02:55:59,139 [salt.state       :1813][INFO    ][13919] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:55:59,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13919] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:56:00,929 [salt.state       :300 ][INFO    ][13919] {'pid': 13942, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:56:00,930 [salt.state       :1951][INFO    ][13919] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:00.930807 duration_in_ms=1793.167
2019-06-26 02:56:00,934 [salt.state       :1780][INFO    ][13919] Running state [maas.process_machines] at time 02:56:00.934089
2019-06-26 02:56:00,934 [salt.state       :1813][INFO    ][13919] Executing state module.run for [maas.process_machines]
2019-06-26 02:56:00,935 [salt.utils.decorators:613 ][WARNING ][13919] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:56:01,515 [salt.loaded.ext.module.maas:412 ][WARNING ][13919] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:56:01,515 [salt.loaded.ext.module.maas:92  ][INFO    ][13919] machine hostname=cmp002 power_type=ipmi mac_addresses=['9c:b6:54:8a:10:18'] power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 system_id=cm63ft architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:56:02,797 [salt.loaded.ext.module.maas:412 ][WARNING ][13919] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:56:02,799 [salt.loaded.ext.module.maas:92  ][INFO    ][13919] machine hostname=cmp001 power_type=ipmi mac_addresses=['9c:b6:54:8a:95:a0'] power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 system_id=kmkt4b architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:56:04,016 [salt.loaded.ext.module.maas:412 ][WARNING ][13919] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:56:04,017 [salt.loaded.ext.module.maas:92  ][INFO    ][13919] machine hostname=kvm01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=6c78ng architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:56:05,252 [salt.loaded.ext.module.maas:412 ][WARNING ][13919] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:56:05,253 [salt.loaded.ext.module.maas:92  ][INFO    ][13919] machine hostname=kvm03 power_type=ipmi mac_addresses=['14:58:d0:54:7a:28'] power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 system_id=tksabk architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:56:06,472 [salt.loaded.ext.module.maas:412 ][WARNING ][13919] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 02:56:06,472 [salt.loaded.ext.module.maas:92  ][INFO    ][13919] machine hostname=kvm02 power_type=ipmi mac_addresses=['14:58:d0:54:6a:60'] power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 system_id=w3frpd architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 02:56:07,480 [salt.state       :300 ][INFO    ][13919] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-26 02:56:07,481 [salt.state       :1951][INFO    ][13919] Completed state [maas.process_machines] at time 02:56:07.481433 duration_in_ms=6547.341
2019-06-26 02:56:07,485 [salt.minion      :1711][INFO    ][13919] Returning information for job: 20190626025552836539
2019-06-26 02:56:40,572 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025640557387
2019-06-26 02:56:40,600 [salt.minion      :1432][INFO    ][14190] Starting a new job with PID 14190
2019-06-26 02:56:46,588 [salt.state       :915 ][INFO    ][14190] Loading fresh modules for state activity
2019-06-26 02:56:46,697 [salt.state       :1780][INFO    ][14190] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:46.697359
2019-06-26 02:56:46,697 [salt.state       :1813][INFO    ][14190] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:56:46,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14190] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:56:48,488 [salt.state       :300 ][INFO    ][14190] {'pid': 14198, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:56:48,489 [salt.state       :1951][INFO    ][14190] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:48.489508 duration_in_ms=1792.149
2019-06-26 02:56:48,492 [salt.state       :1780][INFO    ][14190] Running state [maas.wait_for_machine_status] at time 02:56:48.492629
2019-06-26 02:56:48,493 [salt.state       :1813][INFO    ][14190] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 02:56:48,495 [salt.utils.decorators:613 ][WARNING ][14190] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:56:51,265 [salt.state       :300 ][INFO    ][14190] {'ret': True}
2019-06-26 02:56:51,267 [salt.state       :1951][INFO    ][14190] Completed state [maas.wait_for_machine_status] at time 02:56:51.265647 duration_in_ms=2773.016
2019-06-26 02:56:51,270 [salt.minion      :1711][INFO    ][14190] Returning information for job: 20190626025640557387
2019-06-26 02:56:51,819 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025651809019
2019-06-26 02:56:51,845 [salt.minion      :1432][INFO    ][14238] Starting a new job with PID 14238
2019-06-26 02:56:52,780 [salt.state       :915 ][INFO    ][14238] Loading fresh modules for state activity
2019-06-26 02:56:52,926 [salt.state       :1780][INFO    ][14238] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:52.926244
2019-06-26 02:56:52,926 [salt.state       :1813][INFO    ][14238] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:56:52,928 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14238] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:56:54,672 [salt.state       :300 ][INFO    ][14238] {'pid': 14245, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:56:54,674 [salt.state       :1951][INFO    ][14238] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:54.674491 duration_in_ms=1748.245
2019-06-26 02:56:54,678 [salt.state       :1780][INFO    ][14238] Running state [maas_machines_storage_cmp002_lvm] at time 02:56:54.678225
2019-06-26 02:56:54,678 [salt.state       :1813][INFO    ][14238] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-26 02:56:55,233 [salt.state       :300 ][INFO    ][14238] Machine cmp002 is not in Ready state.
2019-06-26 02:56:55,233 [salt.state       :1951][INFO    ][14238] Completed state [maas_machines_storage_cmp002_lvm] at time 02:56:55.233809 duration_in_ms=555.584
2019-06-26 02:56:55,234 [salt.state       :1780][INFO    ][14238] Running state [maas_machines_storage_cmp001_lvm] at time 02:56:55.234209
2019-06-26 02:56:55,234 [salt.state       :1813][INFO    ][14238] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-26 02:56:55,781 [salt.state       :300 ][INFO    ][14238] Machine cmp001 is not in Ready state.
2019-06-26 02:56:55,782 [salt.state       :1951][INFO    ][14238] Completed state [maas_machines_storage_cmp001_lvm] at time 02:56:55.781681 duration_in_ms=547.471
2019-06-26 02:56:55,785 [salt.minion      :1711][INFO    ][14238] Returning information for job: 20190626025651809019
2019-06-26 02:56:56,340 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025656323625
2019-06-26 02:56:56,368 [salt.minion      :1432][INFO    ][14255] Starting a new job with PID 14255
2019-06-26 02:56:57,401 [salt.state       :915 ][INFO    ][14255] Loading fresh modules for state activity
2019-06-26 02:56:57,500 [salt.state       :1780][INFO    ][14255] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:57.500264
2019-06-26 02:56:57,500 [salt.state       :1813][INFO    ][14255] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:56:57,502 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14255] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:56:59,204 [salt.state       :300 ][INFO    ][14255] {'pid': 14262, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:56:59,205 [salt.state       :1951][INFO    ][14255] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:56:59.205265 duration_in_ms=1705.0
2019-06-26 02:56:59,208 [salt.state       :1780][INFO    ][14255] Running state [maas.deploy_machines] at time 02:56:59.208690
2019-06-26 02:56:59,209 [salt.state       :1813][INFO    ][14255] Executing state module.run for [maas.deploy_machines]
2019-06-26 02:56:59,214 [salt.utils.decorators:613 ][WARNING ][14255] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:56:59,739 [salt.loaded.ext.module.maas:684 ][INFO    ][14255] deploymachines hwe_kernel=ga-16.04 system_id=w3frpd distro_series=xenial
2019-06-26 02:57:02,324 [salt.state       :300 ][INFO    ][14255] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {}, 'success': ['kvm02']}}
2019-06-26 02:57:02,325 [salt.state       :1951][INFO    ][14255] Completed state [maas.deploy_machines] at time 02:57:02.325177 duration_in_ms=3116.486
2019-06-26 02:57:02,329 [salt.minion      :1711][INFO    ][14255] Returning information for job: 20190626025656323625
2019-06-26 02:57:02,899 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command state.apply with jid 20190626025702885747
2019-06-26 02:57:02,927 [salt.minion      :1432][INFO    ][14320] Starting a new job with PID 14320
2019-06-26 02:57:08,963 [salt.state       :915 ][INFO    ][14320] Loading fresh modules for state activity
2019-06-26 02:57:09,053 [salt.state       :1780][INFO    ][14320] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:09.053575
2019-06-26 02:57:09,053 [salt.state       :1813][INFO    ][14320] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 02:57:09,055 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14320] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 02:57:10,905 [salt.state       :300 ][INFO    ][14320] {'pid': 14336, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 02:57:10,906 [salt.state       :1951][INFO    ][14320] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:10.906643 duration_in_ms=1853.067
2019-06-26 02:57:10,915 [salt.state       :1780][INFO    ][14320] Running state [maas.wait_for_machine_status] at time 02:57:10.914962
2019-06-26 02:57:10,915 [salt.state       :1813][INFO    ][14320] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 02:57:10,915 [salt.utils.decorators:613 ][WARNING ][14320] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 02:57:13,653 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2247.2728219s left)
2019-06-26 02:57:17,982 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025717924990
2019-06-26 02:57:18,001 [salt.minion      :1432][INFO    ][14358] Starting a new job with PID 14358
2019-06-26 02:57:18,031 [salt.minion      :1711][INFO    ][14358] Returning information for job: 20190626025717924990
2019-06-26 02:57:46,495 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2214.43059897s left)
2019-06-26 02:57:48,055 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025748041431
2019-06-26 02:57:48,084 [salt.minion      :1432][INFO    ][14400] Starting a new job with PID 14400
2019-06-26 02:57:48,109 [salt.minion      :1711][INFO    ][14400] Returning information for job: 20190626025748041431
2019-06-26 02:58:18,121 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025818113204
2019-06-26 02:58:18,139 [salt.minion      :1432][INFO    ][14432] Starting a new job with PID 14432
2019-06-26 02:58:18,162 [salt.minion      :1711][INFO    ][14432] Returning information for job: 20190626025818113204
2019-06-26 02:58:19,020 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2181.90530896s left)
2019-06-26 02:58:48,185 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025848172665
2019-06-26 02:58:48,211 [salt.minion      :1432][INFO    ][14475] Starting a new job with PID 14475
2019-06-26 02:58:48,234 [salt.minion      :1711][INFO    ][14475] Returning information for job: 20190626025848172665
2019-06-26 02:58:51,688 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2149.23754692s left)
2019-06-26 02:59:18,233 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025918220300
2019-06-26 02:59:18,259 [salt.minion      :1432][INFO    ][14509] Starting a new job with PID 14509
2019-06-26 02:59:18,284 [salt.minion      :1711][INFO    ][14509] Returning information for job: 20190626025918220300
2019-06-26 02:59:24,319 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2116.60616398s left)
2019-06-26 02:59:48,280 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626025948267035
2019-06-26 02:59:48,298 [salt.minion      :1432][INFO    ][14559] Starting a new job with PID 14559
2019-06-26 02:59:48,325 [salt.minion      :1711][INFO    ][14559] Returning information for job: 20190626025948267035
2019-06-26 02:59:57,145 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2083.78058004s left)
2019-06-26 03:00:18,355 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030018344284
2019-06-26 03:00:18,370 [salt.minion      :1432][INFO    ][14590] Starting a new job with PID 14590
2019-06-26 03:00:18,393 [salt.minion      :1711][INFO    ][14590] Returning information for job: 20190626030018344284
2019-06-26 03:00:29,913 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2051.01276588s left)
2019-06-26 03:00:48,420 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030048408547
2019-06-26 03:00:48,442 [salt.minion      :1432][INFO    ][14640] Starting a new job with PID 14640
2019-06-26 03:00:48,466 [salt.minion      :1711][INFO    ][14640] Returning information for job: 20190626030048408547
2019-06-26 03:01:02,604 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2018.3219769s left)
2019-06-26 03:01:18,453 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030118440361
2019-06-26 03:01:18,474 [salt.minion      :1432][INFO    ][14693] Starting a new job with PID 14693
2019-06-26 03:01:18,500 [salt.minion      :1711][INFO    ][14693] Returning information for job: 20190626030118440361
2019-06-26 03:01:35,314 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1985.6114769s left)
2019-06-26 03:01:48,535 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030148523393
2019-06-26 03:01:48,559 [salt.minion      :1432][INFO    ][14811] Starting a new job with PID 14811
2019-06-26 03:01:48,589 [salt.minion      :1711][INFO    ][14811] Returning information for job: 20190626030148523393
2019-06-26 03:02:08,073 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1952.85276604s left)
2019-06-26 03:02:18,572 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030218560158
2019-06-26 03:02:18,595 [salt.minion      :1432][INFO    ][14886] Starting a new job with PID 14886
2019-06-26 03:02:18,618 [salt.minion      :1711][INFO    ][14886] Returning information for job: 20190626030218560158
2019-06-26 03:02:40,760 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1920.16595006s left)
2019-06-26 03:02:48,623 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030248611796
2019-06-26 03:02:48,648 [salt.minion      :1432][INFO    ][15000] Starting a new job with PID 15000
2019-06-26 03:02:48,678 [salt.minion      :1711][INFO    ][15000] Returning information for job: 20190626030248611796
2019-06-26 03:03:13,654 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1887.27156305s left)
2019-06-26 03:03:18,692 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030318684536
2019-06-26 03:03:18,717 [salt.minion      :1432][INFO    ][15058] Starting a new job with PID 15058
2019-06-26 03:03:18,744 [salt.minion      :1711][INFO    ][15058] Returning information for job: 20190626030318684536
2019-06-26 03:03:46,629 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1854.29656291s left)
2019-06-26 03:03:48,800 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030348790977
2019-06-26 03:03:48,824 [salt.minion      :1432][INFO    ][15170] Starting a new job with PID 15170
2019-06-26 03:03:48,860 [salt.minion      :1711][INFO    ][15170] Returning information for job: 20190626030348790977
2019-06-26 03:04:18,889 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030418881914
2019-06-26 03:04:18,911 [salt.minion      :1432][INFO    ][15218] Starting a new job with PID 15218
2019-06-26 03:04:18,934 [salt.minion      :1711][INFO    ][15218] Returning information for job: 20190626030418881914
2019-06-26 03:04:19,609 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1821.31653404s left)
2019-06-26 03:04:40,826 [salt.utils.schedule:1377][INFO    ][3172] Running scheduled job: __mine_interval
2019-06-26 03:04:49,038 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030449024753
2019-06-26 03:04:49,064 [salt.minion      :1432][INFO    ][15354] Starting a new job with PID 15354
2019-06-26 03:04:49,090 [salt.minion      :1711][INFO    ][15354] Returning information for job: 20190626030449024753
2019-06-26 03:04:52,675 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1788.250664s left)
2019-06-26 03:05:19,200 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030519183507
2019-06-26 03:05:19,231 [salt.minion      :1432][INFO    ][15554] Starting a new job with PID 15554
2019-06-26 03:05:19,254 [salt.minion      :1711][INFO    ][15554] Returning information for job: 20190626030519183507
2019-06-26 03:05:25,680 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1755.24536204s left)
2019-06-26 03:05:49,363 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030549347306
2019-06-26 03:05:49,390 [salt.minion      :1432][INFO    ][15602] Starting a new job with PID 15602
2019-06-26 03:05:49,414 [salt.minion      :1711][INFO    ][15602] Returning information for job: 20190626030549347306
2019-06-26 03:05:58,659 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1722.26671004s left)
2019-06-26 03:06:19,508 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030619495498
2019-06-26 03:06:19,536 [salt.minion      :1432][INFO    ][15629] Starting a new job with PID 15629
2019-06-26 03:06:19,564 [salt.minion      :1711][INFO    ][15629] Returning information for job: 20190626030619495498
2019-06-26 03:06:31,535 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1689.39063692s left)
2019-06-26 03:06:49,672 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030649662674
2019-06-26 03:06:49,693 [salt.minion      :1432][INFO    ][15687] Starting a new job with PID 15687
2019-06-26 03:06:49,719 [salt.minion      :1711][INFO    ][15687] Returning information for job: 20190626030649662674
2019-06-26 03:07:04,378 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1656.54793406s left)
2019-06-26 03:07:19,824 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030719811172
2019-06-26 03:07:19,851 [salt.minion      :1432][INFO    ][15711] Starting a new job with PID 15711
2019-06-26 03:07:19,877 [salt.minion      :1711][INFO    ][15711] Returning information for job: 20190626030719811172
2019-06-26 03:07:37,306 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1623.61922789s left)
2019-06-26 03:07:49,992 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030749982542
2019-06-26 03:07:50,016 [salt.minion      :1432][INFO    ][15762] Starting a new job with PID 15762
2019-06-26 03:07:50,040 [salt.minion      :1711][INFO    ][15762] Returning information for job: 20190626030749982542
2019-06-26 03:08:10,271 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1590.65464401s left)
2019-06-26 03:08:20,153 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030820137697
2019-06-26 03:08:20,176 [salt.minion      :1432][INFO    ][15788] Starting a new job with PID 15788
2019-06-26 03:08:20,199 [salt.minion      :1711][INFO    ][15788] Returning information for job: 20190626030820137697
2019-06-26 03:08:43,355 [salt.loaded.ext.module.maas:1023][INFO    ][14320] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1557.57036591s left)
2019-06-26 03:08:50,335 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626030850320118
2019-06-26 03:08:50,362 [salt.minion      :1432][INFO    ][15840] Starting a new job with PID 15840
2019-06-26 03:08:50,387 [salt.minion      :1711][INFO    ][15840] Returning information for job: 20190626030850320118
2019-06-26 03:09:16,195 [salt.state       :300 ][INFO    ][14320] {'ret': True}
2019-06-26 03:09:16,195 [salt.state       :1951][INFO    ][14320] Completed state [maas.wait_for_machine_status] at time 03:09:16.195828 duration_in_ms=725280.859
2019-06-26 03:09:16,201 [salt.minion      :1711][INFO    ][14320] Returning information for job: 20190626025702885747
2019-06-26 04:04:40,825 [salt.utils.schedule:1377][INFO    ][3172] Running scheduled job: __mine_interval
2019-06-26 04:35:53,071 [salt.minion      :1308][INFO    ][3172] User sudo_ubuntu Executing command cp.push_dir with jid 20190626043553059728
2019-06-26 04:35:53,096 [salt.minion      :1432][INFO    ][22084] Starting a new job with PID 22084
