2019-04-23 02:03:02,638 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:03:52,687 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:04:42,736 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:05:32,783 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:06:22,828 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:07:12,872 [salt.minion      :870 ][ERROR   ][387] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-23 02:08:46,688 [salt.utils.decorators:613 ][WARNING ][2773] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:08:47,780 [salt.utils.decorators:613 ][WARNING ][2773] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:08:58,592 [salt.loaded.int.states.file:2298][WARNING ][2909] 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-04-23 02:09:02,521 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3179] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-23 02:09:02,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3179] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-04-23 02:09:02,573 [salt.utils.parsers:1051][WARNING ][387] Minion received a SIGTERM. Exiting.
2019-04-23 02:09:03,742 [salt.cli.daemons :293 ][INFO    ][3338] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-04-23 02:09:03,913 [salt.cli.daemons :82  ][INFO    ][3338] Starting up the Salt Minion
2019-04-23 02:09:03,913 [salt.utils.event :1017][INFO    ][3338] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-04-23 02:09:05,071 [salt.minion      :976 ][INFO    ][3338] Creating minion process manager
2019-04-23 02:09:06,305 [salt.state       :2022][WARNING ][3183] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-23 02:09:07,601 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3338] Executing command ['date', '+%z'] in directory '/root'
2019-04-23 02:09:07,626 [salt.utils.schedule:568 ][INFO    ][3338] Updating job settings for scheduled job: __mine_interval
2019-04-23 02:09:07,628 [salt.minion      :1108][INFO    ][3338] Added mine.update to scheduler
2019-04-23 02:09:07,633 [salt.minion      :1975][INFO    ][3338] Minion is starting as user 'root'
2019-04-23 02:09:07,651 [salt.minion      :2336][INFO    ][3338] Minion is ready to receive requests!
2019-04-23 02:09:09,526 [salt.utils.decorators:613 ][WARNING ][3183] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:09:14,785 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423020914774725
2019-04-23 02:09:14,802 [salt.minion      :1432][INFO    ][3851] Starting a new job with PID 3851
2019-04-23 02:09:14,830 [salt.minion      :1711][INFO    ][3851] Returning information for job: 20190423020914774725
2019-04-23 02:09:22,884 [salt.utils.decorators:613 ][WARNING ][3183] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:09:44,805 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423020944793978
2019-04-23 02:09:44,827 [salt.minion      :1432][INFO    ][4350] Starting a new job with PID 4350
2019-04-23 02:09:44,855 [salt.minion      :1711][INFO    ][4350] Returning information for job: 20190423020944793978
2019-04-23 02:09:49,880 [salt.utils.decorators:613 ][WARNING ][3183] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:09:50,801 [salt.utils.decorators:613 ][WARNING ][3183] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:09:51,820 [salt.loaded.ext.module.maasng:1008][WARNING ][3183] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-04-23 02:09:51,820 [salt.loaded.ext.module.maasng:1011][WARNING ][3183] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-04-23 02:09:52,700 [salt.loaded.ext.module.maasng:1235][WARNING ][3183] Ignoring parameter vlan:0
2019-04-23 02:09:54,389 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423020954377804
2019-04-23 02:09:54,406 [salt.minion      :1432][INFO    ][4707] Starting a new job with PID 4707
2019-04-23 02:10:02,462 [salt.state       :915 ][INFO    ][4707] Loading fresh modules for state activity
2019-04-23 02:10:02,525 [salt.fileclient  :1219][INFO    ][4707] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-04-23 02:10:02,572 [salt.state       :1780][INFO    ][4707] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:10:02.571925
2019-04-23 02:10:02,572 [salt.state       :1813][INFO    ][4707] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:10:02,574 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4707] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:10:04,437 [salt.state       :300 ][INFO    ][4707] {'pid': 4751, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:10:04,438 [salt.state       :1951][INFO    ][4707] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:10:04.438479 duration_in_ms=1866.555
2019-04-23 02:10:04,441 [salt.state       :1780][INFO    ][4707] Running state [maas.process_machines] at time 02:10:04.441406
2019-04-23 02:10:04,441 [salt.state       :1813][INFO    ][4707] Executing state module.run for [maas.process_machines]
2019-04-23 02:10:04,444 [salt.utils.decorators:613 ][WARNING ][4707] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:10:04,505 [salt.loaded.ext.module.maas:412 ][WARNING ][4707] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:10:04,506 [salt.loaded.ext.module.maas:92  ][INFO    ][4707] 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-04-23 02:10:05,972 [salt.loaded.ext.module.maas:412 ][WARNING ][4707] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:10:05,972 [salt.loaded.ext.module.maas:92  ][INFO    ][4707] 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-04-23 02:10:07,220 [salt.loaded.ext.module.maas:412 ][WARNING ][4707] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:10:07,220 [salt.loaded.ext.module.maas:92  ][INFO    ][4707] 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-04-23 02:10:08,443 [salt.loaded.ext.module.maas:412 ][WARNING ][4707] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:10:08,444 [salt.loaded.ext.module.maas:92  ][INFO    ][4707] 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-04-23 02:10:09,433 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021009424629
2019-04-23 02:10:09,456 [salt.minion      :1432][INFO    ][4957] Starting a new job with PID 4957
2019-04-23 02:10:09,488 [salt.minion      :1711][INFO    ][4957] Returning information for job: 20190423021009424629
2019-04-23 02:10:09,710 [salt.loaded.ext.module.maas:412 ][WARNING ][4707] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:10:09,712 [salt.loaded.ext.module.maas:92  ][INFO    ][4707] 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-04-23 02:10:11,042 [salt.state       :300 ][INFO    ][4707] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-04-23 02:10:11,042 [salt.state       :1951][INFO    ][4707] Completed state [maas.process_machines] at time 02:10:11.042627 duration_in_ms=6601.221
2019-04-23 02:10:11,051 [salt.minion      :1711][INFO    ][4707] Returning information for job: 20190423020954377804
2019-04-23 02:10:42,383 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423021042371728
2019-04-23 02:10:42,405 [salt.minion      :1432][INFO    ][5111] Starting a new job with PID 5111
2019-04-23 02:10:50,178 [salt.state       :915 ][INFO    ][5111] Loading fresh modules for state activity
2019-04-23 02:10:50,240 [salt.fileclient  :1219][INFO    ][5111] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-04-23 02:10:50,289 [salt.state       :1780][INFO    ][5111] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:10:50.288961
2019-04-23 02:10:50,289 [salt.state       :1813][INFO    ][5111] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:10:50,292 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5111] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:10:52,124 [salt.state       :300 ][INFO    ][5111] {'pid': 5120, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:10:52,125 [salt.state       :1951][INFO    ][5111] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:10:52.125566 duration_in_ms=1836.604
2019-04-23 02:10:52,130 [salt.state       :1780][INFO    ][5111] Running state [maas.wait_for_machine_status] at time 02:10:52.129967
2019-04-23 02:10:52,130 [salt.state       :1813][INFO    ][5111] Executing state module.run for [maas.wait_for_machine_status]
2019-04-23 02:10:52,132 [salt.utils.decorators:613 ][WARNING ][5111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:10:52,949 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.1933651s left)
2019-04-23 02:10:57,465 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021057446226
2019-04-23 02:10:57,487 [salt.minion      :1432][INFO    ][5131] Starting a new job with PID 5131
2019-04-23 02:10:57,514 [salt.minion      :1711][INFO    ][5131] Returning information for job: 20190423021057446226
2019-04-23 02:11:23,747 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.39580798s left)
2019-04-23 02:11:27,660 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021127653446
2019-04-23 02:11:27,672 [salt.minion      :1432][INFO    ][5208] Starting a new job with PID 5208
2019-04-23 02:11:27,700 [salt.minion      :1711][INFO    ][5208] Returning information for job: 20190423021127653446
2019-04-23 02:11:54,525 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.61767197s left)
2019-04-23 02:11:57,730 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021157722748
2019-04-23 02:11:57,753 [salt.minion      :1432][INFO    ][5227] Starting a new job with PID 5227
2019-04-23 02:11:57,780 [salt.minion      :1711][INFO    ][5227] Returning information for job: 20190423021157722748
2019-04-23 02:12:25,416 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.72610998s left)
2019-04-23 02:12:27,765 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021227750671
2019-04-23 02:12:27,787 [salt.minion      :1432][INFO    ][5308] Starting a new job with PID 5308
2019-04-23 02:12:27,814 [salt.minion      :1711][INFO    ][5308] Returning information for job: 20190423021227750671
2019-04-23 02:12:56,533 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.60912991s left)
2019-04-23 02:12:57,817 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021257802029
2019-04-23 02:12:57,840 [salt.minion      :1432][INFO    ][5367] Starting a new job with PID 5367
2019-04-23 02:12:57,872 [salt.minion      :1711][INFO    ][5367] Returning information for job: 20190423021257802029
2019-04-23 02:13:27,666 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.47612906s left)
2019-04-23 02:13:27,901 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021327888454
2019-04-23 02:13:27,920 [salt.minion      :1432][INFO    ][5568] Starting a new job with PID 5568
2019-04-23 02:13:27,947 [salt.minion      :1711][INFO    ][5568] Returning information for job: 20190423021327888454
2019-04-23 02:13:57,969 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021357957626
2019-04-23 02:13:57,986 [salt.minion      :1432][INFO    ][5627] Starting a new job with PID 5627
2019-04-23 02:13:58,017 [salt.minion      :1711][INFO    ][5627] Returning information for job: 20190423021357957626
2019-04-23 02:13:58,765 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1313.3775661s left)
2019-04-23 02:14:28,012 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021428001825
2019-04-23 02:14:28,026 [salt.minion      :1432][INFO    ][5953] Starting a new job with PID 5953
2019-04-23 02:14:28,053 [salt.minion      :1711][INFO    ][5953] Returning information for job: 20190423021428001825
2019-04-23 02:14:29,973 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1282.1698339s left)
2019-04-23 02:14:58,062 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021458048389
2019-04-23 02:14:58,081 [salt.minion      :1432][INFO    ][6056] Starting a new job with PID 6056
2019-04-23 02:14:58,111 [salt.minion      :1711][INFO    ][6056] Returning information for job: 20190423021458048389
2019-04-23 02:15:01,786 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1250.35653996s left)
2019-04-23 02:15:28,236 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021528224401
2019-04-23 02:15:28,250 [salt.minion      :1432][INFO    ][6457] Starting a new job with PID 6457
2019-04-23 02:15:28,278 [salt.minion      :1711][INFO    ][6457] Returning information for job: 20190423021528224401
2019-04-23 02:15:33,718 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1218.42485213s left)
2019-04-23 02:15:58,317 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021558306486
2019-04-23 02:15:58,340 [salt.minion      :1432][INFO    ][6492] Starting a new job with PID 6492
2019-04-23 02:15:58,369 [salt.minion      :1711][INFO    ][6492] Returning information for job: 20190423021558306486
2019-04-23 02:16:05,848 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1186.29411912s left)
2019-04-23 02:16:28,448 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021628436893
2019-04-23 02:16:28,464 [salt.minion      :1432][INFO    ][6754] Starting a new job with PID 6754
2019-04-23 02:16:28,493 [salt.minion      :1711][INFO    ][6754] Returning information for job: 20190423021628436893
2019-04-23 02:16:38,008 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1154.13477302s left)
2019-04-23 02:16:58,538 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021658522534
2019-04-23 02:16:58,556 [salt.minion      :1432][INFO    ][6778] Starting a new job with PID 6778
2019-04-23 02:16:58,584 [salt.minion      :1711][INFO    ][6778] Returning information for job: 20190423021658522534
2019-04-23 02:17:10,343 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1121.7993319s left)
2019-04-23 02:17:28,686 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021728671884
2019-04-23 02:17:28,709 [salt.minion      :1432][INFO    ][7032] Starting a new job with PID 7032
2019-04-23 02:17:28,739 [salt.minion      :1711][INFO    ][7032] Returning information for job: 20190423021728671884
2019-04-23 02:17:42,890 [salt.loaded.ext.module.maas:1023][INFO    ][5111] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1089.25258708s left)
2019-04-23 02:17:58,796 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021758789166
2019-04-23 02:17:58,809 [salt.minion      :1432][INFO    ][7071] Starting a new job with PID 7071
2019-04-23 02:17:58,835 [salt.minion      :1711][INFO    ][7071] Returning information for job: 20190423021758789166
2019-04-23 02:18:15,785 [salt.state       :300 ][INFO    ][5111] {'ret': True}
2019-04-23 02:18:15,785 [salt.state       :1951][INFO    ][5111] Completed state [maas.wait_for_machine_status] at time 02:18:15.785559 duration_in_ms=443655.592
2019-04-23 02:18:15,788 [salt.minion      :1711][INFO    ][5111] Returning information for job: 20190423021042371728
2019-04-23 02:18:16,524 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423021816512097
2019-04-23 02:18:16,538 [salt.minion      :1432][INFO    ][7227] Starting a new job with PID 7227
2019-04-23 02:18:24,187 [salt.state       :915 ][INFO    ][7227] Loading fresh modules for state activity
2019-04-23 02:18:24,251 [salt.fileclient  :1219][INFO    ][7227] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-04-23 02:18:24,350 [salt.state       :1780][INFO    ][7227] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:24.350444
2019-04-23 02:18:24,350 [salt.state       :1813][INFO    ][7227] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:18:24,353 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7227] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:18:26,248 [salt.state       :300 ][INFO    ][7227] {'pid': 7240, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:18:26,249 [salt.state       :1951][INFO    ][7227] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:26.249436 duration_in_ms=1898.991
2019-04-23 02:18:26,254 [salt.state       :1780][INFO    ][7227] Running state [maas_machines_storage_cmp002_lvm] at time 02:18:26.254235
2019-04-23 02:18:26,255 [salt.state       :1813][INFO    ][7227] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-23 02:18:27,374 [salt.loaded.ext.module.maasng:610 ][INFO    ][7227] myakby
2019-04-23 02:18:27,374 [salt.loaded.ext.module.maasng:626 ][INFO    ][7227] sda
2019-04-23 02:18:27,934 [salt.loaded.ext.module.maasng:361 ][INFO    ][7227] myakby
2019-04-23 02:18:28,021 [salt.loaded.ext.module.maasng:367 ][INFO    ][7227] [{u'block_size': 4096, 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'6f6f7fef-89c9-4496-8788-d2cf3c730b29', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myakby', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'41549fbf-7492-4d21-8a2e-9bf75921481d', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'size': 800101236736}], u'filesystem': None, u'id': 1, u'name': u'sda', u'system_id': u'myakby', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/'}, {u'block_size': 4096, u'uuid': u'8ea73191-e107-4d3d-b137-0b63f35afc86', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 800097042432, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'b3505548-6343-49e9-8e18-4bda5fa66190', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id': 3, u'name': u'vgroot-lvroot', u'system_id': u'myakby', 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'size': 800097042432, u'type': u'virtual', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/3/'}]
2019-04-23 02:18:28,021 [salt.loaded.ext.module.maasng:632 ][INFO    ][7227] vgroot
2019-04-23 02:18:28,022 [salt.loaded.ext.module.maasng:635 ][INFO    ][7227] lvroot
2019-04-23 02:18:28,022 [salt.loaded.ext.module.maasng:639 ][INFO    ][7227] 107374182400
2019-04-23 02:18:28,595 [salt.loaded.ext.module.maasng:645 ][INFO    ][7227] {u'hwe_kernel': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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'mode': u'dhcp', u'id': 18}], 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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/4/'}, u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 800109715456, u'available_size': 0, 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'77f95626-1bc9-485b-93cd-c407208011c8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myakby', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'37a94482-befd-4937-a433-44750a7d4d07', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'id': 1, u'name': u'sda', u'system_id': u'myakby', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/'}, 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/myakby/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'myakby', u'power_state': u'off', 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'disable_ipv4': False, u'blockdevice_set': [{u'block_size': 4096, 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'77f95626-1bc9-485b-93cd-c407208011c8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myakby', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'37a94482-befd-4937-a433-44750a7d4d07', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'filesystem': None, u'id': 1, u'name': u'sda', u'system_id': u'myakby', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/'}, {u'block_size': 4096, u'uuid': u'fc2dc2f1-e7e1-4023-96f7-ce57d8a38863', 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'9315338f-5d80-451e-9bbd-eed00932451f', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id': 11, u'name': u'vgroot-lvroot', u'system_id': u'myakby', 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'size': 107374182400, u'type': u'virtual', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/11/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 40, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'myakby', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 800109715456, u'available_size': 0, 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'77f95626-1bc9-485b-93cd-c407208011c8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myakby', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'37a94482-befd-4937-a433-44750a7d4d07', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'id': 1, u'name': u'sda', u'system_id': u'myakby', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/1/'}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'uuid': u'fc2dc2f1-e7e1-4023-96f7-ce57d8a38863', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'id': 11, u'name': u'vgroot-lvroot', u'system_id': u'myakby', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'9315338f-5d80-451e-9bbd-eed00932451f', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, 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'resource_uri': u'/MAAS/api/2.0/nodes/myakby/blockdevices/11/'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'min_hwe_kernel': u'ga-16.04', 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'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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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'mode': u'dhcp', u'id': 18}], 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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/4/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'id': 15, u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:50', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/15/'}, {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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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': 19}], 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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'enabled': True, u'id': 13, 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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/13/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 20}], 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'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 14, u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:48', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/14/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 21}], 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'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 11, u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:49', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/11/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'id': 12, u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:51', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'myakby', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myakby/interfaces/12/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-04-23 02:18:28,598 [salt.state       :300 ][INFO    ][7227] {'new': {'storage_layout': 'lvm'}}
2019-04-23 02:18:28,601 [salt.state       :1951][INFO    ][7227] Completed state [maas_machines_storage_cmp002_lvm] at time 02:18:28.600955 duration_in_ms=2346.72
2019-04-23 02:18:28,601 [salt.state       :1780][INFO    ][7227] Running state [maas_machines_storage_cmp001_lvm] at time 02:18:28.601364
2019-04-23 02:18:28,601 [salt.state       :1813][INFO    ][7227] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-23 02:18:29,712 [salt.loaded.ext.module.maasng:610 ][INFO    ][7227] pcbnx6
2019-04-23 02:18:29,712 [salt.loaded.ext.module.maasng:626 ][INFO    ][7227] sda
2019-04-23 02:18:30,360 [salt.loaded.ext.module.maasng:361 ][INFO    ][7227] pcbnx6
2019-04-23 02:18:30,454 [salt.loaded.ext.module.maasng:367 ][INFO    ][7227] [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/', u'used_size': 800106479616, u'tags': [u'ssd'], u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'pcbnx6', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'1f035915-8f9e-46af-8c99-745ba07bb03d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pcbnx6', u'device_id': 2, u'filesystem': {u'uuid': u'11c6950e-f39f-455d-b0cc-828cb9b644bf', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, 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/pcbnx6/blockdevices/2/partition/2'}]}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/4/', u'used_size': 800097042432, u'tags': [], u'filesystem': {u'uuid': u'f81ec221-d14d-44d1-89c2-a05233643673', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'ee7cb2f7-e50b-436d-b856-725141a635f0', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pcbnx6', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'size': 800097042432, u'type': u'virtual', u'id': 4, u'partitions': []}]
2019-04-23 02:18:30,454 [salt.loaded.ext.module.maasng:632 ][INFO    ][7227] vgroot
2019-04-23 02:18:30,455 [salt.loaded.ext.module.maasng:635 ][INFO    ][7227] lvroot
2019-04-23 02:18:30,455 [salt.loaded.ext.module.maasng:639 ][INFO    ][7227] 107374182400
2019-04-23 02:18:31,052 [salt.loaded.ext.module.maasng:645 ][INFO    ][7227] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {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'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, 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'ty8cwb', 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'effective_mtu': 1500, u'enabled': True, u'id': 5, 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'ty8cwb', 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'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/5/'}, u'ip_addresses': [u'192.168.11.39', u'192.168.11.42'], 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'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/', u'used_size': 800106479616, u'tags': [u'ssd'], u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'pcbnx6', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'a676f7ef-f367-4642-aff1-5d43f23c21fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pcbnx6', u'device_id': 2, u'filesystem': {u'uuid': u'32970027-76d2-4777-92e1-4b110f630537', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/partition/7'}]}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'uuid': u'76a7faca-57f3-4d0b-a172-93c17df31261', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'72de163b-1ce6-4dc9-975f-7aaa74aa4f22', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pcbnx6', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'type': u'virtual', u'id': 12, u'partitions': []}], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'pcbnx6', 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'disable_ipv4': False, u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/', u'used_size': 800106479616, u'tags': [u'ssd'], u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'pcbnx6', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'a676f7ef-f367-4642-aff1-5d43f23c21fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pcbnx6', u'device_id': 2, u'filesystem': {u'uuid': u'32970027-76d2-4777-92e1-4b110f630537', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/partition/7'}]}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'pcbnx6', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'uuid': u'76a7faca-57f3-4d0b-a172-93c17df31261', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'72de163b-1ce6-4dc9-975f-7aaa74aa4f22', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pcbnx6', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'type': u'virtual', u'id': 12, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'commissioning_status_name': u'Passed', u'boot_disk': {u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/', u'used_size': 800106479616, u'tags': [u'ssd'], u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'pcbnx6', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'a676f7ef-f367-4642-aff1-5d43f23c21fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pcbnx6', u'device_id': 2, u'filesystem': {u'uuid': u'32970027-76d2-4777-92e1-4b110f630537', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/blockdevices/2/partition/7'}]}, u'interface_set': [{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'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, 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'ty8cwb', 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'effective_mtu': 1500, u'enabled': True, u'id': 5, 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'ty8cwb', 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'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/5/'}, {u'vlan': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'id': 17, u'discovered': None, u'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'38:ea:a7:8f:1f:d4', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/17/'}, {u'vlan': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'id': 19, u'discovered': None, u'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'38:ea:a7:8f:1f:d5', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/19/'}, {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'name': u'ens2f0', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'id': 16, u'discovered': None, u'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'38:ea:a7:8f:52:cc', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/16/'}, {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'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, 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'ty8cwb', 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'id': 26, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'id': 18, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ty8cwb', 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.42'}], u'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'9c:b6:54:8a:95:a4', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'ens2f1', u'links': [{u'id': 27, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'id': 20, u'discovered': None, u'parents': [], u'system_id': u'pcbnx6', u'mac_address': u'38:ea:a7:8f:52:cd', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/pcbnx6/interfaces/20/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/pcbnx6/'}
2019-04-23 02:18:31,054 [salt.state       :300 ][INFO    ][7227] {'new': {'storage_layout': 'lvm'}}
2019-04-23 02:18:31,055 [salt.state       :1951][INFO    ][7227] Completed state [maas_machines_storage_cmp001_lvm] at time 02:18:31.055021 duration_in_ms=2453.656
2019-04-23 02:18:31,058 [salt.minion      :1711][INFO    ][7227] Returning information for job: 20190423021816512097
2019-04-23 02:18:31,764 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423021831753159
2019-04-23 02:18:31,783 [salt.minion      :1432][INFO    ][7270] Starting a new job with PID 7270
2019-04-23 02:18:32,935 [salt.state       :915 ][INFO    ][7270] Loading fresh modules for state activity
2019-04-23 02:18:32,988 [salt.fileclient  :1219][INFO    ][7270] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-04-23 02:18:33,035 [salt.state       :1780][INFO    ][7270] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:33.035291
2019-04-23 02:18:33,035 [salt.state       :1813][INFO    ][7270] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:18:33,037 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7270] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:18:34,974 [salt.state       :300 ][INFO    ][7270] {'pid': 7277, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:18:34,976 [salt.state       :1951][INFO    ][7270] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:34.975898 duration_in_ms=1940.607
2019-04-23 02:18:34,979 [salt.state       :1780][INFO    ][7270] Running state [maas.deploy_machines] at time 02:18:34.979787
2019-04-23 02:18:34,980 [salt.state       :1813][INFO    ][7270] Executing state module.run for [maas.deploy_machines]
2019-04-23 02:18:34,982 [salt.utils.decorators:613 ][WARNING ][7270] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:18:35,532 [salt.loaded.ext.module.maas:684 ][INFO    ][7270] deploymachines hwe_kernel=ga-16.04 system_id=myakby distro_series=xenial
2019-04-23 02:18:37,862 [salt.loaded.ext.module.maas:684 ][INFO    ][7270] deploymachines hwe_kernel=ga-16.04 system_id=pcbnx6 distro_series=xenial
2019-04-23 02:18:40,220 [salt.loaded.ext.module.maas:684 ][INFO    ][7270] deploymachines hwe_kernel=ga-16.04 system_id=qb7t74 distro_series=xenial
2019-04-23 02:18:42,573 [salt.loaded.ext.module.maas:684 ][INFO    ][7270] deploymachines hwe_kernel=ga-16.04 system_id=syssym distro_series=xenial
2019-04-23 02:18:44,921 [salt.loaded.ext.module.maas:684 ][INFO    ][7270] deploymachines hwe_kernel=ga-16.04 system_id=4ehnhb distro_series=xenial
2019-04-23 02:18:46,873 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021846865319
2019-04-23 02:18:46,892 [salt.minion      :1432][INFO    ][7535] Starting a new job with PID 7535
2019-04-23 02:18:46,924 [salt.minion      :1711][INFO    ][7535] Returning information for job: 20190423021846865319
2019-04-23 02:18:47,338 [salt.state       :300 ][INFO    ][7270] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-04-23 02:18:47,338 [salt.state       :1951][INFO    ][7270] Completed state [maas.deploy_machines] at time 02:18:47.338647 duration_in_ms=12358.86
2019-04-23 02:18:47,342 [salt.minion      :1711][INFO    ][7270] Returning information for job: 20190423021831753159
2019-04-23 02:18:48,032 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423021848018404
2019-04-23 02:18:48,054 [salt.minion      :1432][INFO    ][7553] Starting a new job with PID 7553
2019-04-23 02:18:55,738 [salt.state       :915 ][INFO    ][7553] Loading fresh modules for state activity
2019-04-23 02:18:55,796 [salt.fileclient  :1219][INFO    ][7553] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-04-23 02:18:55,844 [salt.state       :1780][INFO    ][7553] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:55.844305
2019-04-23 02:18:55,844 [salt.state       :1813][INFO    ][7553] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:18:55,846 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7553] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:18:57,808 [salt.state       :300 ][INFO    ][7553] {'pid': 7566, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:18:57,809 [salt.state       :1951][INFO    ][7553] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:18:57.809273 duration_in_ms=1964.968
2019-04-23 02:18:57,812 [salt.state       :1780][INFO    ][7553] Running state [maas.wait_for_machine_status] at time 02:18:57.812528
2019-04-23 02:18:57,813 [salt.state       :1813][INFO    ][7553] Executing state module.run for [maas.wait_for_machine_status]
2019-04-23 02:18:57,813 [salt.utils.decorators:613 ][WARNING ][7553] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:19:00,792 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.0354619s left)
2019-04-23 02:19:03,145 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021903136804
2019-04-23 02:19:03,158 [salt.minion      :1432][INFO    ][7595] Starting a new job with PID 7595
2019-04-23 02:19:03,189 [salt.minion      :1711][INFO    ][7595] Returning information for job: 20190423021903136804
2019-04-23 02:19:33,200 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423021933189144
2019-04-23 02:19:33,214 [salt.minion      :1432][INFO    ][7685] Starting a new job with PID 7685
2019-04-23 02:19:33,246 [salt.minion      :1711][INFO    ][7685] Returning information for job: 20190423021933189144
2019-04-23 02:19:33,559 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.26867294s left)
2019-04-23 02:20:03,287 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022003274173
2019-04-23 02:20:03,309 [salt.minion      :1432][INFO    ][7711] Starting a new job with PID 7711
2019-04-23 02:20:03,340 [salt.minion      :1711][INFO    ][7711] Returning information for job: 20190423022003274173
2019-04-23 02:20:06,310 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2181.51774478s left)
2019-04-23 02:20:33,349 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022033339568
2019-04-23 02:20:33,368 [salt.minion      :1432][INFO    ][7783] Starting a new job with PID 7783
2019-04-23 02:20:33,396 [salt.minion      :1711][INFO    ][7783] Returning information for job: 20190423022033339568
2019-04-23 02:20:39,101 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2148.72723699s left)
2019-04-23 02:21:03,413 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022103406055
2019-04-23 02:21:03,432 [salt.minion      :1432][INFO    ][7813] Starting a new job with PID 7813
2019-04-23 02:21:03,464 [salt.minion      :1711][INFO    ][7813] Returning information for job: 20190423022103406055
2019-04-23 02:21:12,133 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2115.69488978s left)
2019-04-23 02:21:33,465 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022133456453
2019-04-23 02:21:33,480 [salt.minion      :1432][INFO    ][7934] Starting a new job with PID 7934
2019-04-23 02:21:33,513 [salt.minion      :1711][INFO    ][7934] Returning information for job: 20190423022133456453
2019-04-23 02:21:44,935 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2082.89302182s left)
2019-04-23 02:22:03,537 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022203525872
2019-04-23 02:22:03,561 [salt.minion      :1432][INFO    ][8013] Starting a new job with PID 8013
2019-04-23 02:22:03,593 [salt.minion      :1711][INFO    ][8013] Returning information for job: 20190423022203525872
2019-04-23 02:22:17,875 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2049.95239377s left)
2019-04-23 02:22:33,642 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022233629666
2019-04-23 02:22:33,666 [salt.minion      :1432][INFO    ][8284] Starting a new job with PID 8284
2019-04-23 02:22:33,696 [salt.minion      :1711][INFO    ][8284] Returning information for job: 20190423022233629666
2019-04-23 02:22:50,752 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2017.07753778s left)
2019-04-23 02:23:03,686 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022303678883
2019-04-23 02:23:03,704 [salt.minion      :1432][INFO    ][8357] Starting a new job with PID 8357
2019-04-23 02:23:03,731 [salt.minion      :1711][INFO    ][8357] Returning information for job: 20190423022303678883
2019-04-23 02:23:23,778 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1984.04981494s left)
2019-04-23 02:23:33,812 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022333794745
2019-04-23 02:23:33,835 [salt.minion      :1432][INFO    ][8604] Starting a new job with PID 8604
2019-04-23 02:23:33,866 [salt.minion      :1711][INFO    ][8604] Returning information for job: 20190423022333794745
2019-04-23 02:23:56,729 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1951.09848189s left)
2019-04-23 02:24:03,924 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022403914502
2019-04-23 02:24:03,945 [salt.minion      :1432][INFO    ][8653] Starting a new job with PID 8653
2019-04-23 02:24:03,976 [salt.minion      :1711][INFO    ][8653] Returning information for job: 20190423022403914502
2019-04-23 02:24:29,622 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1918.20597982s left)
2019-04-23 02:24:34,097 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022434085557
2019-04-23 02:24:34,113 [salt.minion      :1432][INFO    ][9088] Starting a new job with PID 9088
2019-04-23 02:24:34,142 [salt.minion      :1711][INFO    ][9088] Returning information for job: 20190423022434085557
2019-04-23 02:25:02,578 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1885.25017786s left)
2019-04-23 02:25:04,169 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022504155755
2019-04-23 02:25:04,186 [salt.minion      :1432][INFO    ][9124] Starting a new job with PID 9124
2019-04-23 02:25:04,217 [salt.minion      :1711][INFO    ][9124] Returning information for job: 20190423022504155755
2019-04-23 02:25:34,346 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022534338337
2019-04-23 02:25:34,368 [salt.minion      :1432][INFO    ][9367] Starting a new job with PID 9367
2019-04-23 02:25:34,402 [salt.minion      :1711][INFO    ][9367] Returning information for job: 20190423022534338337
2019-04-23 02:25:35,408 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1852.42012596s left)
2019-04-23 02:26:04,474 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022604460220
2019-04-23 02:26:04,495 [salt.minion      :1432][INFO    ][9399] Starting a new job with PID 9399
2019-04-23 02:26:04,524 [salt.minion      :1711][INFO    ][9399] Returning information for job: 20190423022604460220
2019-04-23 02:26:08,117 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1819.71117496s left)
2019-04-23 02:26:34,673 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022634658147
2019-04-23 02:26:34,691 [salt.minion      :1432][INFO    ][9802] Starting a new job with PID 9802
2019-04-23 02:26:34,722 [salt.minion      :1711][INFO    ][9802] Returning information for job: 20190423022634658147
2019-04-23 02:26:40,822 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1787.00617385s left)
2019-04-23 02:27:04,793 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022704778680
2019-04-23 02:27:04,812 [salt.minion      :1432][INFO    ][9844] Starting a new job with PID 9844
2019-04-23 02:27:04,846 [salt.minion      :1711][INFO    ][9844] Returning information for job: 20190423022704778680
2019-04-23 02:27:14,060 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1753.7682178s left)
2019-04-23 02:27:34,973 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022734961321
2019-04-23 02:27:34,994 [salt.minion      :1432][INFO    ][10122] Starting a new job with PID 10122
2019-04-23 02:27:35,024 [salt.minion      :1711][INFO    ][10122] Returning information for job: 20190423022734961321
2019-04-23 02:27:46,798 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1721.03027296s left)
2019-04-23 02:28:05,117 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022805101939
2019-04-23 02:28:05,137 [salt.minion      :1432][INFO    ][10172] Starting a new job with PID 10172
2019-04-23 02:28:05,166 [salt.minion      :1711][INFO    ][10172] Returning information for job: 20190423022805101939
2019-04-23 02:28:19,643 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1688.18450999s left)
2019-04-23 02:28:35,220 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022835211715
2019-04-23 02:28:35,244 [salt.minion      :1432][INFO    ][10266] Starting a new job with PID 10266
2019-04-23 02:28:35,275 [salt.minion      :1711][INFO    ][10266] Returning information for job: 20190423022835211715
2019-04-23 02:28:52,460 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1655.36776781s left)
2019-04-23 02:29:05,304 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022905290127
2019-04-23 02:29:05,324 [salt.minion      :1432][INFO    ][10452] Starting a new job with PID 10452
2019-04-23 02:29:05,358 [salt.minion      :1711][INFO    ][10452] Returning information for job: 20190423022905290127
2019-04-23 02:29:25,135 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1622.69286084s left)
2019-04-23 02:29:35,360 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423022935352132
2019-04-23 02:29:35,382 [salt.minion      :1432][INFO    ][10741] Starting a new job with PID 10741
2019-04-23 02:29:35,412 [salt.minion      :1711][INFO    ][10741] Returning information for job: 20190423022935352132
2019-04-23 02:29:57,962 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1589.86566281s left)
2019-04-23 02:30:05,525 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023005508498
2019-04-23 02:30:05,545 [salt.minion      :1432][INFO    ][10770] Starting a new job with PID 10770
2019-04-23 02:30:05,578 [salt.minion      :1711][INFO    ][10770] Returning information for job: 20190423023005508498
2019-04-23 02:30:30,600 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1557.22818589s left)
2019-04-23 02:30:35,721 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023035704012
2019-04-23 02:30:35,744 [salt.minion      :1432][INFO    ][10901] Starting a new job with PID 10901
2019-04-23 02:30:35,781 [salt.minion      :1711][INFO    ][10901] Returning information for job: 20190423023035704012
2019-04-23 02:31:03,374 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1524.45427394s left)
2019-04-23 02:31:05,906 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023105898809
2019-04-23 02:31:05,925 [salt.minion      :1432][INFO    ][10972] Starting a new job with PID 10972
2019-04-23 02:31:05,957 [salt.minion      :1711][INFO    ][10972] Returning information for job: 20190423023105898809
2019-04-23 02:31:35,934 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023135922187
2019-04-23 02:31:35,954 [salt.minion      :1432][INFO    ][11076] Starting a new job with PID 11076
2019-04-23 02:31:35,987 [salt.minion      :1711][INFO    ][11076] Returning information for job: 20190423023135922187
2019-04-23 02:31:36,128 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1491.69970989s left)
2019-04-23 02:32:06,149 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023206134398
2019-04-23 02:32:06,170 [salt.minion      :1432][INFO    ][11131] Starting a new job with PID 11131
2019-04-23 02:32:06,208 [salt.minion      :1711][INFO    ][11131] Returning information for job: 20190423023206134398
2019-04-23 02:32:08,851 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1458.97703981s left)
2019-04-23 02:32:36,174 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023236160863
2019-04-23 02:32:36,199 [salt.minion      :1432][INFO    ][11406] Starting a new job with PID 11406
2019-04-23 02:32:36,227 [salt.minion      :1711][INFO    ][11406] Returning information for job: 20190423023236160863
2019-04-23 02:32:41,738 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1426.09018397s left)
2019-04-23 02:33:06,404 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023306391398
2019-04-23 02:33:06,427 [salt.minion      :1432][INFO    ][11434] Starting a new job with PID 11434
2019-04-23 02:33:06,456 [salt.minion      :1711][INFO    ][11434] Returning information for job: 20190423023306391398
2019-04-23 02:33:14,514 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1393.31387091s left)
2019-04-23 02:33:36,626 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023336613217
2019-04-23 02:33:36,646 [salt.minion      :1432][INFO    ][11509] Starting a new job with PID 11509
2019-04-23 02:33:36,679 [salt.minion      :1711][INFO    ][11509] Returning information for job: 20190423023336613217
2019-04-23 02:33:47,216 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1360.61191392s left)
2019-04-23 02:34:06,671 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023406656417
2019-04-23 02:34:06,695 [salt.minion      :1432][INFO    ][11537] Starting a new job with PID 11537
2019-04-23 02:34:06,730 [salt.minion      :1711][INFO    ][11537] Returning information for job: 20190423023406656417
2019-04-23 02:34:19,958 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1327.86960793s left)
2019-04-23 02:34:36,703 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023436690071
2019-04-23 02:34:36,726 [salt.minion      :1432][INFO    ][11609] Starting a new job with PID 11609
2019-04-23 02:34:36,758 [salt.minion      :1711][INFO    ][11609] Returning information for job: 20190423023436690071
2019-04-23 02:34:52,801 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1295.02686381s left)
2019-04-23 02:35:06,774 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023506763565
2019-04-23 02:35:06,794 [salt.minion      :1432][INFO    ][11638] Starting a new job with PID 11638
2019-04-23 02:35:06,829 [salt.minion      :1711][INFO    ][11638] Returning information for job: 20190423023506763565
2019-04-23 02:35:25,481 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1262.34695983s left)
2019-04-23 02:35:36,821 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023536806804
2019-04-23 02:35:36,836 [salt.minion      :1432][INFO    ][11710] Starting a new job with PID 11710
2019-04-23 02:35:36,875 [salt.minion      :1711][INFO    ][11710] Returning information for job: 20190423023536806804
2019-04-23 02:35:58,181 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1229.64675784s left)
2019-04-23 02:36:06,895 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023606881423
2019-04-23 02:36:06,913 [salt.minion      :1432][INFO    ][11745] Starting a new job with PID 11745
2019-04-23 02:36:06,946 [salt.minion      :1711][INFO    ][11745] Returning information for job: 20190423023606881423
2019-04-23 02:36:30,835 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1196.99298692s left)
2019-04-23 02:36:36,949 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023636935417
2019-04-23 02:36:36,970 [salt.minion      :1432][INFO    ][11822] Starting a new job with PID 11822
2019-04-23 02:36:37,001 [salt.minion      :1711][INFO    ][11822] Returning information for job: 20190423023636935417
2019-04-23 02:37:03,576 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1164.25160599s left)
2019-04-23 02:37:07,052 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023707041990
2019-04-23 02:37:07,075 [salt.minion      :1432][INFO    ][11853] Starting a new job with PID 11853
2019-04-23 02:37:07,110 [salt.minion      :1711][INFO    ][11853] Returning information for job: 20190423023707041990
2019-04-23 02:37:36,357 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1131.47119594s left)
2019-04-23 02:37:37,170 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023737162191
2019-04-23 02:37:37,188 [salt.minion      :1432][INFO    ][11927] Starting a new job with PID 11927
2019-04-23 02:37:37,222 [salt.minion      :1711][INFO    ][11927] Returning information for job: 20190423023737162191
2019-04-23 02:38:07,232 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023807223435
2019-04-23 02:38:07,248 [salt.minion      :1432][INFO    ][11953] Starting a new job with PID 11953
2019-04-23 02:38:07,283 [salt.minion      :1711][INFO    ][11953] Returning information for job: 20190423023807223435
2019-04-23 02:38:09,128 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1098.701478s left)
2019-04-23 02:38:37,376 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023837365660
2019-04-23 02:38:37,397 [salt.minion      :1432][INFO    ][12026] Starting a new job with PID 12026
2019-04-23 02:38:37,429 [salt.minion      :1711][INFO    ][12026] Returning information for job: 20190423023837365660
2019-04-23 02:38:41,932 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1065.895473s left)
2019-04-23 02:39:07,506 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023907493486
2019-04-23 02:39:07,523 [salt.minion      :1432][INFO    ][12062] Starting a new job with PID 12062
2019-04-23 02:39:07,559 [salt.minion      :1711][INFO    ][12062] Returning information for job: 20190423023907493486
2019-04-23 02:39:14,748 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1033.07983184s left)
2019-04-23 02:39:37,680 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423023937672451
2019-04-23 02:39:37,701 [salt.minion      :1432][INFO    ][12151] Starting a new job with PID 12151
2019-04-23 02:39:37,733 [salt.minion      :1711][INFO    ][12151] Returning information for job: 20190423023937672451
2019-04-23 02:39:47,429 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1000.39882493s left)
2019-04-23 02:40:07,824 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024007810218
2019-04-23 02:40:07,846 [salt.minion      :1432][INFO    ][12181] Starting a new job with PID 12181
2019-04-23 02:40:07,878 [salt.minion      :1711][INFO    ][12181] Returning information for job: 20190423024007810218
2019-04-23 02:40:20,143 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (967.684749842s left)
2019-04-23 02:40:38,037 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024038021409
2019-04-23 02:40:38,058 [salt.minion      :1432][INFO    ][12255] Starting a new job with PID 12255
2019-04-23 02:40:38,090 [salt.minion      :1711][INFO    ][12255] Returning information for job: 20190423024038021409
2019-04-23 02:40:52,938 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (934.889796972s left)
2019-04-23 02:41:08,224 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024108212289
2019-04-23 02:41:08,237 [salt.minion      :1432][INFO    ][12287] Starting a new job with PID 12287
2019-04-23 02:41:08,266 [salt.minion      :1711][INFO    ][12287] Returning information for job: 20190423024108212289
2019-04-23 02:41:25,728 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (902.100061893s left)
2019-04-23 02:41:38,419 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024138407881
2019-04-23 02:41:38,442 [salt.minion      :1432][INFO    ][12360] Starting a new job with PID 12360
2019-04-23 02:41:38,473 [salt.minion      :1711][INFO    ][12360] Returning information for job: 20190423024138407881
2019-04-23 02:41:58,345 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (869.483016968s left)
2019-04-23 02:42:08,626 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024208615923
2019-04-23 02:42:08,647 [salt.minion      :1432][INFO    ][12390] Starting a new job with PID 12390
2019-04-23 02:42:08,678 [salt.minion      :1711][INFO    ][12390] Returning information for job: 20190423024208615923
2019-04-23 02:42:30,989 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (836.838986874s left)
2019-04-23 02:42:38,661 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024238651478
2019-04-23 02:42:38,682 [salt.minion      :1432][INFO    ][12464] Starting a new job with PID 12464
2019-04-23 02:42:38,713 [salt.minion      :1711][INFO    ][12464] Returning information for job: 20190423024238651478
2019-04-23 02:43:03,730 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (804.09766984s left)
2019-04-23 02:43:08,677 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024308670047
2019-04-23 02:43:08,690 [salt.minion      :1432][INFO    ][12496] Starting a new job with PID 12496
2019-04-23 02:43:08,721 [salt.minion      :1711][INFO    ][12496] Returning information for job: 20190423024308670047
2019-04-23 02:43:36,634 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (771.194081783s left)
2019-04-23 02:43:38,737 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024338725548
2019-04-23 02:43:38,757 [salt.minion      :1432][INFO    ][12568] Starting a new job with PID 12568
2019-04-23 02:43:38,791 [salt.minion      :1711][INFO    ][12568] Returning information for job: 20190423024338725548
2019-04-23 02:44:08,856 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024408845409
2019-04-23 02:44:08,876 [salt.minion      :1432][INFO    ][12598] Starting a new job with PID 12598
2019-04-23 02:44:08,909 [salt.minion      :1711][INFO    ][12598] Returning information for job: 20190423024408845409
2019-04-23 02:44:09,341 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (738.487164974s left)
2019-04-23 02:44:38,950 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024438941868
2019-04-23 02:44:38,972 [salt.minion      :1432][INFO    ][12669] Starting a new job with PID 12669
2019-04-23 02:44:39,004 [salt.minion      :1711][INFO    ][12669] Returning information for job: 20190423024438941868
2019-04-23 02:44:42,116 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (705.711922884s left)
2019-04-23 02:45:09,078 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024509065254
2019-04-23 02:45:09,101 [salt.minion      :1432][INFO    ][12699] Starting a new job with PID 12699
2019-04-23 02:45:09,131 [salt.minion      :1711][INFO    ][12699] Returning information for job: 20190423024509065254
2019-04-23 02:45:14,808 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (673.020903826s left)
2019-04-23 02:45:39,187 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024539177813
2019-04-23 02:45:39,209 [salt.minion      :1432][INFO    ][12773] Starting a new job with PID 12773
2019-04-23 02:45:39,245 [salt.minion      :1711][INFO    ][12773] Returning information for job: 20190423024539177813
2019-04-23 02:45:47,582 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (640.246286869s left)
2019-04-23 02:46:09,377 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024609362656
2019-04-23 02:46:09,394 [salt.minion      :1432][INFO    ][12805] Starting a new job with PID 12805
2019-04-23 02:46:09,428 [salt.minion      :1711][INFO    ][12805] Returning information for job: 20190423024609362656
2019-04-23 02:46:20,419 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (607.408796787s left)
2019-04-23 02:46:39,494 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024639486148
2019-04-23 02:46:39,515 [salt.minion      :1432][INFO    ][12878] Starting a new job with PID 12878
2019-04-23 02:46:39,552 [salt.minion      :1711][INFO    ][12878] Returning information for job: 20190423024639486148
2019-04-23 02:46:53,195 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (574.633036852s left)
2019-04-23 02:47:09,712 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024709704605
2019-04-23 02:47:09,727 [salt.minion      :1432][INFO    ][12916] Starting a new job with PID 12916
2019-04-23 02:47:09,757 [salt.minion      :1711][INFO    ][12916] Returning information for job: 20190423024709704605
2019-04-23 02:47:25,852 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (541.97542882s left)
2019-04-23 02:47:39,760 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024739746182
2019-04-23 02:47:39,779 [salt.minion      :1432][INFO    ][12984] Starting a new job with PID 12984
2019-04-23 02:47:39,812 [salt.minion      :1711][INFO    ][12984] Returning information for job: 20190423024739746182
2019-04-23 02:47:58,497 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (509.330739975s left)
2019-04-23 02:48:09,878 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024809870165
2019-04-23 02:48:09,899 [salt.minion      :1432][INFO    ][13025] Starting a new job with PID 13025
2019-04-23 02:48:09,945 [salt.minion      :1711][INFO    ][13025] Returning information for job: 20190423024809870165
2019-04-23 02:48:31,158 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (476.67024684s left)
2019-04-23 02:48:40,073 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024840061725
2019-04-23 02:48:40,094 [salt.minion      :1432][INFO    ][13090] Starting a new job with PID 13090
2019-04-23 02:48:40,128 [salt.minion      :1711][INFO    ][13090] Returning information for job: 20190423024840061725
2019-04-23 02:49:03,961 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (443.866441965s left)
2019-04-23 02:49:10,178 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024910171360
2019-04-23 02:49:10,195 [salt.minion      :1432][INFO    ][13284] Starting a new job with PID 13284
2019-04-23 02:49:10,226 [salt.minion      :1711][INFO    ][13284] Returning information for job: 20190423024910171360
2019-04-23 02:49:36,841 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (410.986562967s left)
2019-04-23 02:49:40,229 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423024940220681
2019-04-23 02:49:40,243 [salt.minion      :1432][INFO    ][13339] Starting a new job with PID 13339
2019-04-23 02:49:40,274 [salt.minion      :1711][INFO    ][13339] Returning information for job: 20190423024940220681
2019-04-23 02:50:09,610 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (378.218171835s left)
2019-04-23 02:50:10,297 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025010289773
2019-04-23 02:50:10,314 [salt.minion      :1432][INFO    ][13398] Starting a new job with PID 13398
2019-04-23 02:50:10,346 [salt.minion      :1711][INFO    ][13398] Returning information for job: 20190423025010289773
2019-04-23 02:50:40,453 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025040445305
2019-04-23 02:50:40,472 [salt.minion      :1432][INFO    ][13439] Starting a new job with PID 13439
2019-04-23 02:50:40,505 [salt.minion      :1711][INFO    ][13439] Returning information for job: 20190423025040445305
2019-04-23 02:50:42,252 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (345.575760841s left)
2019-04-23 02:51:10,535 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025110528320
2019-04-23 02:51:10,550 [salt.minion      :1432][INFO    ][13501] Starting a new job with PID 13501
2019-04-23 02:51:10,584 [salt.minion      :1711][INFO    ][13501] Returning information for job: 20190423025110528320
2019-04-23 02:51:15,059 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (312.769041777s left)
2019-04-23 02:51:40,725 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025140708445
2019-04-23 02:51:40,747 [salt.minion      :1432][INFO    ][13545] Starting a new job with PID 13545
2019-04-23 02:51:40,778 [salt.minion      :1711][INFO    ][13545] Returning information for job: 20190423025140708445
2019-04-23 02:51:47,725 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (280.103284836s left)
2019-04-23 02:52:10,831 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025210822582
2019-04-23 02:52:10,854 [salt.minion      :1432][INFO    ][13611] Starting a new job with PID 13611
2019-04-23 02:52:10,884 [salt.minion      :1711][INFO    ][13611] Returning information for job: 20190423025210822582
2019-04-23 02:52:20,387 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (247.441053867s left)
2019-04-23 02:52:41,059 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025241050798
2019-04-23 02:52:41,077 [salt.minion      :1432][INFO    ][13649] Starting a new job with PID 13649
2019-04-23 02:52:41,110 [salt.minion      :1711][INFO    ][13649] Returning information for job: 20190423025241050798
2019-04-23 02:52:53,230 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (214.598258972s left)
2019-04-23 02:53:11,205 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025311193046
2019-04-23 02:53:11,225 [salt.minion      :1432][INFO    ][13714] Starting a new job with PID 13714
2019-04-23 02:53:11,255 [salt.minion      :1711][INFO    ][13714] Returning information for job: 20190423025311193046
2019-04-23 02:53:26,027 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (181.800704956s left)
2019-04-23 02:53:41,264 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025341249087
2019-04-23 02:53:41,285 [salt.minion      :1432][INFO    ][13750] Starting a new job with PID 13750
2019-04-23 02:53:41,315 [salt.minion      :1711][INFO    ][13750] Returning information for job: 20190423025341249087
2019-04-23 02:53:58,682 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (149.145791769s left)
2019-04-23 02:54:11,483 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025411474286
2019-04-23 02:54:11,503 [salt.minion      :1432][INFO    ][13822] Starting a new job with PID 13822
2019-04-23 02:54:11,537 [salt.minion      :1711][INFO    ][13822] Returning information for job: 20190423025411474286
2019-04-23 02:54:31,486 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (116.34197998s left)
2019-04-23 02:54:41,562 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025441549574
2019-04-23 02:54:41,581 [salt.minion      :1432][INFO    ][13854] Starting a new job with PID 13854
2019-04-23 02:54:41,614 [salt.minion      :1711][INFO    ][13854] Returning information for job: 20190423025441549574
2019-04-23 02:55:04,183 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (83.6446948051s left)
2019-04-23 02:55:11,765 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025511752868
2019-04-23 02:55:11,782 [salt.minion      :1432][INFO    ][13925] Starting a new job with PID 13925
2019-04-23 02:55:11,816 [salt.minion      :1711][INFO    ][13925] Returning information for job: 20190423025511752868
2019-04-23 02:55:36,924 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (50.903605938s left)
2019-04-23 02:55:41,882 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025541869486
2019-04-23 02:55:41,903 [salt.minion      :1432][INFO    ][13959] Starting a new job with PID 13959
2019-04-23 02:55:41,934 [salt.minion      :1711][INFO    ][13959] Returning information for job: 20190423025541869486
2019-04-23 02:56:09,776 [salt.loaded.ext.module.maas:1023][INFO    ][7553] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (18.0519578457s left)
2019-04-23 02:56:11,993 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025611985240
2019-04-23 02:56:12,007 [salt.minion      :1432][INFO    ][14030] Starting a new job with PID 14030
2019-04-23 02:56:12,038 [salt.minion      :1711][INFO    ][14030] Returning information for job: 20190423025611985240
2019-04-23 02:56:42,068 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025642060054
2019-04-23 02:56:42,085 [salt.minion      :1432][INFO    ][14062] Starting a new job with PID 14062
2019-04-23 02:56:42,118 [salt.minion      :1711][INFO    ][14062] Returning information for job: 20190423025642060054
2019-04-23 02:56:42,463 [salt.state       :302 ][ERROR   ][7553] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['kvm02']not in Deployed state
2019-04-23 02:56:42,464 [salt.state       :1951][INFO    ][7553] Completed state [maas.wait_for_machine_status] at time 02:56:42.464423 duration_in_ms=2264651.891
2019-04-23 02:56:42,474 [salt.minion      :1711][INFO    ][7553] Returning information for job: 20190423021848018404
2019-04-23 02:56:53,368 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command pillar.get with jid 20190423025653358654
2019-04-23 02:56:53,386 [salt.minion      :1432][INFO    ][14071] Starting a new job with PID 14071
2019-04-23 02:56:53,396 [salt.minion      :1711][INFO    ][14071] Returning information for job: 20190423025653358654
2019-04-23 02:56:54,061 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command service.status with jid 20190423025654054158
2019-04-23 02:56:54,081 [salt.minion      :1432][INFO    ][14076] Starting a new job with PID 14076
2019-04-23 02:56:54,824 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14076] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-04-23 02:56:54,863 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14076] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-04-23 02:56:54,883 [salt.minion      :1711][INFO    ][14076] Returning information for job: 20190423025654054158
2019-04-23 02:56:55,562 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025655552278
2019-04-23 02:56:55,582 [salt.minion      :1432][INFO    ][14087] Starting a new job with PID 14087
2019-04-23 02:57:03,091 [salt.state       :915 ][INFO    ][14087] Loading fresh modules for state activity
2019-04-23 02:57:03,677 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'salt-minion --version' in directory '/root'
2019-04-23 02:57:04,029 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'salt-minion --version' in directory '/root'
2019-04-23 02:57:05,072 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'salt-minion --version' in directory '/root'
2019-04-23 02:57:05,424 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'salt-minion --version' in directory '/root'
2019-04-23 02:57:07,570 [salt.state       :1780][INFO    ][14087] Running state [salt-minion] at time 02:57:07.570504
2019-04-23 02:57:07,571 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [salt-minion]
2019-04-23 02:57:07,572 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-23 02:57:07,688 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:07,689 [salt.state       :1951][INFO    ][14087] Completed state [salt-minion] at time 02:57:07.689234 duration_in_ms=118.731
2019-04-23 02:57:07,689 [salt.state       :1780][INFO    ][14087] Running state [salt_minion_dependency_packages] at time 02:57:07.689617
2019-04-23 02:57:07,689 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-04-23 02:57:07,699 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:07,700 [salt.state       :1951][INFO    ][14087] Completed state [salt_minion_dependency_packages] at time 02:57:07.699944 duration_in_ms=10.327
2019-04-23 02:57:07,703 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/minion.d/minion.conf] at time 02:57:07.703533
2019-04-23 02:57:07,703 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-04-23 02:57:07,981 [salt.state       :300 ][INFO    ][14087] File /etc/salt/minion.d/minion.conf is in the correct state
2019-04-23 02:57:07,981 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/minion.d/minion.conf] at time 02:57:07.981470 duration_in_ms=277.936
2019-04-23 02:57:07,981 [salt.state       :1780][INFO    ][14087] Running state [python-netaddr] at time 02:57:07.981913
2019-04-23 02:57:07,982 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [python-netaddr]
2019-04-23 02:57:07,991 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:07,991 [salt.state       :1951][INFO    ][14087] Completed state [python-netaddr] at time 02:57:07.991367 duration_in_ms=9.455
2019-04-23 02:57:07,994 [salt.state       :1780][INFO    ][14087] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:57:07.994674
2019-04-23 02:57:07,995 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-04-23 02:57:08,011 [salt.state       :300 ][INFO    ][14087] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-04-23 02:57:08,012 [salt.state       :1951][INFO    ][14087] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:57:08.012220 duration_in_ms=17.544
2019-04-23 02:57:08,014 [salt.state       :1780][INFO    ][14087] Running state [salt-minion] at time 02:57:08.014247
2019-04-23 02:57:08,015 [salt.state       :1813][INFO    ][14087] Executing state service.running for [salt-minion]
2019-04-23 02:57:08,016 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:08,060 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-04-23 02:57:08,076 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-04-23 02:57:08,094 [salt.state       :300 ][INFO    ][14087] The service salt-minion is already running
2019-04-23 02:57:08,095 [salt.state       :1951][INFO    ][14087] Completed state [salt-minion] at time 02:57:08.095203 duration_in_ms=80.956
2019-04-23 02:57:08,097 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains.d] at time 02:57:08.097671
2019-04-23 02:57:08,098 [salt.state       :1813][INFO    ][14087] Executing state file.directory for [/etc/salt/grains.d]
2019-04-23 02:57:08,100 [salt.state       :300 ][INFO    ][14087] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-04-23 02:57:08,100 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains.d] at time 02:57:08.100372 duration_in_ms=2.701
2019-04-23 02:57:08,101 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains] at time 02:57:08.101504
2019-04-23 02:57:08,102 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/grains]
2019-04-23 02:57:08,104 [salt.state       :300 ][INFO    ][14087] File /etc/salt/grains exists with proper permissions. No changes made.
2019-04-23 02:57:08,105 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains] at time 02:57:08.105115 duration_in_ms=3.612
2019-04-23 02:57:08,105 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains.d/placeholder] at time 02:57:08.105639
2019-04-23 02:57:08,105 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-04-23 02:57:08,106 [salt.state       :300 ][INFO    ][14087] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-04-23 02:57:08,106 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains.d/placeholder] at time 02:57:08.106801 duration_in_ms=1.162
2019-04-23 02:57:08,107 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains.d/sphinx] at time 02:57:08.107340
2019-04-23 02:57:08,107 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-04-23 02:57:08,108 [salt.state       :300 ][INFO    ][14087] File /etc/salt/grains.d/sphinx is in the correct state
2019-04-23 02:57:08,109 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains.d/sphinx] at time 02:57:08.109207 duration_in_ms=1.867
2019-04-23 02:57:08,111 [salt.state       :1780][INFO    ][14087] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.111697
2019-04-23 02:57:08,112 [salt.state       :1813][INFO    ][14087] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-04-23 02:57:08,112 [salt.state       :300 ][INFO    ][14087] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-04-23 02:57:08,112 [salt.state       :1951][INFO    ][14087] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.112601 duration_in_ms=0.904
2019-04-23 02:57:08,113 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains.d/dns_records] at time 02:57:08.113153
2019-04-23 02:57:08,113 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-04-23 02:57:08,114 [salt.state       :300 ][INFO    ][14087] File /etc/salt/grains.d/dns_records is in the correct state
2019-04-23 02:57:08,116 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains.d/dns_records] at time 02:57:08.114789 duration_in_ms=1.636
2019-04-23 02:57:08,117 [salt.state       :1780][INFO    ][14087] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.117160
2019-04-23 02:57:08,117 [salt.state       :1813][INFO    ][14087] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-04-23 02:57:08,117 [salt.state       :300 ][INFO    ][14087] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-04-23 02:57:08,118 [salt.state       :1951][INFO    ][14087] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.118030 duration_in_ms=0.87
2019-04-23 02:57:08,118 [salt.state       :1780][INFO    ][14087] Running state [/etc/salt/grains.d/salt] at time 02:57:08.118549
2019-04-23 02:57:08,118 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-04-23 02:57:08,119 [salt.state       :300 ][INFO    ][14087] File /etc/salt/grains.d/salt is in the correct state
2019-04-23 02:57:08,120 [salt.state       :1951][INFO    ][14087] Completed state [/etc/salt/grains.d/salt] at time 02:57:08.120152 duration_in_ms=1.603
2019-04-23 02:57:08,121 [salt.state       :1780][INFO    ][14087] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.121058
2019-04-23 02:57:08,121 [salt.state       :1813][INFO    ][14087] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-04-23 02:57:08,121 [salt.state       :300 ][INFO    ][14087] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-04-23 02:57:08,121 [salt.state       :1951][INFO    ][14087] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:57:08.121900 duration_in_ms=0.841
2019-04-23 02:57:08,124 [salt.state       :1780][INFO    ][14087] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:57:08.124612
2019-04-23 02:57:08,124 [salt.state       :1813][INFO    ][14087] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-04-23 02:57:08,125 [salt.state       :300 ][INFO    ][14087] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-04-23 02:57:08,125 [salt.state       :1951][INFO    ][14087] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:57:08.125504 duration_in_ms=0.892
2019-04-23 02:57:08,126 [salt.state       :1780][INFO    ][14087] Running state [mine.update] at time 02:57:08.126205
2019-04-23 02:57:08,126 [salt.state       :1813][INFO    ][14087] Executing state module.wait for [mine.update]
2019-04-23 02:57:08,126 [salt.state       :300 ][INFO    ][14087] No changes made for mine.update
2019-04-23 02:57:08,127 [salt.state       :1951][INFO    ][14087] Completed state [mine.update] at time 02:57:08.127877 duration_in_ms=1.672
2019-04-23 02:57:08,128 [salt.state       :1780][INFO    ][14087] Running state [ca-certificates] at time 02:57:08.128169
2019-04-23 02:57:08,128 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [ca-certificates]
2019-04-23 02:57:08,138 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:08,138 [salt.state       :1951][INFO    ][14087] Completed state [ca-certificates] at time 02:57:08.138335 duration_in_ms=10.166
2019-04-23 02:57:08,139 [salt.state       :1780][INFO    ][14087] Running state [update-ca-certificates] at time 02:57:08.139914
2019-04-23 02:57:08,140 [salt.state       :1813][INFO    ][14087] Executing state cmd.wait for [update-ca-certificates]
2019-04-23 02:57:08,140 [salt.state       :300 ][INFO    ][14087] No changes made for update-ca-certificates
2019-04-23 02:57:08,140 [salt.state       :1951][INFO    ][14087] Completed state [update-ca-certificates] at time 02:57:08.140779 duration_in_ms=0.865
2019-04-23 02:57:08,141 [salt.state       :1780][INFO    ][14087] Running state [iptables] at time 02:57:08.141060
2019-04-23 02:57:08,141 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [iptables]
2019-04-23 02:57:08,150 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:08,150 [salt.state       :1951][INFO    ][14087] Completed state [iptables] at time 02:57:08.150557 duration_in_ms=9.497
2019-04-23 02:57:08,151 [salt.state       :1780][INFO    ][14087] Running state [iptables-persistent] at time 02:57:08.151755
2019-04-23 02:57:08,152 [salt.state       :1813][INFO    ][14087] Executing state pkg.installed for [iptables-persistent]
2019-04-23 02:57:08,160 [salt.state       :300 ][INFO    ][14087] All specified packages are already installed
2019-04-23 02:57:08,161 [salt.state       :1951][INFO    ][14087] Completed state [iptables-persistent] at time 02:57:08.161195 duration_in_ms=9.439
2019-04-23 02:57:08,162 [salt.state       :1780][INFO    ][14087] Running state [iptables_modules_v4_load] at time 02:57:08.162252
2019-04-23 02:57:08,162 [salt.state       :1813][INFO    ][14087] Executing state kmod.present for [iptables_modules_v4_load]
2019-04-23 02:57:08,164 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'lsmod' in directory '/root'
2019-04-23 02:57:08,188 [salt.state       :300 ][INFO    ][14087] Kernel modules iptable_filter, ip_tables are already present
2019-04-23 02:57:08,188 [salt.state       :1951][INFO    ][14087] Completed state [iptables_modules_v4_load] at time 02:57:08.188595 duration_in_ms=26.343
2019-04-23 02:57:08,189 [salt.state       :1780][INFO    ][14087] Running state [/etc/iptables/rules.v4] at time 02:57:08.189714
2019-04-23 02:57:08,190 [salt.state       :1813][INFO    ][14087] Executing state file.managed for [/etc/iptables/rules.v4]
2019-04-23 02:57:08,291 [salt.state       :300 ][INFO    ][14087] File /etc/iptables/rules.v4 is in the correct state
2019-04-23 02:57:08,291 [salt.state       :1951][INFO    ][14087] Completed state [/etc/iptables/rules.v4] at time 02:57:08.291377 duration_in_ms=101.663
2019-04-23 02:57:08,292 [salt.state       :1780][INFO    ][14087] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:57:08.292554
2019-04-23 02:57:08,292 [salt.state       :1813][INFO    ][14087] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-04-23 02:57:08,293 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-04-23 02:57:08,313 [salt.state       :300 ][INFO    ][14087] onlyif execution failed
2019-04-23 02:57:08,314 [salt.state       :1951][INFO    ][14087] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:57:08.314103 duration_in_ms=21.548
2019-04-23 02:57:08,316 [salt.state       :1780][INFO    ][14087] Running state [netfilter-persistent] at time 02:57:08.316227
2019-04-23 02:57:08,316 [salt.state       :1813][INFO    ][14087] Executing state service.running for [netfilter-persistent]
2019-04-23 02:57:08,318 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:08,342 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-04-23 02:57:08,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-04-23 02:57:08,376 [salt.state       :300 ][INFO    ][14087] The service netfilter-persistent is already running
2019-04-23 02:57:08,376 [salt.state       :1951][INFO    ][14087] Completed state [netfilter-persistent] at time 02:57:08.376900 duration_in_ms=60.673
2019-04-23 02:57:08,377 [salt.state       :1780][INFO    ][14087] Running state [iptables_extra.remove_stale_tables] at time 02:57:08.377818
2019-04-23 02:57:08,378 [salt.state       :1813][INFO    ][14087] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-04-23 02:57:08,378 [salt.state       :300 ][INFO    ][14087] No changes made for iptables_extra.remove_stale_tables
2019-04-23 02:57:08,378 [salt.state       :1951][INFO    ][14087] Completed state [iptables_extra.remove_stale_tables] at time 02:57:08.378758 duration_in_ms=0.94
2019-04-23 02:57:08,381 [salt.state       :1780][INFO    ][14087] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:57:08.381525
2019-04-23 02:57:08,381 [salt.state       :1813][INFO    ][14087] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-04-23 02:57:08,382 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14087] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-04-23 02:57:08,394 [salt.state       :300 ][INFO    ][14087] onlyif execution failed
2019-04-23 02:57:08,394 [salt.state       :1951][INFO    ][14087] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:57:08.394284 duration_in_ms=12.759
2019-04-23 02:57:08,395 [salt.state       :1780][INFO    ][14087] Running state [/etc/iptables/rules.v6] at time 02:57:08.395458
2019-04-23 02:57:08,395 [salt.state       :1813][INFO    ][14087] Executing state file.absent for [/etc/iptables/rules.v6]
2019-04-23 02:57:08,396 [salt.state       :300 ][INFO    ][14087] File /etc/iptables/rules.v6 is not present
2019-04-23 02:57:08,396 [salt.state       :1951][INFO    ][14087] Completed state [/etc/iptables/rules.v6] at time 02:57:08.396505 duration_in_ms=1.047
2019-04-23 02:57:08,397 [salt.state       :1780][INFO    ][14087] Running state [iptables_extra.flush_all] at time 02:57:08.397228
2019-04-23 02:57:08,397 [salt.state       :1813][INFO    ][14087] Executing state module.wait for [iptables_extra.flush_all]
2019-04-23 02:57:08,397 [salt.state       :300 ][INFO    ][14087] No changes made for iptables_extra.flush_all
2019-04-23 02:57:08,398 [salt.state       :1951][INFO    ][14087] Completed state [iptables_extra.flush_all] at time 02:57:08.398061 duration_in_ms=0.834
2019-04-23 02:57:08,401 [salt.minion      :1711][INFO    ][14087] Returning information for job: 20190423025655552278
2019-04-23 02:57:09,068 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025709058208
2019-04-23 02:57:09,086 [salt.minion      :1432][INFO    ][14176] Starting a new job with PID 14176
2019-04-23 02:57:10,345 [salt.state       :915 ][INFO    ][14176] Loading fresh modules for state activity
2019-04-23 02:57:11,659 [salt.state       :1780][INFO    ][14176] Running state [maas-rack-controller] at time 02:57:11.659169
2019-04-23 02:57:11,659 [salt.state       :1813][INFO    ][14176] Executing state pkg.installed for [maas-rack-controller]
2019-04-23 02:57:11,660 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14176] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-23 02:57:11,775 [salt.state       :300 ][INFO    ][14176] All specified packages are already installed
2019-04-23 02:57:11,776 [salt.state       :1951][INFO    ][14176] Completed state [maas-rack-controller] at time 02:57:11.776289 duration_in_ms=117.119
2019-04-23 02:57:11,776 [salt.state       :1780][INFO    ][14176] Running state [ipmitool] at time 02:57:11.776669
2019-04-23 02:57:11,777 [salt.state       :1813][INFO    ][14176] Executing state pkg.installed for [ipmitool]
2019-04-23 02:57:11,785 [salt.state       :300 ][INFO    ][14176] All specified packages are already installed
2019-04-23 02:57:11,785 [salt.state       :1951][INFO    ][14176] Completed state [ipmitool] at time 02:57:11.785896 duration_in_ms=9.227
2019-04-23 02:57:11,789 [salt.state       :1780][INFO    ][14176] Running state [/etc/maas/rackd.conf] at time 02:57:11.789895
2019-04-23 02:57:11,790 [salt.state       :1813][INFO    ][14176] Executing state file.line for [/etc/maas/rackd.conf]
2019-04-23 02:57:11,791 [salt.state       :300 ][INFO    ][14176] No changes needed to be made
2019-04-23 02:57:11,791 [salt.state       :1951][INFO    ][14176] Completed state [/etc/maas/rackd.conf] at time 02:57:11.791421 duration_in_ms=1.526
2019-04-23 02:57:11,791 [salt.state       :1780][INFO    ][14176] Running state [/etc/maas/rackd.conf] at time 02:57:11.791711
2019-04-23 02:57:11,792 [salt.state       :1813][INFO    ][14176] Executing state file.managed for [/etc/maas/rackd.conf]
2019-04-23 02:57:11,792 [salt.loaded.int.states.file:2298][WARNING ][14176] 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-04-23 02:57:11,793 [salt.state       :300 ][INFO    ][14176] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-04-23 02:57:11,793 [salt.state       :1951][INFO    ][14176] Completed state [/etc/maas/rackd.conf] at time 02:57:11.793391 duration_in_ms=1.68
2019-04-23 02:57:11,794 [salt.state       :1780][INFO    ][14176] Running state [maas-rackd] at time 02:57:11.794444
2019-04-23 02:57:11,794 [salt.state       :1813][INFO    ][14176] Executing state service.running for [maas-rackd]
2019-04-23 02:57:11,795 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14176] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:11,830 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14176] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-04-23 02:57:11,850 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14176] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-04-23 02:57:11,869 [salt.state       :300 ][INFO    ][14176] The service maas-rackd is already running
2019-04-23 02:57:11,869 [salt.state       :1951][INFO    ][14176] Completed state [maas-rackd] at time 02:57:11.869718 duration_in_ms=75.274
2019-04-23 02:57:11,873 [salt.minion      :1711][INFO    ][14176] Returning information for job: 20190423025709058208
2019-04-23 02:57:12,553 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025712545108
2019-04-23 02:57:12,573 [salt.minion      :1432][INFO    ][14245] Starting a new job with PID 14245
2019-04-23 02:57:13,687 [salt.state       :915 ][INFO    ][14245] Loading fresh modules for state activity
2019-04-23 02:57:15,035 [salt.state       :1780][INFO    ][14245] Running state [maas-region-controller] at time 02:57:15.035828
2019-04-23 02:57:15,036 [salt.state       :1813][INFO    ][14245] Executing state pkg.installed for [maas-region-controller]
2019-04-23 02:57:15,037 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-23 02:57:15,148 [salt.state       :300 ][INFO    ][14245] All specified packages are already installed
2019-04-23 02:57:15,149 [salt.state       :1951][INFO    ][14245] Completed state [maas-region-controller] at time 02:57:15.149034 duration_in_ms=113.207
2019-04-23 02:57:15,149 [salt.state       :1780][INFO    ][14245] Running state [python-oauth] at time 02:57:15.149409
2019-04-23 02:57:15,149 [salt.state       :1813][INFO    ][14245] Executing state pkg.installed for [python-oauth]
2019-04-23 02:57:15,160 [salt.state       :300 ][INFO    ][14245] All specified packages are already installed
2019-04-23 02:57:15,160 [salt.state       :1951][INFO    ][14245] Completed state [python-oauth] at time 02:57:15.160299 duration_in_ms=10.89
2019-04-23 02:57:15,163 [salt.state       :1780][INFO    ][14245] Running state [/etc/maas/regiond.conf] at time 02:57:15.163924
2019-04-23 02:57:15,164 [salt.state       :1813][INFO    ][14245] Executing state file.replace for [/etc/maas/regiond.conf]
2019-04-23 02:57:15,169 [salt.state       :300 ][INFO    ][14245] No changes needed to be made
2019-04-23 02:57:15,169 [salt.state       :1951][INFO    ][14245] Completed state [/etc/maas/regiond.conf] at time 02:57:15.169378 duration_in_ms=5.453
2019-04-23 02:57:15,169 [salt.state       :1780][INFO    ][14245] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:57:15.169898
2019-04-23 02:57:15,170 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-04-23 02:57:15,231 [salt.state       :300 ][INFO    ][14245] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-04-23 02:57:15,232 [salt.state       :1951][INFO    ][14245] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:57:15.231994 duration_in_ms=62.096
2019-04-23 02:57:15,232 [salt.state       :1780][INFO    ][14245] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:57:15.232533
2019-04-23 02:57:15,232 [salt.state       :1813][INFO    ][14245] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-23 02:57:15,237 [salt.state       :300 ][INFO    ][14245] No changes needed to be made
2019-04-23 02:57:15,238 [salt.state       :1951][INFO    ][14245] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:57:15.238003 duration_in_ms=5.47
2019-04-23 02:57:15,238 [salt.state       :1780][INFO    ][14245] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:57:15.238522
2019-04-23 02:57:15,238 [salt.state       :1813][INFO    ][14245] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-23 02:57:15,244 [salt.state       :300 ][INFO    ][14245] No changes needed to be made
2019-04-23 02:57:15,244 [salt.state       :1951][INFO    ][14245] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:57:15.244611 duration_in_ms=6.089
2019-04-23 02:57:15,245 [salt.state       :1780][INFO    ][14245] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:57:15.245129
2019-04-23 02:57:15,245 [salt.state       :1813][INFO    ][14245] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-04-23 02:57:15,270 [salt.state       :300 ][INFO    ][14245] No changes needed to be made
2019-04-23 02:57:15,270 [salt.state       :1951][INFO    ][14245] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:57:15.270457 duration_in_ms=25.328
2019-04-23 02:57:15,271 [salt.state       :1780][INFO    ][14245] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:57:15.270992
2019-04-23 02:57:15,271 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-04-23 02:57:15,285 [salt.state       :300 ][INFO    ][14245] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-04-23 02:57:15,286 [salt.state       :1951][INFO    ][14245] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:57:15.285906 duration_in_ms=14.913
2019-04-23 02:57:15,288 [salt.state       :1780][INFO    ][14245] Running state [a2enmod headers] at time 02:57:15.288153
2019-04-23 02:57:15,288 [salt.state       :1813][INFO    ][14245] Executing state cmd.run for [a2enmod headers]
2019-04-23 02:57:15,289 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command 'a2enmod headers' in directory '/root'
2019-04-23 02:57:15,358 [salt.state       :300 ][INFO    ][14245] {'pid': 14264, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-04-23 02:57:15,358 [salt.state       :1951][INFO    ][14245] Completed state [a2enmod headers] at time 02:57:15.358735 duration_in_ms=70.582
2019-04-23 02:57:15,359 [salt.state       :1780][INFO    ][14245] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:57:15.359237
2019-04-23 02:57:15,359 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-04-23 02:57:15,382 [salt.state       :300 ][INFO    ][14245] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-04-23 02:57:15,383 [salt.state       :1951][INFO    ][14245] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:57:15.383118 duration_in_ms=23.881
2019-04-23 02:57:15,384 [salt.state       :1780][INFO    ][14245] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:57:15.384264
2019-04-23 02:57:15,384 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-04-23 02:57:15,441 [salt.state       :300 ][INFO    ][14245] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-04-23 02:57:15,441 [salt.state       :1951][INFO    ][14245] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:57:15.441596 duration_in_ms=57.333
2019-04-23 02:57:15,442 [salt.state       :1780][INFO    ][14245] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:57:15.442163
2019-04-23 02:57:15,442 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-04-23 02:57:15,509 [salt.state       :300 ][INFO    ][14245] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-04-23 02:57:15,509 [salt.state       :1951][INFO    ][14245] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:57:15.509828 duration_in_ms=67.665
2019-04-23 02:57:15,510 [salt.state       :1780][INFO    ][14245] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:57:15.510397
2019-04-23 02:57:15,510 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-04-23 02:57:15,579 [salt.state       :300 ][INFO    ][14245] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-04-23 02:57:15,580 [salt.state       :1951][INFO    ][14245] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:57:15.580152 duration_in_ms=69.755
2019-04-23 02:57:15,580 [salt.state       :1780][INFO    ][14245] Running state [/root/.pgpass] at time 02:57:15.580449
2019-04-23 02:57:15,580 [salt.state       :1813][INFO    ][14245] Executing state file.managed for [/root/.pgpass]
2019-04-23 02:57:15,630 [salt.state       :300 ][INFO    ][14245] File /root/.pgpass is in the correct state
2019-04-23 02:57:15,631 [salt.state       :1951][INFO    ][14245] Completed state [/root/.pgpass] at time 02:57:15.631169 duration_in_ms=50.72
2019-04-23 02:57:15,637 [salt.state       :1780][INFO    ][14245] Running state [maas-region syncdb --noinput] at time 02:57:15.637805
2019-04-23 02:57:15,638 [salt.state       :1813][INFO    ][14245] Executing state cmd.run for [maas-region syncdb --noinput]
2019-04-23 02:57:15,640 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-04-23 02:57:18,482 [salt.state       :300 ][INFO    ][14245] {'pid': 14278, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, auth, metadataserver, sites, maasserver, piston3, contenttypes\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-04-23 02:57:18,482 [salt.state       :1951][INFO    ][14245] Completed state [maas-region syncdb --noinput] at time 02:57:18.482479 duration_in_ms=2844.673
2019-04-23 02:57:18,482 [salt.state       :2022][WARNING ][14245] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-23 02:57:18,485 [salt.state       :1780][INFO    ][14245] Running state [maas-regiond] at time 02:57:18.485654
2019-04-23 02:57:18,486 [salt.state       :1813][INFO    ][14245] Executing state service.running for [maas-regiond]
2019-04-23 02:57:18,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:18,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-04-23 02:57:18,526 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-04-23 02:57:18,539 [salt.state       :300 ][INFO    ][14245] The service maas-regiond is already running
2019-04-23 02:57:18,540 [salt.state       :1951][INFO    ][14245] Completed state [maas-regiond] at time 02:57:18.540227 duration_in_ms=54.573
2019-04-23 02:57:18,541 [salt.state       :1780][INFO    ][14245] Running state [bind9] at time 02:57:18.541922
2019-04-23 02:57:18,542 [salt.state       :1813][INFO    ][14245] Executing state service.running for [bind9]
2019-04-23 02:57:18,545 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:18,558 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-04-23 02:57:18,569 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-04-23 02:57:18,581 [salt.state       :300 ][INFO    ][14245] The service bind9 is already running
2019-04-23 02:57:18,582 [salt.state       :1951][INFO    ][14245] Completed state [bind9] at time 02:57:18.582232 duration_in_ms=40.31
2019-04-23 02:57:18,583 [salt.state       :1780][INFO    ][14245] Running state [apache2] at time 02:57:18.583931
2019-04-23 02:57:18,584 [salt.state       :1813][INFO    ][14245] Executing state service.running for [apache2]
2019-04-23 02:57:18,585 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-04-23 02:57:18,597 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-04-23 02:57:18,610 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-04-23 02:57:18,625 [salt.state       :300 ][INFO    ][14245] The service apache2 is already running
2019-04-23 02:57:18,625 [salt.state       :1951][INFO    ][14245] Completed state [apache2] at time 02:57:18.625715 duration_in_ms=41.784
2019-04-23 02:57:18,629 [salt.state       :1780][INFO    ][14245] Running state [maasng.wait_for_http_code] at time 02:57:18.629474
2019-04-23 02:57:18,629 [salt.state       :1813][INFO    ][14245] Executing state module.run for [maasng.wait_for_http_code]
2019-04-23 02:57:18,630 [salt.utils.decorators:613 ][WARNING ][14245] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:57:18,635 [salt.state       :300 ][INFO    ][14245] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-04-23 02:57:18,635 [salt.state       :1951][INFO    ][14245] Completed state [maasng.wait_for_http_code] at time 02:57:18.635521 duration_in_ms=6.047
2019-04-23 02:57:18,636 [salt.state       :1780][INFO    ][14245] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:57:18.636306
2019-04-23 02:57:18,636 [salt.state       :1813][INFO    ][14245] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-04-23 02:57:18,637 [salt.state       :300 ][INFO    ][14245] /var/lib/maas/.setup_admin exists
2019-04-23 02:57:18,637 [salt.state       :1951][INFO    ][14245] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:57:18.637557 duration_in_ms=1.251
2019-04-23 02:57:18,638 [salt.state       :1780][INFO    ][14245] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:18.638264
2019-04-23 02:57:18,638 [salt.state       :1813][INFO    ][14245] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:57:18,641 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14245] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:57:20,564 [salt.state       :300 ][INFO    ][14245] {'pid': 14309, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:57:20,564 [salt.state       :1951][INFO    ][14245] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:20.564736 duration_in_ms=1926.471
2019-04-23 02:57:20,570 [salt.state       :1780][INFO    ][14245] Running state [maas_region_boot_source_resources_mirror] at time 02:57:20.570432
2019-04-23 02:57:20,570 [salt.state       :1813][INFO    ][14245] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-04-23 02:57:20,633 [salt.state       :300 ][INFO    ][14245] {'changes': {}}
2019-04-23 02:57:20,634 [salt.state       :1951][INFO    ][14245] Completed state [maas_region_boot_source_resources_mirror] at time 02:57:20.634008 duration_in_ms=63.576
2019-04-23 02:57:20,634 [salt.state       :1780][INFO    ][14245] Running state [maasng.boot_resources_import] at time 02:57:20.634696
2019-04-23 02:57:20,635 [salt.state       :1813][INFO    ][14245] Executing state module.run for [maasng.boot_resources_import]
2019-04-23 02:57:20,635 [salt.utils.decorators:613 ][WARNING ][14245] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:57:20,701 [salt.loaded.ext.module.maasng:1600][INFO    ][14245] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-04-23 02:57:25,748 [salt.loaded.ext.module.maasng:1600][INFO    ][14245] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-04-23 02:57:27,640 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025727627288
2019-04-23 02:57:27,657 [salt.minion      :1432][INFO    ][14465] Starting a new job with PID 14465
2019-04-23 02:57:27,689 [salt.minion      :1711][INFO    ][14465] Returning information for job: 20190423025727627288
2019-04-23 02:57:30,841 [salt.state       :300 ][INFO    ][14245] {'ret': True}
2019-04-23 02:57:30,841 [salt.state       :1951][INFO    ][14245] Completed state [maasng.boot_resources_import] at time 02:57:30.841778 duration_in_ms=10207.081
2019-04-23 02:57:30,844 [salt.state       :1780][INFO    ][14245] Running state [maas_region_boot_sources_selection_xenial] at time 02:57:30.842842
2019-04-23 02:57:30,844 [salt.state       :1813][INFO    ][14245] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-04-23 02:57:31,005 [salt.state       :300 ][INFO    ][14245] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-04-23 02:57:31,005 [salt.state       :1951][INFO    ][14245] Completed state [maas_region_boot_sources_selection_xenial] at time 02:57:31.005438 duration_in_ms=162.597
2019-04-23 02:57:31,006 [salt.state       :1780][INFO    ][14245] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 02:57:31.006909
2019-04-23 02:57:31,007 [salt.state       :1813][INFO    ][14245] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-04-23 02:57:31,007 [salt.utils.decorators:613 ][WARNING ][14245] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:57:31,008 [salt.loaded.ext.module.maasng:1771][INFO    ][14245] boot-sources sync initiated for ALL Rack's
2019-04-23 02:57:31,979 [salt.state       :300 ][INFO    ][14245] {'ret': True}
2019-04-23 02:57:31,980 [salt.state       :1951][INFO    ][14245] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 02:57:31.979951 duration_in_ms=973.041
2019-04-23 02:57:31,982 [salt.state       :1780][INFO    ][14245] Running state [maas.process_maas_config] at time 02:57:31.981972
2019-04-23 02:57:31,982 [salt.state       :1813][INFO    ][14245] Executing state module.run for [maas.process_maas_config]
2019-04-23 02:57:31,984 [salt.utils.decorators:613 ][WARNING ][14245] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:57:31,985 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=enable_http_proxy value=True
2019-04-23 02:57:32,036 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=upstream_dns value=8.8.8.8
2019-04-23 02:57:32,089 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=commissioning_distro_series value=xenial
2019-04-23 02:57:32,145 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=default_osystem value=ubuntu
2019-04-23 02:57:32,204 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=active_discovery_interval value=600
2019-04-23 02:57:32,256 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=dnssec_validation value=no
2019-04-23 02:57:33,383 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=maas_name value=mas01
2019-04-23 02:57:33,446 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=network_discovery value=enabled
2019-04-23 02:57:33,540 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=enable_third_party_drivers value=True
2019-04-23 02:57:33,608 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=default_storage_layout value=lvm
2019-04-23 02:57:33,666 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=ntp_external_only value=True
2019-04-23 02:57:33,713 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=disk_erase_with_secure_erase value=False
2019-04-23 02:57:33,766 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=default_distro_series value=xenial
2019-04-23 02:57:33,821 [salt.loaded.ext.module.maas:92  ][INFO    ][14245] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-04-23 02:57:33,926 [salt.state       :300 ][INFO    ][14245] {'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-04-23 02:57:33,928 [salt.state       :1951][INFO    ][14245] Completed state [maas.process_maas_config] at time 02:57:33.928131 duration_in_ms=1946.158
2019-04-23 02:57:33,928 [salt.state       :1780][INFO    ][14245] Running state [pxe_admin] at time 02:57:33.928864
2019-04-23 02:57:33,929 [salt.state       :1813][INFO    ][14245] Executing state maasng.fabric_present for [pxe_admin]
2019-04-23 02:57:33,978 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:34,031 [salt.loaded.ext.module.maasng:1008][WARNING ][14245] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-04-23 02:57:34,032 [salt.loaded.ext.module.maasng:1011][WARNING ][14245] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-04-23 02:57:34,113 [salt.state       :300 ][INFO    ][14245] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-04-23 02:57:34,113 [salt.state       :1951][INFO    ][14245] Completed state [pxe_admin] at time 02:57:34.113871 duration_in_ms=185.006
2019-04-23 02:57:34,114 [salt.state       :1780][INFO    ][14245] Running state [vlan 0] at time 02:57:34.114276
2019-04-23 02:57:34,114 [salt.state       :1813][INFO    ][14245] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-23 02:57:34,174 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 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'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'name': u'untagged'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ty8cwb', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:34,281 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], 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': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-23 02:57:34,510 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 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'fabric': u'fabric-2', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {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'ty8cwb', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:34,588 [salt.state       :300 ][INFO    ][14245] {'new': 'Vlan untagged was updated'}
2019-04-23 02:57:34,589 [salt.state       :1951][INFO    ][14245] Completed state [vlan 0] at time 02:57:34.588938 duration_in_ms=474.662
2019-04-23 02:57:34,590 [salt.state       :1780][INFO    ][14245] Running state [192.168.11.0/24] at time 02:57:34.590440
2019-04-23 02:57:34,591 [salt.state       :1813][INFO    ][14245] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-04-23 02:57:34,773 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:34,773 [salt.loaded.ext.module.maasng:1235][WARNING ][14245] Ignoring parameter vlan:0
2019-04-23 02:57:34,854 [salt.state       :300 ][INFO    ][14245] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-04-23 02:57:34,855 [salt.state       :1951][INFO    ][14245] Completed state [192.168.11.0/24] at time 02:57:34.855810 duration_in_ms=265.37
2019-04-23 02:57:34,856 [salt.state       :1780][INFO    ][14245] Running state [maas_create_iprange_1] at time 02:57:34.856796
2019-04-23 02:57:34,857 [salt.state       :1813][INFO    ][14245] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-04-23 02:57:34,906 [salt.state       :300 ][INFO    ][14245] Iprange maas_create_iprange_1 already exist.
2019-04-23 02:57:34,907 [salt.state       :1951][INFO    ][14245] Completed state [maas_create_iprange_1] at time 02:57:34.907176 duration_in_ms=50.38
2019-04-23 02:57:34,907 [salt.state       :1780][INFO    ][14245] Running state [vlan 0] at time 02:57:34.907509
2019-04-23 02:57:34,907 [salt.state       :1813][INFO    ][14245] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-23 02:57:34,950 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:35,042 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], 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'ty8cwb', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-23 02:57:35,255 [salt.loaded.ext.module.maasng:945 ][INFO    ][14245] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 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'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'name': u'untagged'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 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'primary_rack': u'ty8cwb', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-04-23 02:57:35,348 [salt.state       :300 ][INFO    ][14245] {'new': 'Vlan untagged was updated'}
2019-04-23 02:57:35,348 [salt.state       :1951][INFO    ][14245] Completed state [vlan 0] at time 02:57:35.348318 duration_in_ms=440.808
2019-04-23 02:57:35,349 [salt.state       :1780][INFO    ][14245] Running state [opnfv] at time 02:57:35.349100
2019-04-23 02:57:35,349 [salt.state       :1813][INFO    ][14245] Executing state maasng.sshkey_present for [opnfv]
2019-04-23 02:57:35,401 [salt.loaded.ext.module.maasng:1903][INFO    ][14245] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-04-23 02:57:35,401 [salt.state       :300 ][INFO    ][14245] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-04-23 02:57:35,402 [salt.state       :1951][INFO    ][14245] Completed state [opnfv] at time 02:57:35.402187 duration_in_ms=53.087
2019-04-23 02:57:35,409 [salt.minion      :1711][INFO    ][14245] Returning information for job: 20190423025712545108
2019-04-23 02:57:36,166 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025736157303
2019-04-23 02:57:36,178 [salt.minion      :1432][INFO    ][14695] Starting a new job with PID 14695
2019-04-23 02:57:43,877 [salt.state       :915 ][INFO    ][14695] Loading fresh modules for state activity
2019-04-23 02:57:43,975 [salt.state       :1780][INFO    ][14695] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:43.975658
2019-04-23 02:57:43,976 [salt.state       :1813][INFO    ][14695] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:57:43,977 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14695] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:57:45,914 [salt.state       :300 ][INFO    ][14695] {'pid': 14724, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:57:45,916 [salt.state       :1951][INFO    ][14695] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:57:45.915810 duration_in_ms=1940.152
2019-04-23 02:57:45,919 [salt.state       :1780][INFO    ][14695] Running state [maas.process_machines] at time 02:57:45.919222
2019-04-23 02:57:45,919 [salt.state       :1813][INFO    ][14695] Executing state module.run for [maas.process_machines]
2019-04-23 02:57:45,920 [salt.utils.decorators:613 ][WARNING ][14695] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:57:46,472 [salt.loaded.ext.module.maas:412 ][WARNING ][14695] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:57:46,473 [salt.loaded.ext.module.maas:92  ][INFO    ][14695] 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=myakby architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-23 02:57:47,598 [salt.loaded.ext.module.maas:412 ][WARNING ][14695] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:57:47,600 [salt.loaded.ext.module.maas:92  ][INFO    ][14695] 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=pcbnx6 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-23 02:57:48,709 [salt.loaded.ext.module.maas:412 ][WARNING ][14695] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:57:48,709 [salt.loaded.ext.module.maas:92  ][INFO    ][14695] 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=qb7t74 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-23 02:57:49,804 [salt.loaded.ext.module.maas:412 ][WARNING ][14695] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:57:49,804 [salt.loaded.ext.module.maas:92  ][INFO    ][14695] 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=syssym architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-23 02:57:50,911 [salt.loaded.ext.module.maas:412 ][WARNING ][14695] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-23 02:57:50,912 [salt.loaded.ext.module.maas:92  ][INFO    ][14695] 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=4ehnhb architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-23 02:57:51,272 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025751259219
2019-04-23 02:57:51,296 [salt.minion      :1432][INFO    ][14924] Starting a new job with PID 14924
2019-04-23 02:57:51,337 [salt.minion      :1711][INFO    ][14924] Returning information for job: 20190423025751259219
2019-04-23 02:57:52,014 [salt.state       :300 ][INFO    ][14695] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-04-23 02:57:52,015 [salt.state       :1951][INFO    ][14695] Completed state [maas.process_machines] at time 02:57:52.014974 duration_in_ms=6095.751
2019-04-23 02:57:52,018 [salt.minion      :1711][INFO    ][14695] Returning information for job: 20190423025736157303
2019-04-23 02:58:25,785 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025825777958
2019-04-23 02:58:25,800 [salt.minion      :1432][INFO    ][15015] Starting a new job with PID 15015
2019-04-23 02:58:33,444 [salt.state       :915 ][INFO    ][15015] Loading fresh modules for state activity
2019-04-23 02:58:33,549 [salt.state       :1780][INFO    ][15015] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:33.549650
2019-04-23 02:58:33,550 [salt.state       :1813][INFO    ][15015] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:58:33,551 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15015] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:58:35,483 [salt.state       :300 ][INFO    ][15015] {'pid': 15027, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:58:35,484 [salt.state       :1951][INFO    ][15015] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:35.484700 duration_in_ms=1935.05
2019-04-23 02:58:35,488 [salt.state       :1780][INFO    ][15015] Running state [maas.wait_for_machine_status] at time 02:58:35.488442
2019-04-23 02:58:35,488 [salt.state       :1813][INFO    ][15015] Executing state module.run for [maas.wait_for_machine_status]
2019-04-23 02:58:35,489 [salt.utils.decorators:613 ][WARNING ][15015] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:58:38,285 [salt.state       :300 ][INFO    ][15015] {'ret': True}
2019-04-23 02:58:38,285 [salt.state       :1951][INFO    ][15015] Completed state [maas.wait_for_machine_status] at time 02:58:38.285812 duration_in_ms=2797.37
2019-04-23 02:58:38,288 [salt.minion      :1711][INFO    ][15015] Returning information for job: 20190423025825777958
2019-04-23 02:58:38,995 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025838947512
2019-04-23 02:58:39,012 [salt.minion      :1432][INFO    ][15042] Starting a new job with PID 15042
2019-04-23 02:58:40,180 [salt.state       :915 ][INFO    ][15042] Loading fresh modules for state activity
2019-04-23 02:58:40,326 [salt.state       :1780][INFO    ][15042] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:40.326198
2019-04-23 02:58:40,326 [salt.state       :1813][INFO    ][15042] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:58:40,328 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15042] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:58:42,272 [salt.state       :300 ][INFO    ][15042] {'pid': 15053, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:58:42,273 [salt.state       :1951][INFO    ][15042] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:42.273757 duration_in_ms=1947.557
2019-04-23 02:58:42,281 [salt.state       :1780][INFO    ][15042] Running state [maas_machines_storage_cmp002_lvm] at time 02:58:42.281208
2019-04-23 02:58:42,281 [salt.state       :1813][INFO    ][15042] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-23 02:58:42,811 [salt.state       :300 ][INFO    ][15042] Machine cmp002 is not in Ready state.
2019-04-23 02:58:42,811 [salt.state       :1951][INFO    ][15042] Completed state [maas_machines_storage_cmp002_lvm] at time 02:58:42.811707 duration_in_ms=530.499
2019-04-23 02:58:42,812 [salt.state       :1780][INFO    ][15042] Running state [maas_machines_storage_cmp001_lvm] at time 02:58:42.812122
2019-04-23 02:58:42,812 [salt.state       :1813][INFO    ][15042] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-23 02:58:43,340 [salt.state       :300 ][INFO    ][15042] Machine cmp001 is not in Ready state.
2019-04-23 02:58:43,340 [salt.state       :1951][INFO    ][15042] Completed state [maas_machines_storage_cmp001_lvm] at time 02:58:43.340590 duration_in_ms=528.468
2019-04-23 02:58:43,344 [salt.minion      :1711][INFO    ][15042] Returning information for job: 20190423025838947512
2019-04-23 02:58:44,013 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025844002216
2019-04-23 02:58:44,034 [salt.minion      :1432][INFO    ][15063] Starting a new job with PID 15063
2019-04-23 02:58:45,190 [salt.state       :915 ][INFO    ][15063] Loading fresh modules for state activity
2019-04-23 02:58:45,281 [salt.state       :1780][INFO    ][15063] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:45.281878
2019-04-23 02:58:45,282 [salt.state       :1813][INFO    ][15063] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:58:45,284 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15063] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:58:47,091 [salt.state       :300 ][INFO    ][15063] {'pid': 15070, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:58:47,092 [salt.state       :1951][INFO    ][15063] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:47.092797 duration_in_ms=1810.918
2019-04-23 02:58:47,096 [salt.state       :1780][INFO    ][15063] Running state [maas.deploy_machines] at time 02:58:47.096655
2019-04-23 02:58:47,097 [salt.state       :1813][INFO    ][15063] Executing state module.run for [maas.deploy_machines]
2019-04-23 02:58:47,105 [salt.utils.decorators:613 ][WARNING ][15063] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:58:47,762 [salt.loaded.ext.module.maas:684 ][INFO    ][15063] deploymachines hwe_kernel=ga-16.04 system_id=4ehnhb distro_series=xenial
2019-04-23 02:58:49,820 [salt.state       :300 ][INFO    ][15063] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {}, 'success': ['kvm02']}}
2019-04-23 02:58:49,820 [salt.state       :1951][INFO    ][15063] Completed state [maas.deploy_machines] at time 02:58:49.820798 duration_in_ms=2724.143
2019-04-23 02:58:49,823 [salt.minion      :1711][INFO    ][15063] Returning information for job: 20190423025844002216
2019-04-23 02:58:50,501 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command state.apply with jid 20190423025850489563
2019-04-23 02:58:50,521 [salt.minion      :1432][INFO    ][15131] Starting a new job with PID 15131
2019-04-23 02:58:58,241 [salt.state       :915 ][INFO    ][15131] Loading fresh modules for state activity
2019-04-23 02:58:58,341 [salt.state       :1780][INFO    ][15131] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:58:58.341349
2019-04-23 02:58:58,341 [salt.state       :1813][INFO    ][15131] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-23 02:58:58,344 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15131] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-23 02:59:00,304 [salt.state       :300 ][INFO    ][15131] {'pid': 15142, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-23 02:59:00,305 [salt.state       :1951][INFO    ][15131] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:59:00.304870 duration_in_ms=1963.52
2019-04-23 02:59:00,313 [salt.state       :1780][INFO    ][15131] Running state [maas.wait_for_machine_status] at time 02:59:00.312978
2019-04-23 02:59:00,313 [salt.state       :1813][INFO    ][15131] Executing state module.run for [maas.wait_for_machine_status]
2019-04-23 02:59:00,314 [salt.utils.decorators:613 ][WARNING ][15131] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-23 02:59:03,318 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2247.01102519s left)
2019-04-23 02:59:05,529 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025905520418
2019-04-23 02:59:05,555 [salt.minion      :1432][INFO    ][15173] Starting a new job with PID 15173
2019-04-23 02:59:05,587 [salt.minion      :1711][INFO    ][15173] Returning information for job: 20190423025905520418
2019-04-23 02:59:35,731 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423025935722824
2019-04-23 02:59:35,748 [salt.minion      :1432][INFO    ][15259] Starting a new job with PID 15259
2019-04-23 02:59:35,784 [salt.minion      :1711][INFO    ][15259] Returning information for job: 20190423025935722824
2019-04-23 02:59:36,064 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2214.26483202s left)
2019-04-23 03:00:05,947 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030005933561
2019-04-23 03:00:05,972 [salt.minion      :1432][INFO    ][15282] Starting a new job with PID 15282
2019-04-23 03:00:06,006 [salt.minion      :1711][INFO    ][15282] Returning information for job: 20190423030005933561
2019-04-23 03:00:08,717 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2181.61261606s left)
2019-04-23 03:00:36,006 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030035998378
2019-04-23 03:00:36,020 [salt.minion      :1432][INFO    ][15359] Starting a new job with PID 15359
2019-04-23 03:00:36,049 [salt.minion      :1711][INFO    ][15359] Returning information for job: 20190423030035998378
2019-04-23 03:00:41,638 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2148.69151306s left)
2019-04-23 03:01:06,199 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030106190533
2019-04-23 03:01:06,223 [salt.minion      :1432][INFO    ][15390] Starting a new job with PID 15390
2019-04-23 03:01:06,256 [salt.minion      :1711][INFO    ][15390] Returning information for job: 20190423030106190533
2019-04-23 03:01:14,317 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2116.01280808s left)
2019-04-23 03:01:36,410 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030136393787
2019-04-23 03:01:36,431 [salt.minion      :1432][INFO    ][15463] Starting a new job with PID 15463
2019-04-23 03:01:36,466 [salt.minion      :1711][INFO    ][15463] Returning information for job: 20190423030136393787
2019-04-23 03:01:47,000 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2083.32947707s left)
2019-04-23 03:02:06,485 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030206468477
2019-04-23 03:02:06,504 [salt.minion      :1432][INFO    ][15490] Starting a new job with PID 15490
2019-04-23 03:02:06,535 [salt.minion      :1711][INFO    ][15490] Returning information for job: 20190423030206468477
2019-04-23 03:02:19,655 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2050.67448711s left)
2019-04-23 03:02:36,577 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030236566437
2019-04-23 03:02:36,592 [salt.minion      :1432][INFO    ][15565] Starting a new job with PID 15565
2019-04-23 03:02:36,622 [salt.minion      :1711][INFO    ][15565] Returning information for job: 20190423030236566437
2019-04-23 03:02:52,402 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2017.92697001s left)
2019-04-23 03:03:06,637 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030306629636
2019-04-23 03:03:06,650 [salt.minion      :1432][INFO    ][15617] Starting a new job with PID 15617
2019-04-23 03:03:06,680 [salt.minion      :1711][INFO    ][15617] Returning information for job: 20190423030306629636
2019-04-23 03:03:25,278 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1985.05180502s left)
2019-04-23 03:03:36,726 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030336714246
2019-04-23 03:03:36,749 [salt.minion      :1432][INFO    ][15723] Starting a new job with PID 15723
2019-04-23 03:03:36,781 [salt.minion      :1711][INFO    ][15723] Returning information for job: 20190423030336714246
2019-04-23 03:03:58,104 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1952.22516418s left)
2019-04-23 03:04:06,828 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030406815710
2019-04-23 03:04:06,848 [salt.minion      :1432][INFO    ][15755] Starting a new job with PID 15755
2019-04-23 03:04:06,878 [salt.minion      :1711][INFO    ][15755] Returning information for job: 20190423030406815710
2019-04-23 03:04:30,881 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1919.44815207s left)
2019-04-23 03:04:36,956 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030436945824
2019-04-23 03:04:36,979 [salt.minion      :1432][INFO    ][15959] Starting a new job with PID 15959
2019-04-23 03:04:37,010 [salt.minion      :1711][INFO    ][15959] Returning information for job: 20190423030436945824
2019-04-23 03:05:03,552 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1886.77761006s left)
2019-04-23 03:05:07,177 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030507164820
2019-04-23 03:05:07,199 [salt.minion      :1432][INFO    ][15988] Starting a new job with PID 15988
2019-04-23 03:05:07,231 [salt.minion      :1711][INFO    ][15988] Returning information for job: 20190423030507164820
2019-04-23 03:05:36,550 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1853.77898312s left)
2019-04-23 03:05:37,398 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030537387213
2019-04-23 03:05:37,423 [salt.minion      :1432][INFO    ][16100] Starting a new job with PID 16100
2019-04-23 03:05:37,454 [salt.minion      :1711][INFO    ][16100] Returning information for job: 20190423030537387213
2019-04-23 03:06:07,511 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030607502415
2019-04-23 03:06:07,530 [salt.minion      :1432][INFO    ][16128] Starting a new job with PID 16128
2019-04-23 03:06:07,561 [salt.minion      :1711][INFO    ][16128] Returning information for job: 20190423030607502415
2019-04-23 03:06:09,437 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1820.892699s left)
2019-04-23 03:06:37,553 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030637537693
2019-04-23 03:06:37,571 [salt.minion      :1432][INFO    ][16281] Starting a new job with PID 16281
2019-04-23 03:06:37,605 [salt.minion      :1711][INFO    ][16281] Returning information for job: 20190423030637537693
2019-04-23 03:06:42,342 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1787.98734617s left)
2019-04-23 03:07:07,678 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030707669801
2019-04-23 03:07:07,699 [salt.minion      :1432][INFO    ][16313] Starting a new job with PID 16313
2019-04-23 03:07:07,727 [salt.minion      :1711][INFO    ][16313] Returning information for job: 20190423030707669801
2019-04-23 03:07:15,125 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1755.20428014s left)
2019-04-23 03:07:37,832 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030737821091
2019-04-23 03:07:37,857 [salt.minion      :1432][INFO    ][16471] Starting a new job with PID 16471
2019-04-23 03:07:37,893 [salt.minion      :1711][INFO    ][16471] Returning information for job: 20190423030737821091
2019-04-23 03:07:47,887 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1722.44232512s left)
2019-04-23 03:08:07,988 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030807978945
2019-04-23 03:08:08,010 [salt.minion      :1432][INFO    ][16500] Starting a new job with PID 16500
2019-04-23 03:08:08,041 [salt.minion      :1711][INFO    ][16500] Returning information for job: 20190423030807978945
2019-04-23 03:08:20,687 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1689.64206409s left)
2019-04-23 03:08:38,130 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030838116592
2019-04-23 03:08:38,154 [salt.minion      :1432][INFO    ][16603] Starting a new job with PID 16603
2019-04-23 03:08:38,185 [salt.minion      :1711][INFO    ][16603] Returning information for job: 20190423030838116592
2019-04-23 03:08:53,661 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1656.66794419s left)
2019-04-23 03:09:08,305 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030908292530
2019-04-23 03:09:08,327 [salt.minion      :1432][INFO    ][16639] Starting a new job with PID 16639
2019-04-23 03:09:08,359 [salt.minion      :1711][INFO    ][16639] Returning information for job: 20190423030908292530
2019-04-23 03:09:08,654 [salt.utils.schedule:1377][INFO    ][3338] Running scheduled job: __mine_interval
2019-04-23 03:09:26,465 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1623.86475801s left)
2019-04-23 03:09:38,445 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423030938433297
2019-04-23 03:09:38,468 [salt.minion      :1432][INFO    ][16881] Starting a new job with PID 16881
2019-04-23 03:09:38,499 [salt.minion      :1711][INFO    ][16881] Returning information for job: 20190423030938433297
2019-04-23 03:09:59,297 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1591.0327642s left)
2019-04-23 03:10:08,616 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423031008600834
2019-04-23 03:10:08,638 [salt.minion      :1432][INFO    ][16913] Starting a new job with PID 16913
2019-04-23 03:10:08,669 [salt.minion      :1711][INFO    ][16913] Returning information for job: 20190423031008600834
2019-04-23 03:10:32,237 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1558.09206915s left)
2019-04-23 03:10:38,776 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423031038764260
2019-04-23 03:10:38,795 [salt.minion      :1432][INFO    ][16985] Starting a new job with PID 16985
2019-04-23 03:10:38,827 [salt.minion      :1711][INFO    ][16985] Returning information for job: 20190423031038764260
2019-04-23 03:11:04,997 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1525.33218718s left)
2019-04-23 03:11:08,831 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423031108816583
2019-04-23 03:11:08,854 [salt.minion      :1432][INFO    ][17016] Starting a new job with PID 17016
2019-04-23 03:11:08,886 [salt.minion      :1711][INFO    ][17016] Returning information for job: 20190423031108816583
2019-04-23 03:11:37,853 [salt.loaded.ext.module.maas:1023][INFO    ][15131] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1492.47646904s left)
2019-04-23 03:11:39,007 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423031138993020
2019-04-23 03:11:39,031 [salt.minion      :1432][INFO    ][17113] Starting a new job with PID 17113
2019-04-23 03:11:39,059 [salt.minion      :1711][INFO    ][17113] Returning information for job: 20190423031138993020
2019-04-23 03:12:09,080 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command saltutil.find_job with jid 20190423031209070263
2019-04-23 03:12:09,095 [salt.minion      :1432][INFO    ][17167] Starting a new job with PID 17167
2019-04-23 03:12:09,125 [salt.minion      :1711][INFO    ][17167] Returning information for job: 20190423031209070263
2019-04-23 03:12:11,358 [salt.state       :300 ][INFO    ][15131] {'ret': True}
2019-04-23 03:12:11,359 [salt.state       :1951][INFO    ][15131] Completed state [maas.wait_for_machine_status] at time 03:12:11.359215 duration_in_ms=791046.234
2019-04-23 03:12:11,364 [salt.minion      :1711][INFO    ][15131] Returning information for job: 20190423025850489563
2019-04-23 04:09:08,653 [salt.utils.schedule:1377][INFO    ][3338] Running scheduled job: __mine_interval
2019-04-23 04:56:17,337 [salt.minion      :1308][INFO    ][3338] User sudo_ubuntu Executing command cp.push_dir with jid 20190423045617327619
2019-04-23 04:56:17,358 [salt.minion      :1432][INFO    ][27773] Starting a new job with PID 27773
