2019-11-26 09:07:22,591 [salt.utils.decorators:613 ][WARNING ][2186] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:07:23,164 [salt.utils.decorators:613 ][WARNING ][2186] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:07:25,293 [salt.loaded.int.states.file:2298][WARNING ][2373] 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-11-26 09:07:41,279 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-26 09:07:41,313 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-26 09:07:41,334 [salt.utils.parsers:1051][WARNING ][365] Minion received a SIGTERM. Exiting.
2019-11-26 09:07:42,293 [salt.cli.daemons :293 ][INFO    ][2988] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-11-26 09:07:42,370 [salt.cli.daemons :82  ][INFO    ][2988] Starting up the Salt Minion
2019-11-26 09:07:42,370 [salt.utils.event :1017][INFO    ][2988] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-11-26 09:07:43,010 [salt.minion      :976 ][INFO    ][2988] Creating minion process manager
2019-11-26 09:07:44,339 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][2988] Executing command ['date', '+%z'] in directory '/root'
2019-11-26 09:07:44,358 [salt.utils.schedule:568 ][INFO    ][2988] Updating job settings for scheduled job: __mine_interval
2019-11-26 09:07:44,397 [salt.minion      :1108][INFO    ][2988] Added mine.update to scheduler
2019-11-26 09:07:44,403 [salt.minion      :1975][INFO    ][2988] Minion is starting as user 'root'
2019-11-26 09:07:44,416 [salt.minion      :2336][INFO    ][2988] Minion is ready to receive requests!
2019-11-26 09:07:47,105 [salt.state       :2022][WARNING ][2879] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-26 09:07:49,643 [salt.utils.decorators:613 ][WARNING ][2879] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:07:55,174 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126090755161135
2019-11-26 09:07:55,196 [salt.minion      :1432][INFO    ][3438] Starting a new job with PID 3438
2019-11-26 09:07:55,222 [salt.minion      :1711][INFO    ][3438] Returning information for job: 20191126090755161135
2019-11-26 09:08:25,234 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126090825220905
2019-11-26 09:08:25,257 [salt.minion      :1432][INFO    ][3767] Starting a new job with PID 3767
2019-11-26 09:08:25,281 [salt.minion      :1711][INFO    ][3767] Returning information for job: 20191126090825220905
2019-11-26 09:08:39,426 [salt.utils.decorators:613 ][WARNING ][2879] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:08:55,281 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126090855268734
2019-11-26 09:08:55,301 [salt.minion      :1432][INFO    ][3878] Starting a new job with PID 3878
2019-11-26 09:08:55,319 [salt.minion      :1711][INFO    ][3878] Returning information for job: 20191126090855268734
2019-11-26 09:09:25,344 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126090925327600
2019-11-26 09:09:25,366 [salt.minion      :1432][INFO    ][4128] Starting a new job with PID 4128
2019-11-26 09:09:25,391 [salt.minion      :1711][INFO    ][4128] Returning information for job: 20191126090925327600
2019-11-26 09:09:55,414 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126090955397786
2019-11-26 09:09:55,430 [salt.minion      :1432][INFO    ][4195] Starting a new job with PID 4195
2019-11-26 09:09:55,452 [salt.minion      :1711][INFO    ][4195] Returning information for job: 20191126090955397786
2019-11-26 09:09:57,054 [salt.utils.decorators:613 ][WARNING ][2879] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:10:13,892 [salt.utils.decorators:613 ][WARNING ][2879] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:10:17,699 [salt.loaded.ext.module.maasng:1008][WARNING ][2879] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-11-26 09:10:17,699 [salt.loaded.ext.module.maasng:1011][WARNING ][2879] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-11-26 09:10:18,550 [salt.loaded.ext.module.maasng:1235][WARNING ][2879] Ignoring parameter vlan:0
2019-11-26 09:10:20,192 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126091020184910
2019-11-26 09:10:20,207 [salt.minion      :1432][INFO    ][4422] Starting a new job with PID 4422
2019-11-26 09:10:24,068 [salt.state       :915 ][INFO    ][4422] Loading fresh modules for state activity
2019-11-26 09:10:24,129 [salt.fileclient  :1219][INFO    ][4422] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-11-26 09:10:24,173 [salt.state       :1780][INFO    ][4422] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:24.172920
2019-11-26 09:10:24,173 [salt.state       :1813][INFO    ][4422] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:10:24,175 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4422] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:10:25,628 [salt.state       :300 ][INFO    ][4422] {'pid': 4446, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:10:25,629 [salt.state       :1951][INFO    ][4422] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:25.629232 duration_in_ms=1456.311
2019-11-26 09:10:25,631 [salt.state       :1780][INFO    ][4422] Running state [maas.process_machines] at time 09:10:25.631834
2019-11-26 09:10:25,632 [salt.state       :1813][INFO    ][4422] Executing state module.run for [maas.process_machines]
2019-11-26 09:10:25,633 [salt.utils.decorators:613 ][WARNING ][4422] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:10:25,701 [salt.loaded.ext.module.maas:412 ][WARNING ][4422] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:10:25,701 [salt.loaded.ext.module.maas:92  ][INFO    ][4422] machine hostname=cmp002 power_type=ipmi mac_addresses=00:25:b5:a0:00:6a power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:10:27,873 [salt.loaded.ext.module.maas:412 ][WARNING ][4422] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:10:27,874 [salt.loaded.ext.module.maas:92  ][INFO    ][4422] machine hostname=cmp001 power_type=ipmi mac_addresses=00:25:b5:a0:00:5a power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:10:29,238 [salt.loaded.ext.module.maas:412 ][WARNING ][4422] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:10:29,239 [salt.loaded.ext.module.maas:92  ][INFO    ][4422] machine hostname=kvm01 power_type=ipmi mac_addresses=00:25:b5:a0:00:2a power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:10:30,584 [salt.loaded.ext.module.maas:412 ][WARNING ][4422] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:10:30,585 [salt.loaded.ext.module.maas:92  ][INFO    ][4422] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:10:31,916 [salt.loaded.ext.module.maas:412 ][WARNING ][4422] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:10:31,917 [salt.loaded.ext.module.maas:92  ][INFO    ][4422] machine hostname=kvm02 power_type=ipmi mac_addresses=00:25:b5:a0:00:3a power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:10:33,626 [salt.state       :300 ][INFO    ][4422] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-26 09:10:33,626 [salt.state       :1951][INFO    ][4422] Completed state [maas.process_machines] at time 09:10:33.626592 duration_in_ms=7994.756
2019-11-26 09:10:33,669 [salt.minion      :1711][INFO    ][4422] Returning information for job: 20191126091020184910
2019-11-26 09:11:04,653 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126091104638136
2019-11-26 09:11:04,675 [salt.minion      :1432][INFO    ][4766] Starting a new job with PID 4766
2019-11-26 09:11:08,452 [salt.state       :915 ][INFO    ][4766] Loading fresh modules for state activity
2019-11-26 09:11:08,502 [salt.fileclient  :1219][INFO    ][4766] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-26 09:11:08,544 [salt.state       :1780][INFO    ][4766] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:11:08.544774
2019-11-26 09:11:08,545 [salt.state       :1813][INFO    ][4766] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:11:08,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4766] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:11:09,976 [salt.state       :300 ][INFO    ][4766] {'pid': 4773, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:11:09,977 [salt.state       :1951][INFO    ][4766] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:11:09.977159 duration_in_ms=1432.385
2019-11-26 09:11:09,978 [salt.state       :1780][INFO    ][4766] Running state [maas.wait_for_machine_status] at time 09:11:09.978402
2019-11-26 09:11:09,978 [salt.state       :1813][INFO    ][4766] Executing state module.run for [maas.wait_for_machine_status]
2019-11-26 09:11:09,978 [salt.utils.decorators:613 ][WARNING ][4766] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:11:10,916 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.06769085s left)
2019-11-26 09:11:19,736 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091119723086
2019-11-26 09:11:19,758 [salt.minion      :1432][INFO    ][4806] Starting a new job with PID 4806
2019-11-26 09:11:19,782 [salt.minion      :1711][INFO    ][4806] Returning information for job: 20191126091119723086
2019-11-26 09:11:41,876 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.10771394s left)
2019-11-26 09:11:49,777 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091149764544
2019-11-26 09:11:49,799 [salt.minion      :1432][INFO    ][4834] Starting a new job with PID 4834
2019-11-26 09:11:49,821 [salt.minion      :1711][INFO    ][4834] Returning information for job: 20191126091149764544
2019-11-26 09:12:13,171 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.81291795s left)
2019-11-26 09:12:19,825 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091219813449
2019-11-26 09:12:19,843 [salt.minion      :1432][INFO    ][4990] Starting a new job with PID 4990
2019-11-26 09:12:19,854 [salt.minion      :1711][INFO    ][4990] Returning information for job: 20191126091219813449
2019-11-26 09:12:44,416 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.56782699s left)
2019-11-26 09:12:49,859 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091249847021
2019-11-26 09:12:49,880 [salt.minion      :1432][INFO    ][5184] Starting a new job with PID 5184
2019-11-26 09:12:49,900 [salt.minion      :1711][INFO    ][5184] Returning information for job: 20191126091249847021
2019-11-26 09:13:16,124 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.85969281s left)
2019-11-26 09:13:19,927 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091319914613
2019-11-26 09:13:19,950 [salt.minion      :1432][INFO    ][5847] Starting a new job with PID 5847
2019-11-26 09:13:19,973 [salt.minion      :1711][INFO    ][5847] Returning information for job: 20191126091319914613
2019-11-26 09:13:48,018 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.96566987s left)
2019-11-26 09:13:49,986 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091349970676
2019-11-26 09:13:50,010 [salt.minion      :1432][INFO    ][5882] Starting a new job with PID 5882
2019-11-26 09:13:50,034 [salt.minion      :1711][INFO    ][5882] Returning information for job: 20191126091349970676
2019-11-26 09:14:20,056 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091420039362
2019-11-26 09:14:20,079 [salt.minion      :1432][INFO    ][6025] Starting a new job with PID 6025
2019-11-26 09:14:20,103 [salt.minion      :1711][INFO    ][6025] Returning information for job: 20191126091420039362
2019-11-26 09:14:21,422 [salt.loaded.ext.module.maas:1023][INFO    ][4766] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1308.5613389s left)
2019-11-26 09:14:50,123 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091450111686
2019-11-26 09:14:50,145 [salt.minion      :1432][INFO    ][6126] Starting a new job with PID 6126
2019-11-26 09:14:50,165 [salt.minion      :1711][INFO    ][6126] Returning information for job: 20191126091450111686
2019-11-26 09:14:55,189 [salt.state       :300 ][INFO    ][4766] {'ret': True}
2019-11-26 09:14:55,189 [salt.state       :1951][INFO    ][4766] Completed state [maas.wait_for_machine_status] at time 09:14:55.189644 duration_in_ms=225211.239
2019-11-26 09:14:55,193 [salt.minion      :1711][INFO    ][4766] Returning information for job: 20191126091104638136
2019-11-26 09:14:55,834 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126091455818107
2019-11-26 09:14:55,855 [salt.minion      :1432][INFO    ][6165] Starting a new job with PID 6165
2019-11-26 09:14:59,744 [salt.state       :915 ][INFO    ][6165] Loading fresh modules for state activity
2019-11-26 09:14:59,796 [salt.fileclient  :1219][INFO    ][6165] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-26 09:14:59,893 [salt.state       :1780][INFO    ][6165] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:14:59.893236
2019-11-26 09:14:59,893 [salt.state       :1813][INFO    ][6165] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:14:59,895 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6165] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:15:01,356 [salt.state       :300 ][INFO    ][6165] {'pid': 6216, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:15:01,356 [salt.state       :1951][INFO    ][6165] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:15:01.356526 duration_in_ms=1463.291
2019-11-26 09:15:01,358 [salt.state       :1780][INFO    ][6165] Running state [maas_machines_storage_cmp002_lvm] at time 09:15:01.358000
2019-11-26 09:15:01,358 [salt.state       :1813][INFO    ][6165] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-26 09:15:02,331 [salt.loaded.ext.module.maasng:610 ][INFO    ][6165] h7ff4m
2019-11-26 09:15:02,332 [salt.loaded.ext.module.maasng:626 ][INFO    ][6165] sda
2019-11-26 09:15:03,159 [salt.loaded.ext.module.maasng:361 ][INFO    ][6165] h7ff4m
2019-11-26 09:15:03,291 [salt.loaded.ext.module.maasng:367 ][INFO    ][6165] [{u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'ccce0191-4189-447c-966e-7fc9db2361da', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h7ff4m', u'filesystem': {u'label': None, u'uuid': u'ed0be8a5-6523-40fa-8044-d8d833f03884', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'device_id': 3}], u'system_id': u'h7ff4m', u'filesystem': None, u'name': u'sda', u'id': 3, u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/'}, {u'block_size': 4096, u'uuid': u'7d6ef39f-a601-4418-a456-9e8c5e8da909', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'partitions': [], u'system_id': u'h7ff4m', u'filesystem': {u'label': u'root', u'uuid': u'a4a69700-e49b-450e-98f8-7782655a5222', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'id': 10, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'size': 2397988454400, u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/10/'}]
2019-11-26 09:15:03,291 [salt.loaded.ext.module.maasng:632 ][INFO    ][6165] vgroot
2019-11-26 09:15:03,292 [salt.loaded.ext.module.maasng:635 ][INFO    ][6165] lvroot
2019-11-26 09:15:03,292 [salt.loaded.ext.module.maasng:639 ][INFO    ][6165] 107374182400
2019-11-26 09:15:03,941 [salt.loaded.ext.module.maasng:645 ][INFO    ][6165] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'ip_addresses': [u'192.168.11.42'], u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/h7ff4m/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'owner_data': {}, u'system_id': u'h7ff4m', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'cff14038-2424-476d-a4f9-2ff0a44380b9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h7ff4m', u'device_id': 3, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'6e4974e8-b919-4891-b444-2be8fabaf149', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h7ff4m', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/', u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'134e9001-dc93-4dd2-a7f6-69d3f5c20603', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'h7ff4m', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'ace551b0-95d4-4789-90b4-dc28d119736d', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/12/', u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'cff14038-2424-476d-a4f9-2ff0a44380b9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h7ff4m', u'device_id': 3, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'6e4974e8-b919-4891-b444-2be8fabaf149', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h7ff4m', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/', u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'h7ff4m', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'cff14038-2424-476d-a4f9-2ff0a44380b9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h7ff4m', u'device_id': 3, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'6e4974e8-b919-4891-b444-2be8fabaf149', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h7ff4m', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/3/', u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'134e9001-dc93-4dd2-a7f6-69d3f5c20603', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'h7ff4m', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'ace551b0-95d4-4789-90b4-dc28d119736d', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/blockdevices/12/', u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.04', u'boot_interface': {u'children': [], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'h7ff4m', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/interfaces/4/'}, u'interface_set': [{u'children': [], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'h7ff4m', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/interfaces/4/'}, {u'children': [], u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 37}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'effective_mtu': 1500, u'system_id': u'h7ff4m', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/interfaces/16/'}, {u'children': [], u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 41}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'effective_mtu': 1500, u'system_id': u'h7ff4m', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/interfaces/17/'}, {u'children': [], u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 34}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'effective_mtu': 1500, u'system_id': u'h7ff4m', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/h7ff4m/interfaces/15/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-26 09:15:03,943 [salt.state       :300 ][INFO    ][6165] {'new': {'storage_layout': 'lvm'}}
2019-11-26 09:15:03,943 [salt.state       :1951][INFO    ][6165] Completed state [maas_machines_storage_cmp002_lvm] at time 09:15:03.943808 duration_in_ms=2585.806
2019-11-26 09:15:03,944 [salt.state       :1780][INFO    ][6165] Running state [maas_machines_storage_cmp001_lvm] at time 09:15:03.944366
2019-11-26 09:15:03,944 [salt.state       :1813][INFO    ][6165] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-26 09:15:05,334 [salt.loaded.ext.module.maasng:610 ][INFO    ][6165] 86g44c
2019-11-26 09:15:05,335 [salt.loaded.ext.module.maasng:626 ][INFO    ][6165] sda
2019-11-26 09:15:06,021 [salt.loaded.ext.module.maasng:361 ][INFO    ][6165] 86g44c
2019-11-26 09:15:06,153 [salt.loaded.ext.module.maasng:367 ][INFO    ][6165] [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'1bb6f19d-9a65-43c0-b843-0b8864af925c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86g44c', u'device_id': 5, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'b4160eb0-b1c5-4441-85a3-52bdab29d54e', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86g44c', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/', u'type': u'physical', u'id': 5, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'uuid': u'8629c8f2-ab10-4896-8071-fb37ddd62438', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86g44c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'ea9ef645-74c1-40b8-8089-f6ec4e2e73cb', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/11/', u'type': u'virtual', u'id': 11, u'serial': None, u'size': 2397988454400}]
2019-11-26 09:15:06,154 [salt.loaded.ext.module.maasng:632 ][INFO    ][6165] vgroot
2019-11-26 09:15:06,154 [salt.loaded.ext.module.maasng:635 ][INFO    ][6165] lvroot
2019-11-26 09:15:06,154 [salt.loaded.ext.module.maasng:639 ][INFO    ][6165] 107374182400
2019-11-26 09:15:06,886 [salt.loaded.ext.module.maasng:645 ][INFO    ][6165] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'ip_addresses': [u'192.168.11.38'], u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/86g44c/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'owner_data': {}, u'system_id': u'86g44c', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'316ae965-d812-4175-8db1-3ef4ca934a5d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86g44c', u'device_id': 5, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'aa77b831-bffc-451b-a961-57fac894455c', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86g44c', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/', u'type': u'physical', u'id': 5, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'cc049ddf-b54f-4a0e-9e32-e9c5109fb804', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86g44c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'9d62c288-bb26-4183-bd55-47ca1ec49df9', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/13/', u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'316ae965-d812-4175-8db1-3ef4ca934a5d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86g44c', u'device_id': 5, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'aa77b831-bffc-451b-a961-57fac894455c', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86g44c', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/', u'type': u'physical', u'id': 5, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'86g44c', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'316ae965-d812-4175-8db1-3ef4ca934a5d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86g44c', u'device_id': 5, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'aa77b831-bffc-451b-a961-57fac894455c', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86g44c', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/5/', u'type': u'physical', u'id': 5, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'cc049ddf-b54f-4a0e-9e32-e9c5109fb804', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86g44c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'9d62c288-bb26-4183-bd55-47ca1ec49df9', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/blockdevices/13/', u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.04', u'boot_interface': {u'children': [], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 36}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'86g44c', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/interfaces/5/'}, u'interface_set': [{u'children': [], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 36}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'86g44c', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/interfaces/5/'}, {u'children': [], u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 38}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'effective_mtu': 1500, u'system_id': u'86g44c', u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/interfaces/21/'}, {u'children': [], u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 40}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'effective_mtu': 1500, u'system_id': u'86g44c', u'type': u'physical', u'id': 22, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/interfaces/22/'}, {u'children': [], u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 42}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'effective_mtu': 1500, u'system_id': u'86g44c', u'type': u'physical', u'id': 23, u'resource_uri': u'/MAAS/api/2.0/nodes/86g44c/interfaces/23/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-26 09:15:06,888 [salt.state       :300 ][INFO    ][6165] {'new': {'storage_layout': 'lvm'}}
2019-11-26 09:15:06,888 [salt.state       :1951][INFO    ][6165] Completed state [maas_machines_storage_cmp001_lvm] at time 09:15:06.888596 duration_in_ms=2944.229
2019-11-26 09:15:06,892 [salt.minion      :1711][INFO    ][6165] Returning information for job: 20191126091455818107
2019-11-26 09:15:07,526 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126091507512433
2019-11-26 09:15:07,547 [salt.minion      :1432][INFO    ][6234] Starting a new job with PID 6234
2019-11-26 09:15:08,257 [salt.state       :915 ][INFO    ][6234] Loading fresh modules for state activity
2019-11-26 09:15:08,286 [salt.fileclient  :1219][INFO    ][6234] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-26 09:15:08,312 [salt.state       :1780][INFO    ][6234] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:15:08.312335
2019-11-26 09:15:08,312 [salt.state       :1813][INFO    ][6234] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:15:08,313 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6234] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:15:09,630 [salt.state       :300 ][INFO    ][6234] {'pid': 6241, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:15:09,631 [salt.state       :1951][INFO    ][6234] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:15:09.631337 duration_in_ms=1319.003
2019-11-26 09:15:09,632 [salt.state       :1780][INFO    ][6234] Running state [maas.deploy_machines] at time 09:15:09.632504
2019-11-26 09:15:09,632 [salt.state       :1813][INFO    ][6234] Executing state module.run for [maas.deploy_machines]
2019-11-26 09:15:09,633 [salt.utils.decorators:613 ][WARNING ][6234] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:15:10,373 [salt.loaded.ext.module.maas:684 ][INFO    ][6234] deploymachines hwe_kernel=ga-18.04 system_id=h7ff4m distro_series=bionic
2019-11-26 09:15:12,742 [salt.loaded.ext.module.maas:684 ][INFO    ][6234] deploymachines hwe_kernel=ga-18.04 system_id=86g44c distro_series=bionic
2019-11-26 09:15:14,958 [salt.loaded.ext.module.maas:684 ][INFO    ][6234] deploymachines hwe_kernel=ga-18.04 system_id=mwhpxd distro_series=bionic
2019-11-26 09:15:17,362 [salt.loaded.ext.module.maas:684 ][INFO    ][6234] deploymachines hwe_kernel=ga-18.04 system_id=8acy4f distro_series=bionic
2019-11-26 09:15:19,493 [salt.loaded.ext.module.maas:684 ][INFO    ][6234] deploymachines hwe_kernel=ga-18.04 system_id=asarmx distro_series=bionic
2019-11-26 09:15:21,669 [salt.state       :300 ][INFO    ][6234] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-26 09:15:21,670 [salt.state       :1951][INFO    ][6234] Completed state [maas.deploy_machines] at time 09:15:21.669944 duration_in_ms=12037.438
2019-11-26 09:15:21,674 [salt.minion      :1711][INFO    ][6234] Returning information for job: 20191126091507512433
2019-11-26 09:15:22,290 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126091522274986
2019-11-26 09:15:22,312 [salt.minion      :1432][INFO    ][6542] Starting a new job with PID 6542
2019-11-26 09:15:26,163 [salt.state       :915 ][INFO    ][6542] Loading fresh modules for state activity
2019-11-26 09:15:26,217 [salt.fileclient  :1219][INFO    ][6542] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-26 09:15:26,259 [salt.state       :1780][INFO    ][6542] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:15:26.258951
2019-11-26 09:15:26,259 [salt.state       :1813][INFO    ][6542] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:15:26,261 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6542] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:15:27,666 [salt.state       :300 ][INFO    ][6542] {'pid': 6557, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:15:27,666 [salt.state       :1951][INFO    ][6542] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:15:27.666533 duration_in_ms=1407.582
2019-11-26 09:15:27,667 [salt.state       :1780][INFO    ][6542] Running state [maas.wait_for_machine_status] at time 09:15:27.667965
2019-11-26 09:15:27,668 [salt.state       :1813][INFO    ][6542] Executing state module.run for [maas.wait_for_machine_status]
2019-11-26 09:15:27,668 [salt.utils.decorators:613 ][WARNING ][6542] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:15:31,104 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.56784987s left)
2019-11-26 09:15:37,335 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091537321659
2019-11-26 09:15:37,357 [salt.minion      :1432][INFO    ][6569] Starting a new job with PID 6569
2019-11-26 09:15:37,381 [salt.minion      :1711][INFO    ][6569] Returning information for job: 20191126091537321659
2019-11-26 09:16:04,502 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.17014694s left)
2019-11-26 09:16:07,379 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091607365636
2019-11-26 09:16:07,402 [salt.minion      :1432][INFO    ][6607] Starting a new job with PID 6607
2019-11-26 09:16:07,425 [salt.minion      :1711][INFO    ][6607] Returning information for job: 20191126091607365636
2019-11-26 09:16:37,425 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091637412322
2019-11-26 09:16:37,447 [salt.minion      :1432][INFO    ][6639] Starting a new job with PID 6639
2019-11-26 09:16:37,470 [salt.minion      :1711][INFO    ][6639] Returning information for job: 20191126091637412322
2019-11-26 09:16:38,269 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.40380502s left)
2019-11-26 09:17:07,474 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091707461988
2019-11-26 09:17:07,492 [salt.minion      :1432][INFO    ][6759] Starting a new job with PID 6759
2019-11-26 09:17:07,503 [salt.minion      :1711][INFO    ][6759] Returning information for job: 20191126091707461988
2019-11-26 09:17:11,528 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.14453101s left)
2019-11-26 09:17:37,517 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091737504859
2019-11-26 09:17:37,539 [salt.minion      :1432][INFO    ][6969] Starting a new job with PID 6969
2019-11-26 09:17:37,563 [salt.minion      :1711][INFO    ][6969] Returning information for job: 20191126091737504859
2019-11-26 09:17:44,927 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.74555492s left)
2019-11-26 09:18:07,581 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091807566274
2019-11-26 09:18:07,604 [salt.minion      :1432][INFO    ][7526] Starting a new job with PID 7526
2019-11-26 09:18:07,628 [salt.minion      :1711][INFO    ][7526] Returning information for job: 20191126091807566274
2019-11-26 09:18:18,550 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.12218881s left)
2019-11-26 09:18:37,655 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091837639704
2019-11-26 09:18:37,678 [salt.minion      :1432][INFO    ][7742] Starting a new job with PID 7742
2019-11-26 09:18:37,700 [salt.minion      :1711][INFO    ][7742] Returning information for job: 20191126091837639704
2019-11-26 09:18:51,836 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.8360858s left)
2019-11-26 09:19:07,716 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091907702786
2019-11-26 09:19:07,738 [salt.minion      :1432][INFO    ][7915] Starting a new job with PID 7915
2019-11-26 09:19:07,761 [salt.minion      :1711][INFO    ][7915] Returning information for job: 20191126091907702786
2019-11-26 09:19:25,313 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.35961986s left)
2019-11-26 09:19:37,778 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126091937765657
2019-11-26 09:19:37,801 [salt.minion      :1432][INFO    ][7969] Starting a new job with PID 7969
2019-11-26 09:19:37,825 [salt.minion      :1711][INFO    ][7969] Returning information for job: 20191126091937765657
2019-11-26 09:19:58,504 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.16830683s left)
2019-11-26 09:20:07,854 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092007841339
2019-11-26 09:20:07,876 [salt.minion      :1432][INFO    ][8129] Starting a new job with PID 8129
2019-11-26 09:20:07,901 [salt.minion      :1711][INFO    ][8129] Returning information for job: 20191126092007841339
2019-11-26 09:20:32,404 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.268677s left)
2019-11-26 09:20:37,928 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092037915166
2019-11-26 09:20:37,946 [salt.minion      :1432][INFO    ][8230] Starting a new job with PID 8230
2019-11-26 09:20:37,970 [salt.minion      :1711][INFO    ][8230] Returning information for job: 20191126092037915166
2019-11-26 09:21:05,972 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1911.70032692s left)
2019-11-26 09:21:08,008 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092107995211
2019-11-26 09:21:08,030 [salt.minion      :1432][INFO    ][8626] Starting a new job with PID 8626
2019-11-26 09:21:08,056 [salt.minion      :1711][INFO    ][8626] Returning information for job: 20191126092107995211
2019-11-26 09:21:38,096 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092138083172
2019-11-26 09:21:38,117 [salt.minion      :1432][INFO    ][8761] Starting a new job with PID 8761
2019-11-26 09:21:38,140 [salt.minion      :1711][INFO    ][8761] Returning information for job: 20191126092138083172
2019-11-26 09:21:39,220 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.45280695s left)
2019-11-26 09:22:08,183 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092208170211
2019-11-26 09:22:08,206 [salt.minion      :1432][INFO    ][8906] Starting a new job with PID 8906
2019-11-26 09:22:08,229 [salt.minion      :1711][INFO    ][8906] Returning information for job: 20191126092208170211
2019-11-26 09:22:12,197 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.475137s left)
2019-11-26 09:22:38,276 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092238263120
2019-11-26 09:22:38,298 [salt.minion      :1432][INFO    ][8965] Starting a new job with PID 8965
2019-11-26 09:22:38,322 [salt.minion      :1711][INFO    ][8965] Returning information for job: 20191126092238263120
2019-11-26 09:22:45,722 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1811.950773s left)
2019-11-26 09:23:08,348 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092308335061
2019-11-26 09:23:08,371 [salt.minion      :1432][INFO    ][9145] Starting a new job with PID 9145
2019-11-26 09:23:08,394 [salt.minion      :1711][INFO    ][9145] Returning information for job: 20191126092308335061
2019-11-26 09:23:18,762 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1778.90991879s left)
2019-11-26 09:23:38,482 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092338469537
2019-11-26 09:23:38,505 [salt.minion      :1432][INFO    ][9290] Starting a new job with PID 9290
2019-11-26 09:23:38,530 [salt.minion      :1711][INFO    ][9290] Returning information for job: 20191126092338469537
2019-11-26 09:23:51,128 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1746.54430389s left)
2019-11-26 09:24:08,597 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092408580841
2019-11-26 09:24:08,620 [salt.minion      :1432][INFO    ][9656] Starting a new job with PID 9656
2019-11-26 09:24:08,643 [salt.minion      :1711][INFO    ][9656] Returning information for job: 20191126092408580841
2019-11-26 09:24:24,005 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1713.66749883s left)
2019-11-26 09:24:38,719 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092438706451
2019-11-26 09:24:38,741 [salt.minion      :1432][INFO    ][9762] Starting a new job with PID 9762
2019-11-26 09:24:38,765 [salt.minion      :1711][INFO    ][9762] Returning information for job: 20191126092438706451
2019-11-26 09:24:57,063 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1680.6094358s left)
2019-11-26 09:25:08,850 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092508834824
2019-11-26 09:25:08,873 [salt.minion      :1432][INFO    ][9802] Starting a new job with PID 9802
2019-11-26 09:25:08,896 [salt.minion      :1711][INFO    ][9802] Returning information for job: 20191126092508834824
2019-11-26 09:25:30,397 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1647.27550387s left)
2019-11-26 09:25:38,992 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092538976873
2019-11-26 09:25:39,015 [salt.minion      :1432][INFO    ][9837] Starting a new job with PID 9837
2019-11-26 09:25:39,038 [salt.minion      :1711][INFO    ][9837] Returning information for job: 20191126092538976873
2019-11-26 09:26:03,828 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1613.84401584s left)
2019-11-26 09:26:09,138 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092609125304
2019-11-26 09:26:09,161 [salt.minion      :1432][INFO    ][9877] Starting a new job with PID 9877
2019-11-26 09:26:09,186 [salt.minion      :1711][INFO    ][9877] Returning information for job: 20191126092609125304
2019-11-26 09:26:37,110 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1580.56275582s left)
2019-11-26 09:26:39,294 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092639281637
2019-11-26 09:26:39,317 [salt.minion      :1432][INFO    ][9914] Starting a new job with PID 9914
2019-11-26 09:26:39,342 [salt.minion      :1711][INFO    ][9914] Returning information for job: 20191126092639281637
2019-11-26 09:27:09,459 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092709448203
2019-11-26 09:27:09,480 [salt.minion      :1432][INFO    ][9955] Starting a new job with PID 9955
2019-11-26 09:27:09,503 [salt.minion      :1711][INFO    ][9955] Returning information for job: 20191126092709448203
2019-11-26 09:27:10,544 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1547.12839389s left)
2019-11-26 09:27:39,628 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092739616259
2019-11-26 09:27:39,651 [salt.minion      :1432][INFO    ][9991] Starting a new job with PID 9991
2019-11-26 09:27:39,675 [salt.minion      :1711][INFO    ][9991] Returning information for job: 20191126092739616259
2019-11-26 09:27:43,780 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1513.89186597s left)
2019-11-26 09:28:09,811 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092809798120
2019-11-26 09:28:09,833 [salt.minion      :1432][INFO    ][10138] Starting a new job with PID 10138
2019-11-26 09:28:09,857 [salt.minion      :1711][INFO    ][10138] Returning information for job: 20191126092809798120
2019-11-26 09:28:17,334 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1480.33803797s left)
2019-11-26 09:28:39,999 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092839986381
2019-11-26 09:28:40,022 [salt.minion      :1432][INFO    ][10180] Starting a new job with PID 10180
2019-11-26 09:28:40,045 [salt.minion      :1711][INFO    ][10180] Returning information for job: 20191126092839986381
2019-11-26 09:28:50,979 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1446.69288683s left)
2019-11-26 09:29:10,201 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092910188914
2019-11-26 09:29:10,222 [salt.minion      :1432][INFO    ][10221] Starting a new job with PID 10221
2019-11-26 09:29:10,246 [salt.minion      :1711][INFO    ][10221] Returning information for job: 20191126092910188914
2019-11-26 09:29:24,417 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1413.25509501s left)
2019-11-26 09:29:40,415 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126092940401896
2019-11-26 09:29:40,438 [salt.minion      :1432][INFO    ][10256] Starting a new job with PID 10256
2019-11-26 09:29:40,461 [salt.minion      :1711][INFO    ][10256] Returning information for job: 20191126092940401896
2019-11-26 09:29:57,720 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1379.95268393s left)
2019-11-26 09:30:10,641 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093010628308
2019-11-26 09:30:10,664 [salt.minion      :1432][INFO    ][10310] Starting a new job with PID 10310
2019-11-26 09:30:10,687 [salt.minion      :1711][INFO    ][10310] Returning information for job: 20191126093010628308
2019-11-26 09:30:31,228 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1346.44398284s left)
2019-11-26 09:30:40,663 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093040650908
2019-11-26 09:30:40,686 [salt.minion      :1432][INFO    ][10344] Starting a new job with PID 10344
2019-11-26 09:30:40,711 [salt.minion      :1711][INFO    ][10344] Returning information for job: 20191126093040650908
2019-11-26 09:31:04,873 [salt.loaded.ext.module.maas:1023][INFO    ][6542] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1312.79891992s left)
2019-11-26 09:31:10,699 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093110686556
2019-11-26 09:31:10,719 [salt.minion      :1432][INFO    ][10387] Starting a new job with PID 10387
2019-11-26 09:31:10,743 [salt.minion      :1711][INFO    ][10387] Returning information for job: 20191126093110686556
2019-11-26 09:31:38,298 [salt.loaded.ext.module.maas:993 ][INFO    ][6542] Machine asarmx mark broken
2019-11-26 09:31:39,051 [salt.loaded.ext.module.maas:996 ][INFO    ][6542] Machine asarmx mark fixed
2019-11-26 09:31:40,266 [salt.loaded.ext.module.maas:684 ][INFO    ][6542] deploymachines hwe_kernel=ga-18.04 system_id=asarmx distro_series=bionic
2019-11-26 09:31:40,741 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093140728962
2019-11-26 09:31:40,762 [salt.minion      :1432][INFO    ][10440] Starting a new job with PID 10440
2019-11-26 09:31:40,785 [salt.minion      :1711][INFO    ][10440] Returning information for job: 20191126093140728962
2019-11-26 09:31:42,604 [salt.loaded.ext.module.maas:160 ][ERROR   ][6542] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-11-26 09:31:42,605 [salt.state       :302 ][ERROR   ][6542] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-11-26 09:31:42,606 [salt.state       :1951][INFO    ][6542] Completed state [maas.wait_for_machine_status] at time 09:31:42.606104 duration_in_ms=974938.133
2019-11-26 09:31:42,611 [salt.minion      :1711][INFO    ][6542] Returning information for job: 20191126091522274986
2019-11-26 09:31:53,416 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command pillar.get with jid 20191126093153403342
2019-11-26 09:31:53,440 [salt.minion      :1432][INFO    ][10513] Starting a new job with PID 10513
2019-11-26 09:31:53,446 [salt.minion      :1711][INFO    ][10513] Returning information for job: 20191126093153403342
2019-11-26 09:31:54,048 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command service.status with jid 20191126093154034764
2019-11-26 09:31:54,071 [salt.minion      :1432][INFO    ][10518] Starting a new job with PID 10518
2019-11-26 09:31:54,434 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10518] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-26 09:31:54,467 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10518] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-26 09:31:54,482 [salt.minion      :1711][INFO    ][10518] Returning information for job: 20191126093154034764
2019-11-26 09:31:54,977 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126093154964455
2019-11-26 09:31:54,999 [salt.minion      :1432][INFO    ][10529] Starting a new job with PID 10529
2019-11-26 09:31:58,667 [salt.state       :915 ][INFO    ][10529] Loading fresh modules for state activity
2019-11-26 09:31:59,083 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'salt-minion --version' in directory '/root'
2019-11-26 09:31:59,383 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'salt-minion --version' in directory '/root'
2019-11-26 09:32:00,219 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'salt-minion --version' in directory '/root'
2019-11-26 09:32:00,577 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'salt-minion --version' in directory '/root'
2019-11-26 09:32:02,054 [salt.state       :1780][INFO    ][10529] Running state [salt-minion] at time 09:32:02.054389
2019-11-26 09:32:02,054 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [salt-minion]
2019-11-26 09:32:02,055 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-26 09:32:02,137 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,138 [salt.state       :1951][INFO    ][10529] Completed state [salt-minion] at time 09:32:02.138098 duration_in_ms=83.709
2019-11-26 09:32:02,138 [salt.state       :1780][INFO    ][10529] Running state [salt_minion_dependency_packages] at time 09:32:02.138409
2019-11-26 09:32:02,138 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-26 09:32:02,144 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,144 [salt.state       :1951][INFO    ][10529] Completed state [salt_minion_dependency_packages] at time 09:32:02.144667 duration_in_ms=6.257
2019-11-26 09:32:02,147 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/minion.d/minion.conf] at time 09:32:02.147617
2019-11-26 09:32:02,147 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-26 09:32:02,342 [salt.state       :300 ][INFO    ][10529] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-26 09:32:02,342 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/minion.d/minion.conf] at time 09:32:02.342516 duration_in_ms=194.899
2019-11-26 09:32:02,342 [salt.state       :1780][INFO    ][10529] Running state [python-netaddr] at time 09:32:02.342739
2019-11-26 09:32:02,342 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [python-netaddr]
2019-11-26 09:32:02,348 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,348 [salt.state       :1951][INFO    ][10529] Completed state [python-netaddr] at time 09:32:02.348608 duration_in_ms=5.869
2019-11-26 09:32:02,351 [salt.state       :1780][INFO    ][10529] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:32:02.351188
2019-11-26 09:32:02,351 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-26 09:32:02,361 [salt.state       :300 ][INFO    ][10529] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-26 09:32:02,361 [salt.state       :1951][INFO    ][10529] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:32:02.361916 duration_in_ms=10.728
2019-11-26 09:32:02,362 [salt.state       :1780][INFO    ][10529] Running state [salt-minion] at time 09:32:02.362727
2019-11-26 09:32:02,362 [salt.state       :1813][INFO    ][10529] Executing state service.running for [salt-minion]
2019-11-26 09:32:02,363 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:02,399 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-26 09:32:02,416 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-26 09:32:02,433 [salt.state       :300 ][INFO    ][10529] The service salt-minion is already running
2019-11-26 09:32:02,434 [salt.state       :1951][INFO    ][10529] Completed state [salt-minion] at time 09:32:02.434224 duration_in_ms=71.497
2019-11-26 09:32:02,435 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains.d] at time 09:32:02.435798
2019-11-26 09:32:02,436 [salt.state       :1813][INFO    ][10529] Executing state file.directory for [/etc/salt/grains.d]
2019-11-26 09:32:02,437 [salt.state       :300 ][INFO    ][10529] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-26 09:32:02,437 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains.d] at time 09:32:02.437382 duration_in_ms=1.583
2019-11-26 09:32:02,438 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains] at time 09:32:02.438087
2019-11-26 09:32:02,438 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/grains]
2019-11-26 09:32:02,439 [salt.state       :300 ][INFO    ][10529] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-26 09:32:02,439 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains] at time 09:32:02.439219 duration_in_ms=1.131
2019-11-26 09:32:02,439 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains.d/placeholder] at time 09:32:02.439703
2019-11-26 09:32:02,440 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-26 09:32:02,440 [salt.state       :300 ][INFO    ][10529] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-26 09:32:02,440 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains.d/placeholder] at time 09:32:02.440796 duration_in_ms=1.093
2019-11-26 09:32:02,441 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains.d/sphinx] at time 09:32:02.441264
2019-11-26 09:32:02,441 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-26 09:32:02,455 [salt.state       :300 ][INFO    ][10529] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-26 09:32:02,456 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains.d/sphinx] at time 09:32:02.456067 duration_in_ms=14.803
2019-11-26 09:32:02,458 [salt.state       :1780][INFO    ][10529] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.458379
2019-11-26 09:32:02,458 [salt.state       :1813][INFO    ][10529] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-26 09:32:02,459 [salt.state       :300 ][INFO    ][10529] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-26 09:32:02,459 [salt.state       :1951][INFO    ][10529] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.459290 duration_in_ms=0.911
2019-11-26 09:32:02,459 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains.d/dns_records] at time 09:32:02.459798
2019-11-26 09:32:02,460 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-26 09:32:02,473 [salt.state       :300 ][INFO    ][10529] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-26 09:32:02,474 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains.d/dns_records] at time 09:32:02.474042 duration_in_ms=14.245
2019-11-26 09:32:02,475 [salt.state       :1780][INFO    ][10529] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.474976
2019-11-26 09:32:02,475 [salt.state       :1813][INFO    ][10529] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-26 09:32:02,475 [salt.state       :300 ][INFO    ][10529] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-26 09:32:02,475 [salt.state       :1951][INFO    ][10529] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.475870 duration_in_ms=0.894
2019-11-26 09:32:02,476 [salt.state       :1780][INFO    ][10529] Running state [/etc/salt/grains.d/salt] at time 09:32:02.476353
2019-11-26 09:32:02,476 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-26 09:32:02,485 [salt.state       :300 ][INFO    ][10529] File /etc/salt/grains.d/salt is in the correct state
2019-11-26 09:32:02,486 [salt.state       :1951][INFO    ][10529] Completed state [/etc/salt/grains.d/salt] at time 09:32:02.486066 duration_in_ms=9.713
2019-11-26 09:32:02,487 [salt.state       :1780][INFO    ][10529] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.486991
2019-11-26 09:32:02,487 [salt.state       :1813][INFO    ][10529] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-26 09:32:02,487 [salt.state       :300 ][INFO    ][10529] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-26 09:32:02,487 [salt.state       :1951][INFO    ][10529] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:32:02.487911 duration_in_ms=0.92
2019-11-26 09:32:02,489 [salt.state       :1780][INFO    ][10529] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:32:02.489882
2019-11-26 09:32:02,490 [salt.state       :1813][INFO    ][10529] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-26 09:32:02,490 [salt.state       :300 ][INFO    ][10529] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-26 09:32:02,490 [salt.state       :1951][INFO    ][10529] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:32:02.490820 duration_in_ms=0.938
2019-11-26 09:32:02,491 [salt.state       :1780][INFO    ][10529] Running state [mine.update] at time 09:32:02.491525
2019-11-26 09:32:02,491 [salt.state       :1813][INFO    ][10529] Executing state module.wait for [mine.update]
2019-11-26 09:32:02,492 [salt.state       :300 ][INFO    ][10529] No changes made for mine.update
2019-11-26 09:32:02,492 [salt.state       :1951][INFO    ][10529] Completed state [mine.update] at time 09:32:02.492375 duration_in_ms=0.85
2019-11-26 09:32:02,492 [salt.state       :1780][INFO    ][10529] Running state [ca-certificates] at time 09:32:02.492665
2019-11-26 09:32:02,492 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [ca-certificates]
2019-11-26 09:32:02,500 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,500 [salt.state       :1951][INFO    ][10529] Completed state [ca-certificates] at time 09:32:02.500741 duration_in_ms=8.076
2019-11-26 09:32:02,501 [salt.state       :1780][INFO    ][10529] Running state [update-ca-certificates] at time 09:32:02.501425
2019-11-26 09:32:02,501 [salt.state       :1813][INFO    ][10529] Executing state cmd.wait for [update-ca-certificates]
2019-11-26 09:32:02,502 [salt.state       :300 ][INFO    ][10529] No changes made for update-ca-certificates
2019-11-26 09:32:02,502 [salt.state       :1951][INFO    ][10529] Completed state [update-ca-certificates] at time 09:32:02.502271 duration_in_ms=0.846
2019-11-26 09:32:02,502 [salt.state       :1780][INFO    ][10529] Running state [iptables] at time 09:32:02.502530
2019-11-26 09:32:02,502 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [iptables]
2019-11-26 09:32:02,509 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,509 [salt.state       :1951][INFO    ][10529] Completed state [iptables] at time 09:32:02.509879 duration_in_ms=7.35
2019-11-26 09:32:02,510 [salt.state       :1780][INFO    ][10529] Running state [iptables-persistent] at time 09:32:02.510123
2019-11-26 09:32:02,510 [salt.state       :1813][INFO    ][10529] Executing state pkg.installed for [iptables-persistent]
2019-11-26 09:32:02,517 [salt.state       :300 ][INFO    ][10529] All specified packages are already installed
2019-11-26 09:32:02,517 [salt.state       :1951][INFO    ][10529] Completed state [iptables-persistent] at time 09:32:02.517257 duration_in_ms=7.134
2019-11-26 09:32:02,518 [salt.state       :1780][INFO    ][10529] Running state [iptables_modules_v4_load] at time 09:32:02.518248
2019-11-26 09:32:02,518 [salt.state       :1813][INFO    ][10529] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-26 09:32:02,519 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'lsmod' in directory '/root'
2019-11-26 09:32:02,543 [salt.state       :300 ][INFO    ][10529] Kernel modules iptable_filter, ip_tables are already present
2019-11-26 09:32:02,544 [salt.state       :1951][INFO    ][10529] Completed state [iptables_modules_v4_load] at time 09:32:02.544028 duration_in_ms=25.781
2019-11-26 09:32:02,544 [salt.state       :1780][INFO    ][10529] Running state [/etc/iptables/rules.v4] at time 09:32:02.544857
2019-11-26 09:32:02,545 [salt.state       :1813][INFO    ][10529] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-26 09:32:02,647 [salt.state       :300 ][INFO    ][10529] File /etc/iptables/rules.v4 is in the correct state
2019-11-26 09:32:02,648 [salt.state       :1951][INFO    ][10529] Completed state [/etc/iptables/rules.v4] at time 09:32:02.647943 duration_in_ms=103.086
2019-11-26 09:32:02,649 [salt.state       :1780][INFO    ][10529] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:32:02.649036
2019-11-26 09:32:02,649 [salt.state       :1813][INFO    ][10529] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-26 09:32:02,649 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-26 09:32:02,671 [salt.state       :300 ][INFO    ][10529] onlyif execution failed
2019-11-26 09:32:02,672 [salt.state       :1951][INFO    ][10529] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:32:02.672033 duration_in_ms=22.996
2019-11-26 09:32:02,673 [salt.state       :1780][INFO    ][10529] Running state [netfilter-persistent] at time 09:32:02.673014
2019-11-26 09:32:02,673 [salt.state       :1813][INFO    ][10529] Executing state service.running for [netfilter-persistent]
2019-11-26 09:32:02,674 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:02,693 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-26 09:32:02,711 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-26 09:32:02,728 [salt.state       :300 ][INFO    ][10529] The service netfilter-persistent is already running
2019-11-26 09:32:02,728 [salt.state       :1951][INFO    ][10529] Completed state [netfilter-persistent] at time 09:32:02.728820 duration_in_ms=55.806
2019-11-26 09:32:02,729 [salt.state       :1780][INFO    ][10529] Running state [iptables_extra.remove_stale_tables] at time 09:32:02.729814
2019-11-26 09:32:02,730 [salt.state       :1813][INFO    ][10529] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-26 09:32:02,730 [salt.state       :300 ][INFO    ][10529] No changes made for iptables_extra.remove_stale_tables
2019-11-26 09:32:02,730 [salt.state       :1951][INFO    ][10529] Completed state [iptables_extra.remove_stale_tables] at time 09:32:02.730870 duration_in_ms=1.057
2019-11-26 09:32:02,731 [salt.state       :1780][INFO    ][10529] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:32:02.731155
2019-11-26 09:32:02,731 [salt.state       :1813][INFO    ][10529] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-26 09:32:02,732 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10529] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-26 09:32:02,747 [salt.state       :300 ][INFO    ][10529] onlyif execution failed
2019-11-26 09:32:02,747 [salt.state       :1951][INFO    ][10529] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:32:02.747670 duration_in_ms=16.514
2019-11-26 09:32:02,749 [salt.state       :1780][INFO    ][10529] Running state [/etc/iptables/rules.v6] at time 09:32:02.749257
2019-11-26 09:32:02,749 [salt.state       :1813][INFO    ][10529] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-26 09:32:02,750 [salt.state       :300 ][INFO    ][10529] File /etc/iptables/rules.v6 is not present
2019-11-26 09:32:02,750 [salt.state       :1951][INFO    ][10529] Completed state [/etc/iptables/rules.v6] at time 09:32:02.750902 duration_in_ms=1.647
2019-11-26 09:32:02,752 [salt.state       :1780][INFO    ][10529] Running state [iptables_extra.flush_all] at time 09:32:02.751968
2019-11-26 09:32:02,752 [salt.state       :1813][INFO    ][10529] Executing state module.wait for [iptables_extra.flush_all]
2019-11-26 09:32:02,752 [salt.state       :300 ][INFO    ][10529] No changes made for iptables_extra.flush_all
2019-11-26 09:32:02,753 [salt.state       :1951][INFO    ][10529] Completed state [iptables_extra.flush_all] at time 09:32:02.753162 duration_in_ms=1.193
2019-11-26 09:32:02,757 [salt.minion      :1711][INFO    ][10529] Returning information for job: 20191126093154964455
2019-11-26 09:32:03,392 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126093203382807
2019-11-26 09:32:03,413 [salt.minion      :1432][INFO    ][10608] Starting a new job with PID 10608
2019-11-26 09:32:04,157 [salt.state       :915 ][INFO    ][10608] Loading fresh modules for state activity
2019-11-26 09:32:04,779 [salt.state       :1780][INFO    ][10608] Running state [maas-rack-controller] at time 09:32:04.779511
2019-11-26 09:32:04,779 [salt.state       :1813][INFO    ][10608] Executing state pkg.installed for [maas-rack-controller]
2019-11-26 09:32:04,780 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10608] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-26 09:32:04,886 [salt.state       :300 ][INFO    ][10608] All specified packages are already installed
2019-11-26 09:32:04,886 [salt.state       :1951][INFO    ][10608] Completed state [maas-rack-controller] at time 09:32:04.886578 duration_in_ms=107.067
2019-11-26 09:32:04,887 [salt.state       :1780][INFO    ][10608] Running state [ipmitool] at time 09:32:04.887002
2019-11-26 09:32:04,887 [salt.state       :1813][INFO    ][10608] Executing state pkg.installed for [ipmitool]
2019-11-26 09:32:04,895 [salt.state       :300 ][INFO    ][10608] All specified packages are already installed
2019-11-26 09:32:04,896 [salt.state       :1951][INFO    ][10608] Completed state [ipmitool] at time 09:32:04.896156 duration_in_ms=9.154
2019-11-26 09:32:04,899 [salt.state       :1780][INFO    ][10608] Running state [/etc/maas/rackd.conf] at time 09:32:04.899887
2019-11-26 09:32:04,900 [salt.state       :1813][INFO    ][10608] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-26 09:32:04,901 [salt.state       :300 ][INFO    ][10608] No changes needed to be made
2019-11-26 09:32:04,901 [salt.state       :1951][INFO    ][10608] Completed state [/etc/maas/rackd.conf] at time 09:32:04.901606 duration_in_ms=1.72
2019-11-26 09:32:04,901 [salt.state       :1780][INFO    ][10608] Running state [/etc/maas/rackd.conf] at time 09:32:04.901909
2019-11-26 09:32:04,902 [salt.state       :1813][INFO    ][10608] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-26 09:32:04,902 [salt.loaded.int.states.file:2298][WARNING ][10608] 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-11-26 09:32:04,903 [salt.state       :300 ][INFO    ][10608] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-26 09:32:04,903 [salt.state       :1951][INFO    ][10608] Completed state [/etc/maas/rackd.conf] at time 09:32:04.903786 duration_in_ms=1.878
2019-11-26 09:32:04,905 [salt.state       :1780][INFO    ][10608] Running state [maas-rackd] at time 09:32:04.905004
2019-11-26 09:32:04,905 [salt.state       :1813][INFO    ][10608] Executing state service.running for [maas-rackd]
2019-11-26 09:32:04,906 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10608] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:04,940 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10608] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-26 09:32:04,957 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10608] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-26 09:32:04,974 [salt.state       :300 ][INFO    ][10608] The service maas-rackd is already running
2019-11-26 09:32:04,975 [salt.state       :1951][INFO    ][10608] Completed state [maas-rackd] at time 09:32:04.975362 duration_in_ms=70.358
2019-11-26 09:32:04,977 [salt.minion      :1711][INFO    ][10608] Returning information for job: 20191126093203382807
2019-11-26 09:32:05,556 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126093205546768
2019-11-26 09:32:05,578 [salt.minion      :1432][INFO    ][10631] Starting a new job with PID 10631
2019-11-26 09:32:06,348 [salt.state       :915 ][INFO    ][10631] Loading fresh modules for state activity
2019-11-26 09:32:07,039 [salt.state       :1780][INFO    ][10631] Running state [maas-region-controller] at time 09:32:07.039540
2019-11-26 09:32:07,039 [salt.state       :1813][INFO    ][10631] Executing state pkg.installed for [maas-region-controller]
2019-11-26 09:32:07,040 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-26 09:32:07,134 [salt.state       :300 ][INFO    ][10631] All specified packages are already installed
2019-11-26 09:32:07,135 [salt.state       :1951][INFO    ][10631] Completed state [maas-region-controller] at time 09:32:07.135224 duration_in_ms=95.684
2019-11-26 09:32:07,135 [salt.state       :1780][INFO    ][10631] Running state [python-oauth] at time 09:32:07.135560
2019-11-26 09:32:07,135 [salt.state       :1813][INFO    ][10631] Executing state pkg.installed for [python-oauth]
2019-11-26 09:32:07,141 [salt.state       :300 ][INFO    ][10631] All specified packages are already installed
2019-11-26 09:32:07,142 [salt.state       :1951][INFO    ][10631] Completed state [python-oauth] at time 09:32:07.142151 duration_in_ms=6.591
2019-11-26 09:32:07,145 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/regiond.conf] at time 09:32:07.145249
2019-11-26 09:32:07,145 [salt.state       :1813][INFO    ][10631] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-26 09:32:07,199 [salt.state       :300 ][INFO    ][10631] No changes needed to be made
2019-11-26 09:32:07,200 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/regiond.conf] at time 09:32:07.199996 duration_in_ms=54.747
2019-11-26 09:32:07,200 [salt.state       :1780][INFO    ][10631] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:32:07.200637
2019-11-26 09:32:07,201 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-26 09:32:07,270 [salt.state       :300 ][INFO    ][10631] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-26 09:32:07,270 [salt.state       :1951][INFO    ][10631] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:32:07.270844 duration_in_ms=70.206
2019-11-26 09:32:07,271 [salt.state       :1780][INFO    ][10631] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:32:07.271387
2019-11-26 09:32:07,271 [salt.state       :1813][INFO    ][10631] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-26 09:32:07,290 [salt.state       :300 ][INFO    ][10631] No changes needed to be made
2019-11-26 09:32:07,290 [salt.state       :1951][INFO    ][10631] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:32:07.290261 duration_in_ms=18.873
2019-11-26 09:32:07,290 [salt.state       :1780][INFO    ][10631] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:32:07.290805
2019-11-26 09:32:07,291 [salt.state       :1813][INFO    ][10631] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-26 09:32:07,320 [salt.state       :300 ][INFO    ][10631] No changes needed to be made
2019-11-26 09:32:07,320 [salt.state       :1951][INFO    ][10631] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:32:07.320343 duration_in_ms=29.537
2019-11-26 09:32:07,320 [salt.state       :1780][INFO    ][10631] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:32:07.320895
2019-11-26 09:32:07,321 [salt.state       :1813][INFO    ][10631] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-26 09:32:07,346 [salt.state       :300 ][INFO    ][10631] No changes needed to be made
2019-11-26 09:32:07,347 [salt.state       :1951][INFO    ][10631] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:32:07.347126 duration_in_ms=26.232
2019-11-26 09:32:07,347 [salt.state       :1780][INFO    ][10631] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:32:07.347629
2019-11-26 09:32:07,347 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-26 09:32:07,360 [salt.state       :300 ][INFO    ][10631] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-26 09:32:07,360 [salt.state       :1951][INFO    ][10631] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:32:07.360239 duration_in_ms=12.61
2019-11-26 09:32:07,361 [salt.state       :1780][INFO    ][10631] Running state [a2enmod headers] at time 09:32:07.361427
2019-11-26 09:32:07,365 [salt.state       :1813][INFO    ][10631] Executing state cmd.run for [a2enmod headers]
2019-11-26 09:32:07,366 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command 'a2enmod headers' in directory '/root'
2019-11-26 09:32:07,439 [salt.state       :300 ][INFO    ][10631] {'pid': 10650, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-26 09:32:07,440 [salt.state       :1951][INFO    ][10631] Completed state [a2enmod headers] at time 09:32:07.440132 duration_in_ms=78.705
2019-11-26 09:32:07,440 [salt.state       :1780][INFO    ][10631] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:32:07.440623
2019-11-26 09:32:07,441 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-26 09:32:07,456 [salt.state       :300 ][INFO    ][10631] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-26 09:32:07,456 [salt.state       :1951][INFO    ][10631] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:32:07.456865 duration_in_ms=16.242
2019-11-26 09:32:07,457 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:32:07.457442
2019-11-26 09:32:07,457 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-26 09:32:07,522 [salt.state       :300 ][INFO    ][10631] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-26 09:32:07,522 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:32:07.522416 duration_in_ms=64.974
2019-11-26 09:32:07,522 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:32:07.522883
2019-11-26 09:32:07,523 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-26 09:32:07,576 [salt.state       :300 ][INFO    ][10631] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-26 09:32:07,576 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:32:07.576219 duration_in_ms=53.336
2019-11-26 09:32:07,576 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:32:07.576655
2019-11-26 09:32:07,576 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-26 09:32:07,641 [salt.state       :300 ][INFO    ][10631] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-26 09:32:07,641 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:32:07.641815 duration_in_ms=65.16
2019-11-26 09:32:07,642 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 09:32:07.642215
2019-11-26 09:32:07,642 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-11-26 09:32:07,695 [salt.state       :300 ][INFO    ][10631] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-11-26 09:32:07,695 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 09:32:07.695873 duration_in_ms=53.658
2019-11-26 09:32:07,696 [salt.state       :1780][INFO    ][10631] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 09:32:07.696278
2019-11-26 09:32:07,696 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-11-26 09:32:07,743 [salt.state       :300 ][INFO    ][10631] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-11-26 09:32:07,743 [salt.state       :1951][INFO    ][10631] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 09:32:07.743468 duration_in_ms=47.19
2019-11-26 09:32:07,743 [salt.state       :1780][INFO    ][10631] Running state [/root/.pgpass] at time 09:32:07.743727
2019-11-26 09:32:07,743 [salt.state       :1813][INFO    ][10631] Executing state file.managed for [/root/.pgpass]
2019-11-26 09:32:07,785 [salt.state       :300 ][INFO    ][10631] File /root/.pgpass is in the correct state
2019-11-26 09:32:07,785 [salt.state       :1951][INFO    ][10631] Completed state [/root/.pgpass] at time 09:32:07.785423 duration_in_ms=41.696
2019-11-26 09:32:07,789 [salt.state       :1780][INFO    ][10631] Running state [maas-region syncdb --noinput] at time 09:32:07.789229
2019-11-26 09:32:07,789 [salt.state       :1813][INFO    ][10631] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-26 09:32:07,790 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-26 09:32:09,674 [salt.state       :300 ][INFO    ][10631] {'pid': 10667, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, metadataserver, auth, contenttypes, maasserver, sites, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-26 09:32:09,675 [salt.state       :1951][INFO    ][10631] Completed state [maas-region syncdb --noinput] at time 09:32:09.675207 duration_in_ms=1885.977
2019-11-26 09:32:09,675 [salt.state       :2022][WARNING ][10631] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-26 09:32:09,676 [salt.state       :1780][INFO    ][10631] Running state [maas-regiond] at time 09:32:09.676442
2019-11-26 09:32:09,676 [salt.state       :1813][INFO    ][10631] Executing state service.running for [maas-regiond]
2019-11-26 09:32:09,677 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:09,714 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-26 09:32:09,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-26 09:32:09,746 [salt.state       :300 ][INFO    ][10631] The service maas-regiond is already running
2019-11-26 09:32:09,746 [salt.state       :1951][INFO    ][10631] Completed state [maas-regiond] at time 09:32:09.746288 duration_in_ms=69.846
2019-11-26 09:32:09,747 [salt.state       :1780][INFO    ][10631] Running state [bind9] at time 09:32:09.747308
2019-11-26 09:32:09,747 [salt.state       :1813][INFO    ][10631] Executing state service.running for [bind9]
2019-11-26 09:32:09,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:09,764 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-26 09:32:09,779 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-26 09:32:09,794 [salt.state       :300 ][INFO    ][10631] The service bind9 is already running
2019-11-26 09:32:09,795 [salt.state       :1951][INFO    ][10631] Completed state [bind9] at time 09:32:09.794983 duration_in_ms=47.675
2019-11-26 09:32:09,796 [salt.state       :1780][INFO    ][10631] Running state [apache2] at time 09:32:09.795980
2019-11-26 09:32:09,796 [salt.state       :1813][INFO    ][10631] Executing state service.running for [apache2]
2019-11-26 09:32:09,796 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-26 09:32:09,813 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-26 09:32:09,828 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-26 09:32:09,847 [salt.state       :300 ][INFO    ][10631] The service apache2 is already running
2019-11-26 09:32:09,847 [salt.state       :1951][INFO    ][10631] Completed state [apache2] at time 09:32:09.847624 duration_in_ms=51.643
2019-11-26 09:32:09,848 [salt.state       :1780][INFO    ][10631] Running state [maasng.wait_for_http_code] at time 09:32:09.848565
2019-11-26 09:32:09,848 [salt.state       :1813][INFO    ][10631] Executing state module.run for [maasng.wait_for_http_code]
2019-11-26 09:32:09,849 [salt.utils.decorators:613 ][WARNING ][10631] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:32:09,855 [salt.state       :300 ][INFO    ][10631] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-26 09:32:09,856 [salt.state       :1951][INFO    ][10631] Completed state [maasng.wait_for_http_code] at time 09:32:09.855991 duration_in_ms=7.425
2019-11-26 09:32:09,857 [salt.state       :1780][INFO    ][10631] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:32:09.857388
2019-11-26 09:32:09,857 [salt.state       :1813][INFO    ][10631] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-26 09:32:09,858 [salt.state       :300 ][INFO    ][10631] /var/lib/maas/.setup_admin exists
2019-11-26 09:32:09,859 [salt.state       :1951][INFO    ][10631] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:32:09.859012 duration_in_ms=1.624
2019-11-26 09:32:09,860 [salt.state       :1780][INFO    ][10631] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:09.860192
2019-11-26 09:32:09,860 [salt.state       :1813][INFO    ][10631] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:32:09,861 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10631] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:32:11,316 [salt.state       :300 ][INFO    ][10631] {'pid': 10686, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:32:11,317 [salt.state       :1951][INFO    ][10631] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:11.317284 duration_in_ms=1457.093
2019-11-26 09:32:11,322 [salt.state       :1780][INFO    ][10631] Running state [maas_region_boot_source_resources_mirror] at time 09:32:11.322571
2019-11-26 09:32:11,322 [salt.state       :1813][INFO    ][10631] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-26 09:32:11,426 [salt.state       :300 ][INFO    ][10631] {'changes': {}}
2019-11-26 09:32:11,427 [salt.state       :1951][INFO    ][10631] Completed state [maas_region_boot_source_resources_mirror] at time 09:32:11.427073 duration_in_ms=104.5
2019-11-26 09:32:11,428 [salt.state       :1780][INFO    ][10631] Running state [maasng.boot_resources_import] at time 09:32:11.428247
2019-11-26 09:32:11,428 [salt.state       :1813][INFO    ][10631] Executing state module.run for [maasng.boot_resources_import]
2019-11-26 09:32:11,429 [salt.utils.decorators:613 ][WARNING ][10631] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:32:11,535 [salt.loaded.ext.module.maasng:1600][INFO    ][10631] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-26 09:32:16,612 [salt.loaded.ext.module.maasng:1600][INFO    ][10631] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-26 09:32:20,636 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093220622426
2019-11-26 09:32:20,658 [salt.minion      :1432][INFO    ][10738] Starting a new job with PID 10738
2019-11-26 09:32:20,684 [salt.minion      :1711][INFO    ][10738] Returning information for job: 20191126093220622426
2019-11-26 09:32:21,668 [salt.loaded.ext.module.maasng:1600][INFO    ][10631] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-26 09:32:26,777 [salt.state       :300 ][INFO    ][10631] {'ret': True}
2019-11-26 09:32:26,777 [salt.state       :1951][INFO    ][10631] Completed state [maasng.boot_resources_import] at time 09:32:26.777564 duration_in_ms=15349.316
2019-11-26 09:32:26,778 [salt.state       :1780][INFO    ][10631] Running state [maas_region_boot_sources_selection_bionic] at time 09:32:26.778737
2019-11-26 09:32:26,779 [salt.state       :1813][INFO    ][10631] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-11-26 09:32:26,968 [salt.state       :300 ][INFO    ][10631] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-26 09:32:26,968 [salt.state       :1951][INFO    ][10631] Completed state [maas_region_boot_sources_selection_bionic] at time 09:32:26.968818 duration_in_ms=190.08
2019-11-26 09:32:26,970 [salt.state       :1780][INFO    ][10631] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 09:32:26.970170
2019-11-26 09:32:26,970 [salt.state       :1813][INFO    ][10631] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-26 09:32:26,971 [salt.utils.decorators:613 ][WARNING ][10631] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:32:26,971 [salt.loaded.ext.module.maasng:1771][INFO    ][10631] boot-sources sync initiated for ALL Rack's
2019-11-26 09:32:27,860 [salt.state       :300 ][INFO    ][10631] {'ret': True}
2019-11-26 09:32:27,861 [salt.state       :1951][INFO    ][10631] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 09:32:27.861339 duration_in_ms=891.167
2019-11-26 09:32:27,863 [salt.state       :1780][INFO    ][10631] Running state [maas.process_maas_config] at time 09:32:27.863587
2019-11-26 09:32:27,864 [salt.state       :1813][INFO    ][10631] Executing state module.run for [maas.process_maas_config]
2019-11-26 09:32:27,864 [salt.utils.decorators:613 ][WARNING ][10631] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:32:27,865 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=enable_http_proxy value=True
2019-11-26 09:32:27,943 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=upstream_dns value=8.8.8.8
2019-11-26 09:32:30,992 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=commissioning_distro_series value=bionic
2019-11-26 09:32:31,073 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=default_osystem value=ubuntu
2019-11-26 09:32:31,160 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=active_discovery_interval value=600
2019-11-26 09:32:31,227 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=dnssec_validation value=no
2019-11-26 09:32:31,280 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=maas_name value=mas01
2019-11-26 09:32:31,327 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=network_discovery value=enabled
2019-11-26 09:32:31,469 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=enable_third_party_drivers value=True
2019-11-26 09:32:31,526 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=default_storage_layout value=lvm
2019-11-26 09:32:31,585 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=ntp_external_only value=True
2019-11-26 09:32:31,646 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-26 09:32:31,720 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=default_distro_series value=bionic
2019-11-26 09:32:31,780 [salt.loaded.ext.module.maas:92  ][INFO    ][10631] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-11-26 09:32:31,870 [salt.state       :300 ][INFO    ][10631] {'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-11-26 09:32:31,870 [salt.state       :1951][INFO    ][10631] Completed state [maas.process_maas_config] at time 09:32:31.870703 duration_in_ms=4007.115
2019-11-26 09:32:31,871 [salt.state       :1780][INFO    ][10631] Running state [pxe_admin] at time 09:32:31.871670
2019-11-26 09:32:31,872 [salt.state       :1813][INFO    ][10631] Executing state maasng.fabric_present for [pxe_admin]
2019-11-26 09:32:31,934 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-26 09:32:32,000 [salt.loaded.ext.module.maasng:1008][WARNING ][10631] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-26 09:32:32,001 [salt.loaded.ext.module.maasng:1011][WARNING ][10631] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-26 09:32:32,073 [salt.state       :300 ][INFO    ][10631] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-26 09:32:32,073 [salt.state       :1951][INFO    ][10631] Completed state [pxe_admin] at time 09:32:32.073378 duration_in_ms=201.709
2019-11-26 09:32:32,073 [salt.state       :1780][INFO    ][10631] Running state [vlan 0] at time 09:32:32.073686
2019-11-26 09:32:32,074 [salt.state       :1813][INFO    ][10631] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-26 09:32:32,138 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-26 09:32:32,273 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-26 09:32:32,567 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-26 09:32:32,682 [salt.state       :300 ][INFO    ][10631] {'new': 'Vlan untagged was updated'}
2019-11-26 09:32:32,682 [salt.state       :1951][INFO    ][10631] Completed state [vlan 0] at time 09:32:32.682820 duration_in_ms=609.132
2019-11-26 09:32:32,684 [salt.state       :1780][INFO    ][10631] Running state [192.168.11.0/24] at time 09:32:32.684612
2019-11-26 09:32:32,685 [salt.state       :1813][INFO    ][10631] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-26 09:32:32,887 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-26 09:32:32,888 [salt.loaded.ext.module.maasng:1235][WARNING ][10631] Ignoring parameter vlan:0
2019-11-26 09:32:32,966 [salt.state       :300 ][INFO    ][10631] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-26 09:32:32,966 [salt.state       :1951][INFO    ][10631] Completed state [192.168.11.0/24] at time 09:32:32.966400 duration_in_ms=281.787
2019-11-26 09:32:32,967 [salt.state       :1780][INFO    ][10631] Running state [maas_create_iprange_1] at time 09:32:32.967844
2019-11-26 09:32:32,968 [salt.state       :1813][INFO    ][10631] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-26 09:32:33,013 [salt.state       :300 ][INFO    ][10631] Iprange maas_create_iprange_1 already exist.
2019-11-26 09:32:33,013 [salt.state       :1951][INFO    ][10631] Completed state [maas_create_iprange_1] at time 09:32:33.013438 duration_in_ms=45.594
2019-11-26 09:32:33,013 [salt.state       :1780][INFO    ][10631] Running state [vlan 0] at time 09:32:33.013873
2019-11-26 09:32:33,014 [salt.state       :1813][INFO    ][10631] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-26 09:32:33,067 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-26 09:32:33,186 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'w4c7c6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-26 09:32:33,448 [salt.loaded.ext.module.maasng:945 ][INFO    ][10631] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'w4c7c6', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-26 09:32:33,538 [salt.state       :300 ][INFO    ][10631] {'new': 'Vlan untagged was updated'}
2019-11-26 09:32:33,538 [salt.state       :1951][INFO    ][10631] Completed state [vlan 0] at time 09:32:33.538457 duration_in_ms=524.584
2019-11-26 09:32:33,539 [salt.state       :1780][INFO    ][10631] Running state [opnfv] at time 09:32:33.539148
2019-11-26 09:32:33,539 [salt.state       :1813][INFO    ][10631] Executing state maasng.sshkey_present for [opnfv]
2019-11-26 09:32:33,579 [salt.loaded.ext.module.maasng:1903][INFO    ][10631] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-11-26 09:32:33,579 [salt.state       :300 ][INFO    ][10631] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-26 09:32:33,580 [salt.state       :1951][INFO    ][10631] Completed state [opnfv] at time 09:32:33.580263 duration_in_ms=41.115
2019-11-26 09:32:33,583 [salt.minion      :1711][INFO    ][10631] Returning information for job: 20191126093205546768
2019-11-26 09:32:34,198 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126093234190903
2019-11-26 09:32:34,214 [salt.minion      :1432][INFO    ][11002] Starting a new job with PID 11002
2019-11-26 09:32:37,954 [salt.state       :915 ][INFO    ][11002] Loading fresh modules for state activity
2019-11-26 09:32:38,052 [salt.state       :1780][INFO    ][11002] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:38.051936
2019-11-26 09:32:38,052 [salt.state       :1813][INFO    ][11002] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:32:38,054 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11002] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:32:39,536 [salt.state       :300 ][INFO    ][11002] {'pid': 11030, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:32:39,536 [salt.state       :1951][INFO    ][11002] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:39.536469 duration_in_ms=1484.534
2019-11-26 09:32:39,537 [salt.state       :1780][INFO    ][11002] Running state [maas.process_machines] at time 09:32:39.537692
2019-11-26 09:32:39,537 [salt.state       :1813][INFO    ][11002] Executing state module.run for [maas.process_machines]
2019-11-26 09:32:39,538 [salt.utils.decorators:613 ][WARNING ][11002] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:32:40,211 [salt.loaded.ext.module.maas:412 ][WARNING ][11002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:32:40,212 [salt.loaded.ext.module.maas:92  ][INFO    ][11002] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=h7ff4m architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:32:41,248 [salt.loaded.ext.module.maas:412 ][WARNING ][11002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:32:41,249 [salt.loaded.ext.module.maas:92  ][INFO    ][11002] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=86g44c architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:32:42,427 [salt.loaded.ext.module.maas:412 ][WARNING ][11002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:32:42,428 [salt.loaded.ext.module.maas:92  ][INFO    ][11002] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=mwhpxd architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:32:43,655 [salt.loaded.ext.module.maas:412 ][WARNING ][11002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:32:43,656 [salt.loaded.ext.module.maas:92  ][INFO    ][11002] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=8acy4f architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:32:44,733 [salt.loaded.ext.module.maas:412 ][WARNING ][11002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-26 09:32:44,734 [salt.loaded.ext.module.maas:92  ][INFO    ][11002] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=asarmx architecture=amd64/generic power_parameters_power_user=admin
2019-11-26 09:32:45,895 [salt.state       :300 ][INFO    ][11002] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-26 09:32:45,896 [salt.state       :1951][INFO    ][11002] Completed state [maas.process_machines] at time 09:32:45.896131 duration_in_ms=6358.438
2019-11-26 09:32:45,900 [salt.minion      :1711][INFO    ][11002] Returning information for job: 20191126093234190903
2019-11-26 09:33:19,252 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126093319239771
2019-11-26 09:33:19,274 [salt.minion      :1432][INFO    ][11303] Starting a new job with PID 11303
2019-11-26 09:33:22,964 [salt.state       :915 ][INFO    ][11303] Loading fresh modules for state activity
2019-11-26 09:33:23,057 [salt.state       :1780][INFO    ][11303] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:33:23.056989
2019-11-26 09:33:23,057 [salt.state       :1813][INFO    ][11303] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:33:23,059 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11303] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:33:24,523 [salt.state       :300 ][INFO    ][11303] {'pid': 11310, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:33:24,523 [salt.state       :1951][INFO    ][11303] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:33:24.523466 duration_in_ms=1466.477
2019-11-26 09:33:24,524 [salt.state       :1780][INFO    ][11303] Running state [maas.wait_for_machine_status] at time 09:33:24.524694
2019-11-26 09:33:24,524 [salt.state       :1813][INFO    ][11303] Executing state module.run for [maas.wait_for_machine_status]
2019-11-26 09:33:24,525 [salt.utils.decorators:613 ][WARNING ][11303] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:33:27,916 [salt.loaded.ext.module.maas:993 ][INFO    ][11303] Machine asarmx mark broken
2019-11-26 09:33:28,230 [salt.loaded.ext.module.maas:996 ][INFO    ][11303] Machine asarmx mark fixed
2019-11-26 09:33:28,977 [salt.loaded.ext.module.maas:684 ][INFO    ][11303] deploymachines hwe_kernel=ga-18.04 system_id=asarmx distro_series=bionic
2019-11-26 09:33:31,427 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1493.10318708s left)
2019-11-26 09:33:34,393 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093334340763
2019-11-26 09:33:34,415 [salt.minion      :1432][INFO    ][11377] Starting a new job with PID 11377
2019-11-26 09:33:34,440 [salt.minion      :1711][INFO    ][11377] Returning information for job: 20191126093334340763
2019-11-26 09:34:04,444 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093404431331
2019-11-26 09:34:04,465 [salt.minion      :1432][INFO    ][11421] Starting a new job with PID 11421
2019-11-26 09:34:04,490 [salt.minion      :1711][INFO    ][11421] Returning information for job: 20191126093404431331
2019-11-26 09:34:04,772 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1459.75773501s left)
2019-11-26 09:34:34,530 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093434516980
2019-11-26 09:34:34,553 [salt.minion      :1432][INFO    ][11449] Starting a new job with PID 11449
2019-11-26 09:34:34,579 [salt.minion      :1711][INFO    ][11449] Returning information for job: 20191126093434516980
2019-11-26 09:34:38,384 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1426.14579797s left)
2019-11-26 09:35:04,580 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093504568410
2019-11-26 09:35:04,603 [salt.minion      :1432][INFO    ][11495] Starting a new job with PID 11495
2019-11-26 09:35:04,629 [salt.minion      :1711][INFO    ][11495] Returning information for job: 20191126093504568410
2019-11-26 09:35:11,402 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1393.12787104s left)
2019-11-26 09:35:34,636 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093534624545
2019-11-26 09:35:34,657 [salt.minion      :1432][INFO    ][11589] Starting a new job with PID 11589
2019-11-26 09:35:34,681 [salt.minion      :1711][INFO    ][11589] Returning information for job: 20191126093534624545
2019-11-26 09:35:45,012 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.51734805s left)
2019-11-26 09:36:04,689 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093604676176
2019-11-26 09:36:04,711 [salt.minion      :1432][INFO    ][11724] Starting a new job with PID 11724
2019-11-26 09:36:04,737 [salt.minion      :1711][INFO    ][11724] Returning information for job: 20191126093604676176
2019-11-26 09:36:18,484 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1326.045784s left)
2019-11-26 09:36:34,752 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093634736734
2019-11-26 09:36:34,774 [salt.minion      :1432][INFO    ][11802] Starting a new job with PID 11802
2019-11-26 09:36:34,801 [salt.minion      :1711][INFO    ][11802] Returning information for job: 20191126093634736734
2019-11-26 09:36:51,501 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1293.029037s left)
2019-11-26 09:37:04,814 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093704801133
2019-11-26 09:37:04,836 [salt.minion      :1432][INFO    ][11877] Starting a new job with PID 11877
2019-11-26 09:37:04,862 [salt.minion      :1711][INFO    ][11877] Returning information for job: 20191126093704801133
2019-11-26 09:37:25,062 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1259.4678371s left)
2019-11-26 09:37:34,885 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093734872109
2019-11-26 09:37:34,907 [salt.minion      :1432][INFO    ][11917] Starting a new job with PID 11917
2019-11-26 09:37:34,934 [salt.minion      :1711][INFO    ][11917] Returning information for job: 20191126093734872109
2019-11-26 09:37:58,667 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1225.86321497s left)
2019-11-26 09:38:04,958 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093804945046
2019-11-26 09:38:04,980 [salt.minion      :1432][INFO    ][12010] Starting a new job with PID 12010
2019-11-26 09:38:05,005 [salt.minion      :1711][INFO    ][12010] Returning information for job: 20191126093804945046
2019-11-26 09:38:32,341 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1192.18854403s left)
2019-11-26 09:38:35,030 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093835017395
2019-11-26 09:38:35,053 [salt.minion      :1432][INFO    ][12058] Starting a new job with PID 12058
2019-11-26 09:38:35,079 [salt.minion      :1711][INFO    ][12058] Returning information for job: 20191126093835017395
2019-11-26 09:39:05,108 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093905095951
2019-11-26 09:39:05,130 [salt.minion      :1432][INFO    ][12179] Starting a new job with PID 12179
2019-11-26 09:39:05,157 [salt.minion      :1711][INFO    ][12179] Returning information for job: 20191126093905095951
2019-11-26 09:39:06,060 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1158.46985197s left)
2019-11-26 09:39:35,191 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126093935178215
2019-11-26 09:39:35,214 [salt.minion      :1432][INFO    ][12231] Starting a new job with PID 12231
2019-11-26 09:39:35,242 [salt.minion      :1711][INFO    ][12231] Returning information for job: 20191126093935178215
2019-11-26 09:39:39,800 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.73000097s left)
2019-11-26 09:40:05,289 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126094005275354
2019-11-26 09:40:05,312 [salt.minion      :1432][INFO    ][12288] Starting a new job with PID 12288
2019-11-26 09:40:05,338 [salt.minion      :1711][INFO    ][12288] Returning information for job: 20191126094005275354
2019-11-26 09:40:13,349 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1091.18091917s left)
2019-11-26 09:40:35,388 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126094035375500
2019-11-26 09:40:35,411 [salt.minion      :1432][INFO    ][12345] Starting a new job with PID 12345
2019-11-26 09:40:35,436 [salt.minion      :1711][INFO    ][12345] Returning information for job: 20191126094035375500
2019-11-26 09:40:46,845 [salt.loaded.ext.module.maas:1023][INFO    ][11303] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1057.68506217s left)
2019-11-26 09:41:05,567 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command saltutil.find_job with jid 20191126094105555331
2019-11-26 09:41:05,590 [salt.minion      :1432][INFO    ][12406] Starting a new job with PID 12406
2019-11-26 09:41:05,616 [salt.minion      :1711][INFO    ][12406] Returning information for job: 20191126094105555331
2019-11-26 09:41:20,627 [salt.state       :300 ][INFO    ][11303] {'ret': True}
2019-11-26 09:41:20,628 [salt.state       :1951][INFO    ][11303] Completed state [maas.wait_for_machine_status] at time 09:41:20.627918 duration_in_ms=476103.22
2019-11-26 09:41:20,632 [salt.minion      :1711][INFO    ][11303] Returning information for job: 20191126093319239771
2019-11-26 09:41:21,283 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126094121270103
2019-11-26 09:41:21,305 [salt.minion      :1432][INFO    ][12474] Starting a new job with PID 12474
2019-11-26 09:41:25,278 [salt.state       :915 ][INFO    ][12474] Loading fresh modules for state activity
2019-11-26 09:41:25,414 [salt.state       :1780][INFO    ][12474] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:25.414528
2019-11-26 09:41:25,414 [salt.state       :1813][INFO    ][12474] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:41:25,416 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12474] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:41:26,819 [salt.state       :300 ][INFO    ][12474] {'pid': 12487, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:41:26,820 [salt.state       :1951][INFO    ][12474] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:26.820056 duration_in_ms=1405.527
2019-11-26 09:41:26,823 [salt.state       :1780][INFO    ][12474] Running state [maas_machines_storage_cmp002_lvm] at time 09:41:26.823358
2019-11-26 09:41:26,823 [salt.state       :1813][INFO    ][12474] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-26 09:41:27,535 [salt.state       :300 ][INFO    ][12474] Machine cmp002 is not in Ready state.
2019-11-26 09:41:27,536 [salt.state       :1951][INFO    ][12474] Completed state [maas_machines_storage_cmp002_lvm] at time 09:41:27.535961 duration_in_ms=712.604
2019-11-26 09:41:27,536 [salt.state       :1780][INFO    ][12474] Running state [maas_machines_storage_cmp001_lvm] at time 09:41:27.536307
2019-11-26 09:41:27,536 [salt.state       :1813][INFO    ][12474] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-26 09:41:28,285 [salt.state       :300 ][INFO    ][12474] Machine cmp001 is not in Ready state.
2019-11-26 09:41:28,286 [salt.state       :1951][INFO    ][12474] Completed state [maas_machines_storage_cmp001_lvm] at time 09:41:28.286315 duration_in_ms=750.006
2019-11-26 09:41:28,290 [salt.minion      :1711][INFO    ][12474] Returning information for job: 20191126094121270103
2019-11-26 09:41:28,914 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126094128898890
2019-11-26 09:41:28,938 [salt.minion      :1432][INFO    ][12498] Starting a new job with PID 12498
2019-11-26 09:41:29,729 [salt.state       :915 ][INFO    ][12498] Loading fresh modules for state activity
2019-11-26 09:41:29,819 [salt.state       :1780][INFO    ][12498] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:29.819841
2019-11-26 09:41:29,820 [salt.state       :1813][INFO    ][12498] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:41:29,822 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12498] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:41:31,313 [salt.state       :300 ][INFO    ][12498] {'pid': 12505, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:41:31,314 [salt.state       :1951][INFO    ][12498] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:31.314039 duration_in_ms=1494.198
2019-11-26 09:41:31,315 [salt.state       :1780][INFO    ][12498] Running state [maas.deploy_machines] at time 09:41:31.315264
2019-11-26 09:41:31,315 [salt.state       :1813][INFO    ][12498] Executing state module.run for [maas.deploy_machines]
2019-11-26 09:41:31,316 [salt.utils.decorators:613 ][WARNING ][12498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:41:32,044 [salt.state       :300 ][INFO    ][12498] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-26 09:41:32,044 [salt.state       :1951][INFO    ][12498] Completed state [maas.deploy_machines] at time 09:41:32.044902 duration_in_ms=729.635
2019-11-26 09:41:32,048 [salt.minion      :1711][INFO    ][12498] Returning information for job: 20191126094128898890
2019-11-26 09:41:32,697 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command state.apply with jid 20191126094132680164
2019-11-26 09:41:32,719 [salt.minion      :1432][INFO    ][12514] Starting a new job with PID 12514
2019-11-26 09:41:33,493 [salt.state       :915 ][INFO    ][12514] Loading fresh modules for state activity
2019-11-26 09:41:33,589 [salt.state       :1780][INFO    ][12514] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:33.589696
2019-11-26 09:41:33,590 [salt.state       :1813][INFO    ][12514] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-26 09:41:33,592 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12514] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-26 09:41:35,035 [salt.state       :300 ][INFO    ][12514] {'pid': 12521, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-26 09:41:35,036 [salt.state       :1951][INFO    ][12514] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:35.035991 duration_in_ms=1446.296
2019-11-26 09:41:35,037 [salt.state       :1780][INFO    ][12514] Running state [maas.wait_for_machine_status] at time 09:41:35.037573
2019-11-26 09:41:35,037 [salt.state       :1813][INFO    ][12514] Executing state module.run for [maas.wait_for_machine_status]
2019-11-26 09:41:35,038 [salt.utils.decorators:613 ][WARNING ][12514] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-26 09:41:38,771 [salt.state       :300 ][INFO    ][12514] {'ret': True}
2019-11-26 09:41:38,772 [salt.state       :1951][INFO    ][12514] Completed state [maas.wait_for_machine_status] at time 09:41:38.772091 duration_in_ms=3734.513
2019-11-26 09:41:38,776 [salt.minion      :1711][INFO    ][12514] Returning information for job: 20191126094132680164
2019-11-26 10:07:45,419 [salt.utils.schedule:1377][INFO    ][2988] Running scheduled job: __mine_interval
2019-11-26 11:07:45,419 [salt.utils.schedule:1377][INFO    ][2988] Running scheduled job: __mine_interval
2019-11-26 11:08:26,202 [salt.minion      :1308][INFO    ][2988] User sudo_ubuntu Executing command cp.push_dir with jid 20191126110826188752
2019-11-26 11:08:26,224 [salt.minion      :1432][INFO    ][18560] Starting a new job with PID 18560
