2019-12-11 05:04:19,337 [salt.utils.decorators:613 ][WARNING ][2152] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:04:19,854 [salt.utils.decorators:613 ][WARNING ][2152] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:04:21,746 [salt.loaded.int.states.file:2298][WARNING ][2392] 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-12-11 05:04:47,688 [salt.state       :2022][WARNING ][2993] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-11 05:04:50,292 [salt.utils.decorators:613 ][WARNING ][2993] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:05:22,518 [salt.utils.decorators:613 ][WARNING ][2993] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:06:37,510 [salt.utils.decorators:613 ][WARNING ][2993] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:06:54,396 [salt.utils.decorators:613 ][WARNING ][2993] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:06:59,205 [salt.loaded.ext.module.maasng:1008][WARNING ][2993] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-12-11 05:06:59,205 [salt.loaded.ext.module.maasng:1011][WARNING ][2993] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-12-11 05:07:00,039 [salt.loaded.ext.module.maasng:1235][WARNING ][2993] Ignoring parameter vlan:0
2019-12-11 05:07:01,005 [salt.utils.decorators:613 ][WARNING ][2993] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:07:06,812 [salt.utils.decorators:613 ][WARNING ][7693] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:07:06,859 [salt.loaded.ext.module.maas:412 ][WARNING ][7693] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:07:08,124 [salt.loaded.ext.module.maas:412 ][WARNING ][7693] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:07:09,807 [salt.loaded.ext.module.maas:412 ][WARNING ][7693] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:07:11,012 [salt.loaded.ext.module.maas:412 ][WARNING ][7693] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:07:12,437 [salt.loaded.ext.module.maas:412 ][WARNING ][7693] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:07:16,584 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8322] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-11 05:07:16,617 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8322] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-12-11 05:07:16,639 [salt.utils.parsers:1051][WARNING ][322] Minion received a SIGTERM. Exiting.
2019-12-11 05:07:17,679 [salt.cli.daemons :293 ][INFO    ][8375] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-12-11 05:07:17,780 [salt.cli.daemons :82  ][INFO    ][8375] Starting up the Salt Minion
2019-12-11 05:07:17,781 [salt.utils.event :1017][INFO    ][8375] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-12-11 05:07:18,701 [salt.minion      :976 ][INFO    ][8375] Creating minion process manager
2019-12-11 05:07:20,177 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][8375] Executing command ['date', '+%z'] in directory '/root'
2019-12-11 05:07:20,196 [salt.utils.schedule:568 ][INFO    ][8375] Updating job settings for scheduled job: __mine_interval
2019-12-11 05:07:20,197 [salt.minion      :1108][INFO    ][8375] Added mine.update to scheduler
2019-12-11 05:07:20,201 [salt.minion      :1975][INFO    ][8375] Minion is starting as user 'root'
2019-12-11 05:07:20,215 [salt.minion      :2336][INFO    ][8375] Minion is ready to receive requests!
2019-12-11 05:07:44,748 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211050744733989
2019-12-11 05:07:44,769 [salt.minion      :1432][INFO    ][8491] Starting a new job with PID 8491
2019-12-11 05:07:48,428 [salt.state       :915 ][INFO    ][8491] Loading fresh modules for state activity
2019-12-11 05:07:48,480 [salt.fileclient  :1219][INFO    ][8491] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-12-11 05:07:48,524 [salt.state       :1780][INFO    ][8491] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:07:48.524332
2019-12-11 05:07:48,524 [salt.state       :1813][INFO    ][8491] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:07:48,526 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8491] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:07:49,999 [salt.state       :300 ][INFO    ][8491] {'pid': 8498, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:07:50,000 [salt.state       :1951][INFO    ][8491] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:07:50.000759 duration_in_ms=1476.426
2019-12-11 05:07:50,004 [salt.state       :1780][INFO    ][8491] Running state [maas.wait_for_machine_status] at time 05:07:50.003941
2019-12-11 05:07:50,004 [salt.state       :1813][INFO    ][8491] Executing state module.run for [maas.wait_for_machine_status]
2019-12-11 05:07:50,005 [salt.utils.decorators:613 ][WARNING ][8491] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:07:50,968 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.04648304s left)
2019-12-11 05:07:59,821 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211050759808824
2019-12-11 05:07:59,840 [salt.minion      :1432][INFO    ][8526] Starting a new job with PID 8526
2019-12-11 05:07:59,862 [salt.minion      :1711][INFO    ][8526] Returning information for job: 20191211050759808824
2019-12-11 05:08:21,953 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.06170106s left)
2019-12-11 05:08:29,858 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211050829845402
2019-12-11 05:08:29,881 [salt.minion      :1432][INFO    ][8562] Starting a new job with PID 8562
2019-12-11 05:08:29,905 [salt.minion      :1711][INFO    ][8562] Returning information for job: 20191211050829845402
2019-12-11 05:08:52,841 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.17363501s left)
2019-12-11 05:08:59,923 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211050859912401
2019-12-11 05:08:59,942 [salt.minion      :1432][INFO    ][8696] Starting a new job with PID 8696
2019-12-11 05:08:59,965 [salt.minion      :1711][INFO    ][8696] Returning information for job: 20191211050859912401
2019-12-11 05:09:24,330 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.68437004s left)
2019-12-11 05:09:29,968 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211050929956194
2019-12-11 05:09:29,990 [salt.minion      :1432][INFO    ][9020] Starting a new job with PID 9020
2019-12-11 05:09:30,015 [salt.minion      :1711][INFO    ][9020] Returning information for job: 20191211050929956194
2019-12-11 05:09:56,063 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.95218801s left)
2019-12-11 05:10:00,037 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051000024232
2019-12-11 05:10:00,059 [salt.minion      :1432][INFO    ][9592] Starting a new job with PID 9592
2019-12-11 05:10:00,082 [salt.minion      :1711][INFO    ][9592] Returning information for job: 20191211051000024232
2019-12-11 05:10:27,849 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.16613102s left)
2019-12-11 05:10:30,093 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051030076362
2019-12-11 05:10:30,115 [salt.minion      :1432][INFO    ][9647] Starting a new job with PID 9647
2019-12-11 05:10:30,139 [salt.minion      :1711][INFO    ][9647] Returning information for job: 20191211051030076362
2019-12-11 05:11:00,165 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051100148728
2019-12-11 05:11:00,187 [salt.minion      :1432][INFO    ][9858] Starting a new job with PID 9858
2019-12-11 05:11:00,209 [salt.minion      :1711][INFO    ][9858] Returning information for job: 20191211051100148728
2019-12-11 05:11:01,316 [salt.loaded.ext.module.maas:1023][INFO    ][8491] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1308.69841003s left)
2019-12-11 05:11:30,227 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051130211365
2019-12-11 05:11:30,249 [salt.minion      :1432][INFO    ][9940] Starting a new job with PID 9940
2019-12-11 05:11:30,272 [salt.minion      :1711][INFO    ][9940] Returning information for job: 20191211051130211365
2019-12-11 05:11:34,894 [salt.state       :300 ][INFO    ][8491] {'ret': True}
2019-12-11 05:11:34,895 [salt.state       :1951][INFO    ][8491] Completed state [maas.wait_for_machine_status] at time 05:11:34.895254 duration_in_ms=224891.311
2019-12-11 05:11:34,899 [salt.minion      :1711][INFO    ][8491] Returning information for job: 20191211050744733989
2019-12-11 05:11:35,497 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211051135480707
2019-12-11 05:11:35,519 [salt.minion      :1432][INFO    ][9983] Starting a new job with PID 9983
2019-12-11 05:11:39,347 [salt.state       :915 ][INFO    ][9983] Loading fresh modules for state activity
2019-12-11 05:11:39,397 [salt.fileclient  :1219][INFO    ][9983] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-12-11 05:11:39,484 [salt.state       :1780][INFO    ][9983] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:39.484553
2019-12-11 05:11:39,484 [salt.state       :1813][INFO    ][9983] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:11:39,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9983] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:11:40,957 [salt.state       :300 ][INFO    ][9983] {'pid': 9999, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:11:40,958 [salt.state       :1951][INFO    ][9983] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:40.958660 duration_in_ms=1474.106
2019-12-11 05:11:40,962 [salt.state       :1780][INFO    ][9983] Running state [maas_machines_storage_cmp002_lvm] at time 05:11:40.961973
2019-12-11 05:11:40,962 [salt.state       :1813][INFO    ][9983] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-11 05:11:42,391 [salt.loaded.ext.module.maasng:610 ][INFO    ][9983] a8payb
2019-12-11 05:11:42,391 [salt.loaded.ext.module.maasng:626 ][INFO    ][9983] sda
2019-12-11 05:11:43,099 [salt.loaded.ext.module.maasng:361 ][INFO    ][9983] a8payb
2019-12-11 05:11:43,213 [salt.loaded.ext.module.maasng:367 ][INFO    ][9983] [{u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/', u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'tags': [u'rotary'], u'uuid': None, u'id': 4, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'a8payb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'913de98c-c6f7-4999-a615-bb6f0919af5b', u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/partition/4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'a8payb', u'filesystem': {u'uuid': u'73f5bbfe-8bc8-4f7e-ac88-b9613120c371', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 4, u'device_id': 4}], u'type': u'physical', u'model': u'UCSB-MRAID12G', u'size': 2397998940160}, {u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/9/', u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'tags': [], u'uuid': u'1e4b56f0-8587-4476-adf8-3810f9cffb84', u'id': 9, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'a8payb', u'partition_table_type': None, u'filesystem': {u'uuid': u'1ab50d1c-8870-43d2-bccb-179c506daf94', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'model': None, u'size': 2397988454400}]
2019-12-11 05:11:43,214 [salt.loaded.ext.module.maasng:632 ][INFO    ][9983] vgroot
2019-12-11 05:11:43,215 [salt.loaded.ext.module.maasng:635 ][INFO    ][9983] lvroot
2019-12-11 05:11:43,215 [salt.loaded.ext.module.maasng:639 ][INFO    ][9983] 107374182400
2019-12-11 05:11:43,820 [salt.loaded.ext.module.maasng:645 ][INFO    ][9983] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.41'], u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 30}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'children': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'a8payb', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/interfaces/4/'}, u'min_hwe_kernel': u'ga-18.04', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'fqdn': u'cmp002.maas', u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/a8payb/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'a8payb', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/', u'type': u'physical', u'partitions': [{u'uuid': u'5a4d39b9-cb3c-4d4f-adc7-bac2e7647474', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'a8payb', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'058714ff-31e1-44c7-8711-4540acc4d9db', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/partition/6'}], u'tags': [u'rotary'], u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'a8payb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, {u'size': 107374182400, u'uuid': u'74d44f56-f361-4d70-8910-415d71454a5c', u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/11/', u'type': u'virtual', u'partitions': [], u'tags': [], u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'a8payb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'2b813970-9e9b-44cc-bbac-f1f468643d70', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'serial': None, u'name': u'vgroot-lvroot'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'a8payb', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 30}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'children': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'a8payb', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/interfaces/4/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 31}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6d', u'enabled': True, u'parents': [], u'discovered': None, u'children': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'a8payb', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 32}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6b', u'enabled': True, u'parents': [], u'discovered': None, u'children': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'a8payb', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/interfaces/19/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 33}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6c', u'enabled': True, u'parents': [], u'discovered': None, u'children': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'a8payb', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/', u'type': u'physical', u'partitions': [{u'uuid': u'5a4d39b9-cb3c-4d4f-adc7-bac2e7647474', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'a8payb', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'058714ff-31e1-44c7-8711-4540acc4d9db', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/partition/6'}], u'tags': [u'rotary'], u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'a8payb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}], u'netboot': True, u'osystem': u'', u'node_type': 0, u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'74d44f56-f361-4d70-8910-415d71454a5c', u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/11/', u'type': u'virtual', u'partitions': [], u'tags': [], u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'a8payb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'2b813970-9e9b-44cc-bbac-f1f468643d70', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'serial': None, u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/', u'type': u'physical', u'partitions': [{u'uuid': u'5a4d39b9-cb3c-4d4f-adc7-bac2e7647474', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'a8payb', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'058714ff-31e1-44c7-8711-4540acc4d9db', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/a8payb/blockdevices/4/partition/6'}], u'tags': [u'rotary'], u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'a8payb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}}
2019-12-11 05:11:43,823 [salt.state       :300 ][INFO    ][9983] {'new': {'storage_layout': 'lvm'}}
2019-12-11 05:11:43,824 [salt.state       :1951][INFO    ][9983] Completed state [maas_machines_storage_cmp002_lvm] at time 05:11:43.824197 duration_in_ms=2862.223
2019-12-11 05:11:43,824 [salt.state       :1780][INFO    ][9983] Running state [maas_machines_storage_cmp001_lvm] at time 05:11:43.824791
2019-12-11 05:11:43,825 [salt.state       :1813][INFO    ][9983] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-11 05:11:45,147 [salt.loaded.ext.module.maasng:610 ][INFO    ][9983] d7hc4c
2019-12-11 05:11:45,147 [salt.loaded.ext.module.maasng:626 ][INFO    ][9983] sda
2019-12-11 05:11:45,854 [salt.loaded.ext.module.maasng:361 ][INFO    ][9983] d7hc4c
2019-12-11 05:11:45,987 [salt.loaded.ext.module.maasng:367 ][INFO    ][9983] [{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'72593eff-2f5b-4488-8c5a-fe9b0071ccaf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'd7hc4c', u'device_id': 1, u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'cc00765d-21b7-40fd-9a59-3d4550c06d0f'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/1/partition/1'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'd7hc4c', 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/d7hc4c/blockdevices/1/', u'type': u'physical', u'id': 1, 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'ca1d6cb7-665d-43bd-90e5-935175e055d9', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'd7hc4c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'27488ed4-f62c-4386-902c-d668760039e6'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/6/', u'type': u'virtual', u'id': 6, u'serial': None, u'size': 2397988454400}]
2019-12-11 05:11:45,987 [salt.loaded.ext.module.maasng:632 ][INFO    ][9983] vgroot
2019-12-11 05:11:45,988 [salt.loaded.ext.module.maasng:635 ][INFO    ][9983] lvroot
2019-12-11 05:11:45,988 [salt.loaded.ext.module.maasng:639 ][INFO    ][9983] 107374182400
2019-12-11 05:11:46,628 [salt.loaded.ext.module.maasng:645 ][INFO    ][9983] {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'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'ga-18.04', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'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'f7dbaba6-0aee-45f0-9233-f757cfb67de0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'd7hc4c', u'device_id': 1, u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'11848d20-59c8-4991-b51d-af952fb333ad'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/1/partition/7'}], u'uuid': None, u'id': 1, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'd7hc4c', 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/d7hc4c/blockdevices/1/', u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, u'fqdn': u'cmp001.maas', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'd7hc4c', 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'owner_data': {}, 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'f7dbaba6-0aee-45f0-9233-f757cfb67de0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'd7hc4c', u'device_id': 1, u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'11848d20-59c8-4991-b51d-af952fb333ad'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/1/partition/7'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'd7hc4c', 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/d7hc4c/blockdevices/1/', u'type': u'physical', u'id': 1, 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'179207cc-d190-4210-9e7d-acce41d139d1', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'd7hc4c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'c282a783-da32-48c3-be5c-453056ec00ce'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/12/', u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'cpu_count': 16, 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'f7dbaba6-0aee-45f0-9233-f757cfb67de0', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'd7hc4c', u'device_id': 1, u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'11848d20-59c8-4991-b51d-af952fb333ad'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/blockdevices/1/partition/7'}], u'uuid': None, u'id': 1, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'd7hc4c', 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/d7hc4c/blockdevices/1/', u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'd7hc4c', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'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'179207cc-d190-4210-9e7d-acce41d139d1', u'id': 12, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'd7hc4c', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'c282a783-da32-48c3-be5c-453056ec00ce'}, 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/d7hc4c/blockdevices/12/', u'type': u'virtual', u'serial': None, u'size': 107374182400}], u'ip_addresses': [u'192.168.11.38'], u'architecture': u'amd64/generic', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 15}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'd7hc4c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/interfaces/5/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 15}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'd7hc4c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 17}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'd7hc4c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'd7hc4c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 19}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'd7hc4c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/d7hc4c/interfaces/11/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/d7hc4c/'}
2019-12-11 05:11:46,631 [salt.state       :300 ][INFO    ][9983] {'new': {'storage_layout': 'lvm'}}
2019-12-11 05:11:46,631 [salt.state       :1951][INFO    ][9983] Completed state [maas_machines_storage_cmp001_lvm] at time 05:11:46.631784 duration_in_ms=2806.992
2019-12-11 05:11:46,635 [salt.minion      :1711][INFO    ][9983] Returning information for job: 20191211051135480707
2019-12-11 05:11:47,229 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211051147216058
2019-12-11 05:11:47,250 [salt.minion      :1432][INFO    ][10030] Starting a new job with PID 10030
2019-12-11 05:11:48,023 [salt.state       :915 ][INFO    ][10030] Loading fresh modules for state activity
2019-12-11 05:11:48,074 [salt.fileclient  :1219][INFO    ][10030] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-12-11 05:11:48,115 [salt.state       :1780][INFO    ][10030] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:48.115727
2019-12-11 05:11:48,116 [salt.state       :1813][INFO    ][10030] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:11:48,118 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10030] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:11:49,598 [salt.state       :300 ][INFO    ][10030] {'pid': 10037, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:11:49,599 [salt.state       :1951][INFO    ][10030] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:49.599410 duration_in_ms=1483.683
2019-12-11 05:11:49,600 [salt.state       :1780][INFO    ][10030] Running state [maas.deploy_machines] at time 05:11:49.600760
2019-12-11 05:11:49,601 [salt.state       :1813][INFO    ][10030] Executing state module.run for [maas.deploy_machines]
2019-12-11 05:11:49,601 [salt.utils.decorators:613 ][WARNING ][10030] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:11:50,427 [salt.loaded.ext.module.maas:684 ][INFO    ][10030] deploymachines hwe_kernel=ga-18.04 system_id=a8payb distro_series=bionic
2019-12-11 05:11:52,673 [salt.loaded.ext.module.maas:684 ][INFO    ][10030] deploymachines hwe_kernel=ga-18.04 system_id=d7hc4c distro_series=bionic
2019-12-11 05:11:55,086 [salt.loaded.ext.module.maas:684 ][INFO    ][10030] deploymachines hwe_kernel=ga-18.04 system_id=ya4mwd distro_series=bionic
2019-12-11 05:11:57,836 [salt.loaded.ext.module.maas:684 ][INFO    ][10030] deploymachines hwe_kernel=ga-18.04 system_id=8bgpb3 distro_series=bionic
2019-12-11 05:12:00,489 [salt.loaded.ext.module.maas:684 ][INFO    ][10030] deploymachines hwe_kernel=ga-18.04 system_id=pbfkht distro_series=bionic
2019-12-11 05:12:02,299 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051202289535
2019-12-11 05:12:02,322 [salt.minion      :1432][INFO    ][10367] Starting a new job with PID 10367
2019-12-11 05:12:02,343 [salt.minion      :1711][INFO    ][10367] Returning information for job: 20191211051202289535
2019-12-11 05:12:02,897 [salt.state       :300 ][INFO    ][10030] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-12-11 05:12:02,898 [salt.state       :1951][INFO    ][10030] Completed state [maas.deploy_machines] at time 05:12:02.898062 duration_in_ms=13297.299
2019-12-11 05:12:02,902 [salt.minion      :1711][INFO    ][10030] Returning information for job: 20191211051147216058
2019-12-11 05:12:03,488 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211051203476337
2019-12-11 05:12:03,508 [salt.minion      :1432][INFO    ][10382] Starting a new job with PID 10382
2019-12-11 05:12:06,979 [salt.state       :915 ][INFO    ][10382] Loading fresh modules for state activity
2019-12-11 05:12:07,031 [salt.fileclient  :1219][INFO    ][10382] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-12-11 05:12:07,070 [salt.state       :1780][INFO    ][10382] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:12:07.070158
2019-12-11 05:12:07,070 [salt.state       :1813][INFO    ][10382] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:12:07,072 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10382] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:12:08,493 [salt.state       :300 ][INFO    ][10382] {'pid': 10393, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:12:08,494 [salt.state       :1951][INFO    ][10382] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:12:08.494702 duration_in_ms=1424.542
2019-12-11 05:12:08,498 [salt.state       :1780][INFO    ][10382] Running state [maas.wait_for_machine_status] at time 05:12:08.498302
2019-12-11 05:12:08,499 [salt.state       :1813][INFO    ][10382] Executing state module.run for [maas.wait_for_machine_status]
2019-12-11 05:12:08,499 [salt.utils.decorators:613 ][WARNING ][10382] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:12:11,903 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.60758805s left)
2019-12-11 05:12:18,595 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051218582670
2019-12-11 05:12:18,610 [salt.minion      :1432][INFO    ][10413] Starting a new job with PID 10413
2019-12-11 05:12:18,632 [salt.minion      :1711][INFO    ][10413] Returning information for job: 20191211051218582670
2019-12-11 05:12:45,250 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.26003504s left)
2019-12-11 05:12:48,634 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051248620235
2019-12-11 05:12:48,657 [salt.minion      :1432][INFO    ][10455] Starting a new job with PID 10455
2019-12-11 05:12:48,681 [salt.minion      :1711][INFO    ][10455] Returning information for job: 20191211051248620235
2019-12-11 05:13:18,626 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.88477421s left)
2019-12-11 05:13:18,736 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051318723224
2019-12-11 05:13:18,758 [salt.minion      :1432][INFO    ][10487] Starting a new job with PID 10487
2019-12-11 05:13:18,776 [salt.minion      :1711][INFO    ][10487] Returning information for job: 20191211051318723224
2019-12-11 05:13:48,768 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051348762474
2019-12-11 05:13:48,791 [salt.minion      :1432][INFO    ][10621] Starting a new job with PID 10621
2019-12-11 05:13:48,814 [salt.minion      :1711][INFO    ][10621] Returning information for job: 20191211051348762474
2019-12-11 05:13:51,648 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.86259508s left)
2019-12-11 05:14:18,825 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051418812574
2019-12-11 05:14:18,849 [salt.minion      :1432][INFO    ][10839] Starting a new job with PID 10839
2019-12-11 05:14:18,874 [salt.minion      :1711][INFO    ][10839] Returning information for job: 20191211051418812574
2019-12-11 05:14:24,569 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.94145918s left)
2019-12-11 05:14:48,880 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051448867593
2019-12-11 05:14:48,902 [salt.minion      :1432][INFO    ][11056] Starting a new job with PID 11056
2019-12-11 05:14:48,925 [salt.minion      :1711][INFO    ][11056] Returning information for job: 20191211051448867593
2019-12-11 05:14:57,781 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.72888923s left)
2019-12-11 05:15:18,941 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051518928314
2019-12-11 05:15:18,963 [salt.minion      :1432][INFO    ][11613] Starting a new job with PID 11613
2019-12-11 05:15:18,986 [salt.minion      :1711][INFO    ][11613] Returning information for job: 20191211051518928314
2019-12-11 05:15:30,622 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.8884871s left)
2019-12-11 05:15:48,998 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051548985993
2019-12-11 05:15:49,021 [salt.minion      :1432][INFO    ][11716] Starting a new job with PID 11716
2019-12-11 05:15:49,044 [salt.minion      :1711][INFO    ][11716] Returning information for job: 20191211051548985993
2019-12-11 05:16:03,993 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.51708913s left)
2019-12-11 05:16:19,060 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051619047320
2019-12-11 05:16:19,082 [salt.minion      :1432][INFO    ][11802] Starting a new job with PID 11802
2019-12-11 05:16:19,105 [salt.minion      :1711][INFO    ][11802] Returning information for job: 20191211051619047320
2019-12-11 05:16:37,165 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.34525919s left)
2019-12-11 05:16:49,125 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051649112511
2019-12-11 05:16:49,147 [salt.minion      :1432][INFO    ][11879] Starting a new job with PID 11879
2019-12-11 05:16:49,169 [salt.minion      :1711][INFO    ][11879] Returning information for job: 20191211051649112511
2019-12-11 05:17:10,796 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.71386313s left)
2019-12-11 05:17:19,201 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051719189030
2019-12-11 05:17:19,224 [salt.minion      :1432][INFO    ][12075] Starting a new job with PID 12075
2019-12-11 05:17:19,249 [salt.minion      :1711][INFO    ][12075] Returning information for job: 20191211051719189030
2019-12-11 05:17:44,029 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1914.4817791s left)
2019-12-11 05:17:49,274 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051749260865
2019-12-11 05:17:49,295 [salt.minion      :1432][INFO    ][12216] Starting a new job with PID 12216
2019-12-11 05:17:49,319 [salt.minion      :1711][INFO    ][12216] Returning information for job: 20191211051749260865
2019-12-11 05:18:17,469 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.04133916s left)
2019-12-11 05:18:19,357 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051819344413
2019-12-11 05:18:19,380 [salt.minion      :1432][INFO    ][12588] Starting a new job with PID 12588
2019-12-11 05:18:19,403 [salt.minion      :1711][INFO    ][12588] Returning information for job: 20191211051819344413
2019-12-11 05:18:49,444 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051849430922
2019-12-11 05:18:49,465 [salt.minion      :1432][INFO    ][12699] Starting a new job with PID 12699
2019-12-11 05:18:49,486 [salt.minion      :1711][INFO    ][12699] Returning information for job: 20191211051849430922
2019-12-11 05:18:51,563 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.9468751s left)
2019-12-11 05:19:19,538 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051919524018
2019-12-11 05:19:19,560 [salt.minion      :1432][INFO    ][12779] Starting a new job with PID 12779
2019-12-11 05:19:19,585 [salt.minion      :1711][INFO    ][12779] Returning information for job: 20191211051919524018
2019-12-11 05:19:25,102 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.40815616s left)
2019-12-11 05:19:49,655 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211051949641794
2019-12-11 05:19:49,673 [salt.minion      :1432][INFO    ][12938] Starting a new job with PID 12938
2019-12-11 05:19:49,694 [salt.minion      :1711][INFO    ][12938] Returning information for job: 20191211051949641794
2019-12-11 05:19:57,996 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1780.51431918s left)
2019-12-11 05:20:19,677 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052019665003
2019-12-11 05:20:19,700 [salt.minion      :1432][INFO    ][13145] Starting a new job with PID 13145
2019-12-11 05:20:19,724 [salt.minion      :1711][INFO    ][13145] Returning information for job: 20191211052019665003
2019-12-11 05:20:31,040 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1747.47014999s left)
2019-12-11 05:20:49,789 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052049777299
2019-12-11 05:20:49,809 [salt.minion      :1432][INFO    ][13242] Starting a new job with PID 13242
2019-12-11 05:20:49,822 [salt.minion      :1711][INFO    ][13242] Returning information for job: 20191211052049777299
2019-12-11 05:21:04,156 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1714.35410309s left)
2019-12-11 05:21:19,885 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052119872035
2019-12-11 05:21:19,908 [salt.minion      :1432][INFO    ][13486] Starting a new job with PID 13486
2019-12-11 05:21:19,931 [salt.minion      :1711][INFO    ][13486] Returning information for job: 20191211052119872035
2019-12-11 05:21:37,545 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1680.96542311s left)
2019-12-11 05:21:50,019 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052150002958
2019-12-11 05:21:50,037 [salt.minion      :1432][INFO    ][13558] Starting a new job with PID 13558
2019-12-11 05:21:50,057 [salt.minion      :1711][INFO    ][13558] Returning information for job: 20191211052150002958
2019-12-11 05:22:11,264 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1647.24609208s left)
2019-12-11 05:22:20,143 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052220130940
2019-12-11 05:22:20,165 [salt.minion      :1432][INFO    ][13583] Starting a new job with PID 13583
2019-12-11 05:22:20,189 [salt.minion      :1711][INFO    ][13583] Returning information for job: 20191211052220130940
2019-12-11 05:22:44,642 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1613.86839008s left)
2019-12-11 05:22:50,286 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052250273358
2019-12-11 05:22:50,309 [salt.minion      :1432][INFO    ][13639] Starting a new job with PID 13639
2019-12-11 05:22:50,333 [salt.minion      :1711][INFO    ][13639] Returning information for job: 20191211052250273358
2019-12-11 05:23:18,042 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1580.46782303s left)
2019-12-11 05:23:20,439 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052320426388
2019-12-11 05:23:20,461 [salt.minion      :1432][INFO    ][13660] Starting a new job with PID 13660
2019-12-11 05:23:20,485 [salt.minion      :1711][INFO    ][13660] Returning information for job: 20191211052320426388
2019-12-11 05:23:50,594 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052350586738
2019-12-11 05:23:50,613 [salt.minion      :1432][INFO    ][13724] Starting a new job with PID 13724
2019-12-11 05:23:50,639 [salt.minion      :1711][INFO    ][13724] Returning information for job: 20191211052350586738
2019-12-11 05:23:51,421 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1547.08885407s left)
2019-12-11 05:24:20,758 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052420745993
2019-12-11 05:24:20,781 [salt.minion      :1432][INFO    ][13744] Starting a new job with PID 13744
2019-12-11 05:24:20,803 [salt.minion      :1711][INFO    ][13744] Returning information for job: 20191211052420745993
2019-12-11 05:24:25,059 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1513.4514761s left)
2019-12-11 05:24:50,939 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052450927220
2019-12-11 05:24:50,962 [salt.minion      :1432][INFO    ][13892] Starting a new job with PID 13892
2019-12-11 05:24:50,984 [salt.minion      :1711][INFO    ][13892] Returning information for job: 20191211052450927220
2019-12-11 05:24:58,646 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1479.86406922s left)
2019-12-11 05:25:21,124 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052521111232
2019-12-11 05:25:21,146 [salt.minion      :1432][INFO    ][13923] Starting a new job with PID 13923
2019-12-11 05:25:21,171 [salt.minion      :1711][INFO    ][13923] Returning information for job: 20191211052521111232
2019-12-11 05:25:31,970 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1446.54057908s left)
2019-12-11 05:25:51,328 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052551315894
2019-12-11 05:25:51,351 [salt.minion      :1432][INFO    ][13980] Starting a new job with PID 13980
2019-12-11 05:25:51,374 [salt.minion      :1711][INFO    ][13980] Returning information for job: 20191211052551315894
2019-12-11 05:26:05,400 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1413.11012101s left)
2019-12-11 05:26:21,530 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052621518627
2019-12-11 05:26:21,552 [salt.minion      :1432][INFO    ][14001] Starting a new job with PID 14001
2019-12-11 05:26:21,575 [salt.minion      :1711][INFO    ][14001] Returning information for job: 20191211052621518627
2019-12-11 05:26:38,927 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1379.58317113s left)
2019-12-11 05:26:51,751 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052651738622
2019-12-11 05:26:51,774 [salt.minion      :1432][INFO    ][14064] Starting a new job with PID 14064
2019-12-11 05:26:51,798 [salt.minion      :1711][INFO    ][14064] Returning information for job: 20191211052651738622
2019-12-11 05:27:12,281 [salt.loaded.ext.module.maas:1023][INFO    ][10382] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1346.22924113s left)
2019-12-11 05:27:21,772 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052721759870
2019-12-11 05:27:21,794 [salt.minion      :1432][INFO    ][14085] Starting a new job with PID 14085
2019-12-11 05:27:21,818 [salt.minion      :1711][INFO    ][14085] Returning information for job: 20191211052721759870
2019-12-11 05:27:45,451 [salt.loaded.ext.module.maas:993 ][INFO    ][10382] Machine pbfkht mark broken
2019-12-11 05:27:46,250 [salt.loaded.ext.module.maas:996 ][INFO    ][10382] Machine pbfkht mark fixed
2019-12-11 05:27:47,297 [salt.loaded.ext.module.maas:684 ][INFO    ][10382] deploymachines hwe_kernel=ga-18.04 system_id=pbfkht distro_series=bionic
2019-12-11 05:27:49,876 [salt.loaded.ext.module.maas:160 ][ERROR   ][10382] 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-12-11 05:27:49,878 [salt.state       :302 ][ERROR   ][10382] 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-12-11 05:27:49,878 [salt.state       :1951][INFO    ][10382] Completed state [maas.wait_for_machine_status] at time 05:27:49.878784 duration_in_ms=941380.474
2019-12-11 05:27:49,885 [salt.minion      :1711][INFO    ][10382] Returning information for job: 20191211051203476337
2019-12-11 05:28:00,678 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command pillar.get with jid 20191211052800669714
2019-12-11 05:28:00,699 [salt.minion      :1432][INFO    ][14214] Starting a new job with PID 14214
2019-12-11 05:28:00,706 [salt.minion      :1711][INFO    ][14214] Returning information for job: 20191211052800669714
2019-12-11 05:28:01,183 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command service.status with jid 20191211052801171079
2019-12-11 05:28:01,205 [salt.minion      :1432][INFO    ][14219] Starting a new job with PID 14219
2019-12-11 05:28:01,606 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14219] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:01,640 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14219] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-12-11 05:28:01,656 [salt.minion      :1711][INFO    ][14219] Returning information for job: 20191211052801171079
2019-12-11 05:28:02,177 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211052802164425
2019-12-11 05:28:02,198 [salt.minion      :1432][INFO    ][14230] Starting a new job with PID 14230
2019-12-11 05:28:06,022 [salt.state       :915 ][INFO    ][14230] Loading fresh modules for state activity
2019-12-11 05:28:06,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'salt-minion --version' in directory '/root'
2019-12-11 05:28:06,817 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'salt-minion --version' in directory '/root'
2019-12-11 05:28:07,650 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'salt-minion --version' in directory '/root'
2019-12-11 05:28:07,975 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'salt-minion --version' in directory '/root'
2019-12-11 05:28:09,289 [salt.state       :1780][INFO    ][14230] Running state [salt-minion] at time 05:28:09.289356
2019-12-11 05:28:09,289 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [salt-minion]
2019-12-11 05:28:09,290 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-11 05:28:09,387 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,387 [salt.state       :1951][INFO    ][14230] Completed state [salt-minion] at time 05:28:09.387424 duration_in_ms=98.067
2019-12-11 05:28:09,387 [salt.state       :1780][INFO    ][14230] Running state [salt_minion_dependency_packages] at time 05:28:09.387845
2019-12-11 05:28:09,388 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-12-11 05:28:09,395 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,395 [salt.state       :1951][INFO    ][14230] Completed state [salt_minion_dependency_packages] at time 05:28:09.395930 duration_in_ms=8.084
2019-12-11 05:28:09,399 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/minion.d/minion.conf] at time 05:28:09.399562
2019-12-11 05:28:09,399 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-12-11 05:28:09,592 [salt.state       :300 ][INFO    ][14230] File /etc/salt/minion.d/minion.conf is in the correct state
2019-12-11 05:28:09,592 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/minion.d/minion.conf] at time 05:28:09.592875 duration_in_ms=193.313
2019-12-11 05:28:09,593 [salt.state       :1780][INFO    ][14230] Running state [python-netaddr] at time 05:28:09.593070
2019-12-11 05:28:09,593 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [python-netaddr]
2019-12-11 05:28:09,598 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,598 [salt.state       :1951][INFO    ][14230] Completed state [python-netaddr] at time 05:28:09.598140 duration_in_ms=5.07
2019-12-11 05:28:09,600 [salt.state       :1780][INFO    ][14230] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:28:09.600340
2019-12-11 05:28:09,600 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-12-11 05:28:09,609 [salt.state       :300 ][INFO    ][14230] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-12-11 05:28:09,609 [salt.state       :1951][INFO    ][14230] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:28:09.609811 duration_in_ms=9.471
2019-12-11 05:28:09,610 [salt.state       :1780][INFO    ][14230] Running state [salt-minion] at time 05:28:09.610447
2019-12-11 05:28:09,610 [salt.state       :1813][INFO    ][14230] Executing state service.running for [salt-minion]
2019-12-11 05:28:09,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:09,646 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-12-11 05:28:09,663 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-12-11 05:28:09,679 [salt.state       :300 ][INFO    ][14230] The service salt-minion is already running
2019-12-11 05:28:09,679 [salt.state       :1951][INFO    ][14230] Completed state [salt-minion] at time 05:28:09.679514 duration_in_ms=69.067
2019-12-11 05:28:09,680 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains.d] at time 05:28:09.680647
2019-12-11 05:28:09,680 [salt.state       :1813][INFO    ][14230] Executing state file.directory for [/etc/salt/grains.d]
2019-12-11 05:28:09,681 [salt.state       :300 ][INFO    ][14230] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-12-11 05:28:09,681 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains.d] at time 05:28:09.681823 duration_in_ms=1.175
2019-12-11 05:28:09,682 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains] at time 05:28:09.682316
2019-12-11 05:28:09,682 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/grains]
2019-12-11 05:28:09,682 [salt.state       :300 ][INFO    ][14230] File /etc/salt/grains exists with proper permissions. No changes made.
2019-12-11 05:28:09,683 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains] at time 05:28:09.683132 duration_in_ms=0.816
2019-12-11 05:28:09,683 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains.d/placeholder] at time 05:28:09.683473
2019-12-11 05:28:09,683 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-12-11 05:28:09,684 [salt.state       :300 ][INFO    ][14230] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-12-11 05:28:09,684 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains.d/placeholder] at time 05:28:09.684259 duration_in_ms=0.786
2019-12-11 05:28:09,684 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains.d/sphinx] at time 05:28:09.684609
2019-12-11 05:28:09,684 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-12-11 05:28:09,700 [salt.state       :300 ][INFO    ][14230] File /etc/salt/grains.d/sphinx is in the correct state
2019-12-11 05:28:09,700 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains.d/sphinx] at time 05:28:09.700473 duration_in_ms=15.864
2019-12-11 05:28:09,702 [salt.state       :1780][INFO    ][14230] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.702271
2019-12-11 05:28:09,702 [salt.state       :1813][INFO    ][14230] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-12-11 05:28:09,702 [salt.state       :300 ][INFO    ][14230] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-12-11 05:28:09,703 [salt.state       :1951][INFO    ][14230] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.702985 duration_in_ms=0.714
2019-12-11 05:28:09,703 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains.d/dns_records] at time 05:28:09.703350
2019-12-11 05:28:09,703 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-12-11 05:28:09,712 [salt.state       :300 ][INFO    ][14230] File /etc/salt/grains.d/dns_records is in the correct state
2019-12-11 05:28:09,712 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains.d/dns_records] at time 05:28:09.712367 duration_in_ms=9.016
2019-12-11 05:28:09,713 [salt.state       :1780][INFO    ][14230] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.713084
2019-12-11 05:28:09,713 [salt.state       :1813][INFO    ][14230] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-12-11 05:28:09,713 [salt.state       :300 ][INFO    ][14230] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-12-11 05:28:09,713 [salt.state       :1951][INFO    ][14230] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.713782 duration_in_ms=0.698
2019-12-11 05:28:09,714 [salt.state       :1780][INFO    ][14230] Running state [/etc/salt/grains.d/salt] at time 05:28:09.714153
2019-12-11 05:28:09,714 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-12-11 05:28:09,724 [salt.state       :300 ][INFO    ][14230] File /etc/salt/grains.d/salt is in the correct state
2019-12-11 05:28:09,724 [salt.state       :1951][INFO    ][14230] Completed state [/etc/salt/grains.d/salt] at time 05:28:09.724389 duration_in_ms=10.235
2019-12-11 05:28:09,725 [salt.state       :1780][INFO    ][14230] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.725107
2019-12-11 05:28:09,725 [salt.state       :1813][INFO    ][14230] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-12-11 05:28:09,725 [salt.state       :300 ][INFO    ][14230] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-12-11 05:28:09,725 [salt.state       :1951][INFO    ][14230] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:28:09.725833 duration_in_ms=0.726
2019-12-11 05:28:09,727 [salt.state       :1780][INFO    ][14230] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:28:09.727310
2019-12-11 05:28:09,727 [salt.state       :1813][INFO    ][14230] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-12-11 05:28:09,727 [salt.state       :300 ][INFO    ][14230] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-12-11 05:28:09,728 [salt.state       :1951][INFO    ][14230] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:28:09.728049 duration_in_ms=0.739
2019-12-11 05:28:09,728 [salt.state       :1780][INFO    ][14230] Running state [mine.update] at time 05:28:09.728600
2019-12-11 05:28:09,728 [salt.state       :1813][INFO    ][14230] Executing state module.wait for [mine.update]
2019-12-11 05:28:09,729 [salt.state       :300 ][INFO    ][14230] No changes made for mine.update
2019-12-11 05:28:09,729 [salt.state       :1951][INFO    ][14230] Completed state [mine.update] at time 05:28:09.729278 duration_in_ms=0.678
2019-12-11 05:28:09,729 [salt.state       :1780][INFO    ][14230] Running state [ca-certificates] at time 05:28:09.729503
2019-12-11 05:28:09,729 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [ca-certificates]
2019-12-11 05:28:09,735 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,735 [salt.state       :1951][INFO    ][14230] Completed state [ca-certificates] at time 05:28:09.735725 duration_in_ms=6.222
2019-12-11 05:28:09,736 [salt.state       :1780][INFO    ][14230] Running state [update-ca-certificates] at time 05:28:09.736302
2019-12-11 05:28:09,736 [salt.state       :1813][INFO    ][14230] Executing state cmd.wait for [update-ca-certificates]
2019-12-11 05:28:09,736 [salt.state       :300 ][INFO    ][14230] No changes made for update-ca-certificates
2019-12-11 05:28:09,737 [salt.state       :1951][INFO    ][14230] Completed state [update-ca-certificates] at time 05:28:09.736995 duration_in_ms=0.693
2019-12-11 05:28:09,737 [salt.state       :1780][INFO    ][14230] Running state [iptables] at time 05:28:09.737218
2019-12-11 05:28:09,737 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [iptables]
2019-12-11 05:28:09,742 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,742 [salt.state       :1951][INFO    ][14230] Completed state [iptables] at time 05:28:09.742902 duration_in_ms=5.684
2019-12-11 05:28:09,743 [salt.state       :1780][INFO    ][14230] Running state [iptables-persistent] at time 05:28:09.743112
2019-12-11 05:28:09,743 [salt.state       :1813][INFO    ][14230] Executing state pkg.installed for [iptables-persistent]
2019-12-11 05:28:09,748 [salt.state       :300 ][INFO    ][14230] All specified packages are already installed
2019-12-11 05:28:09,748 [salt.state       :1951][INFO    ][14230] Completed state [iptables-persistent] at time 05:28:09.748629 duration_in_ms=5.517
2019-12-11 05:28:09,749 [salt.state       :1780][INFO    ][14230] Running state [iptables_modules_v4_load] at time 05:28:09.749397
2019-12-11 05:28:09,749 [salt.state       :1813][INFO    ][14230] Executing state kmod.present for [iptables_modules_v4_load]
2019-12-11 05:28:09,750 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'lsmod' in directory '/root'
2019-12-11 05:28:09,772 [salt.state       :300 ][INFO    ][14230] Kernel modules iptable_filter, ip_tables are already present
2019-12-11 05:28:09,772 [salt.state       :1951][INFO    ][14230] Completed state [iptables_modules_v4_load] at time 05:28:09.772536 duration_in_ms=23.139
2019-12-11 05:28:09,773 [salt.state       :1780][INFO    ][14230] Running state [/etc/iptables/rules.v4] at time 05:28:09.773121
2019-12-11 05:28:09,773 [salt.state       :1813][INFO    ][14230] Executing state file.managed for [/etc/iptables/rules.v4]
2019-12-11 05:28:09,844 [salt.state       :300 ][INFO    ][14230] File /etc/iptables/rules.v4 is in the correct state
2019-12-11 05:28:09,844 [salt.state       :1951][INFO    ][14230] Completed state [/etc/iptables/rules.v4] at time 05:28:09.844301 duration_in_ms=71.18
2019-12-11 05:28:09,845 [salt.state       :1780][INFO    ][14230] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:28:09.845057
2019-12-11 05:28:09,845 [salt.state       :1813][INFO    ][14230] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-12-11 05:28:09,845 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-12-11 05:28:09,863 [salt.state       :300 ][INFO    ][14230] onlyif execution failed
2019-12-11 05:28:09,864 [salt.state       :1951][INFO    ][14230] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:28:09.864099 duration_in_ms=19.042
2019-12-11 05:28:09,864 [salt.state       :1780][INFO    ][14230] Running state [netfilter-persistent] at time 05:28:09.864813
2019-12-11 05:28:09,865 [salt.state       :1813][INFO    ][14230] Executing state service.running for [netfilter-persistent]
2019-12-11 05:28:09,865 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:09,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-12-11 05:28:09,899 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-12-11 05:28:09,916 [salt.state       :300 ][INFO    ][14230] The service netfilter-persistent is already running
2019-12-11 05:28:09,916 [salt.state       :1951][INFO    ][14230] Completed state [netfilter-persistent] at time 05:28:09.916522 duration_in_ms=51.709
2019-12-11 05:28:09,917 [salt.state       :1780][INFO    ][14230] Running state [iptables_extra.remove_stale_tables] at time 05:28:09.917186
2019-12-11 05:28:09,917 [salt.state       :1813][INFO    ][14230] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-12-11 05:28:09,917 [salt.state       :300 ][INFO    ][14230] No changes made for iptables_extra.remove_stale_tables
2019-12-11 05:28:09,917 [salt.state       :1951][INFO    ][14230] Completed state [iptables_extra.remove_stale_tables] at time 05:28:09.917955 duration_in_ms=0.769
2019-12-11 05:28:09,918 [salt.state       :1780][INFO    ][14230] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:28:09.918165
2019-12-11 05:28:09,918 [salt.state       :1813][INFO    ][14230] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-12-11 05:28:09,918 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14230] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-12-11 05:28:09,932 [salt.state       :300 ][INFO    ][14230] onlyif execution failed
2019-12-11 05:28:09,932 [salt.state       :1951][INFO    ][14230] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:28:09.932736 duration_in_ms=14.571
2019-12-11 05:28:09,933 [salt.state       :1780][INFO    ][14230] Running state [/etc/iptables/rules.v6] at time 05:28:09.933516
2019-12-11 05:28:09,933 [salt.state       :1813][INFO    ][14230] Executing state file.absent for [/etc/iptables/rules.v6]
2019-12-11 05:28:09,934 [salt.state       :300 ][INFO    ][14230] File /etc/iptables/rules.v6 is not present
2019-12-11 05:28:09,934 [salt.state       :1951][INFO    ][14230] Completed state [/etc/iptables/rules.v6] at time 05:28:09.934362 duration_in_ms=0.847
2019-12-11 05:28:09,934 [salt.state       :1780][INFO    ][14230] Running state [iptables_extra.flush_all] at time 05:28:09.934919
2019-12-11 05:28:09,935 [salt.state       :1813][INFO    ][14230] Executing state module.wait for [iptables_extra.flush_all]
2019-12-11 05:28:09,935 [salt.state       :300 ][INFO    ][14230] No changes made for iptables_extra.flush_all
2019-12-11 05:28:09,935 [salt.state       :1951][INFO    ][14230] Completed state [iptables_extra.flush_all] at time 05:28:09.935604 duration_in_ms=0.685
2019-12-11 05:28:09,938 [salt.minion      :1711][INFO    ][14230] Returning information for job: 20191211052802164425
2019-12-11 05:28:10,584 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211052810571572
2019-12-11 05:28:10,607 [salt.minion      :1432][INFO    ][14310] Starting a new job with PID 14310
2019-12-11 05:28:11,369 [salt.state       :915 ][INFO    ][14310] Loading fresh modules for state activity
2019-12-11 05:28:12,051 [salt.state       :1780][INFO    ][14310] Running state [maas-rack-controller] at time 05:28:12.051739
2019-12-11 05:28:12,052 [salt.state       :1813][INFO    ][14310] Executing state pkg.installed for [maas-rack-controller]
2019-12-11 05:28:12,052 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14310] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-11 05:28:12,150 [salt.state       :300 ][INFO    ][14310] All specified packages are already installed
2019-12-11 05:28:12,151 [salt.state       :1951][INFO    ][14310] Completed state [maas-rack-controller] at time 05:28:12.151314 duration_in_ms=99.575
2019-12-11 05:28:12,151 [salt.state       :1780][INFO    ][14310] Running state [ipmitool] at time 05:28:12.151750
2019-12-11 05:28:12,152 [salt.state       :1813][INFO    ][14310] Executing state pkg.installed for [ipmitool]
2019-12-11 05:28:12,160 [salt.state       :300 ][INFO    ][14310] All specified packages are already installed
2019-12-11 05:28:12,160 [salt.state       :1951][INFO    ][14310] Completed state [ipmitool] at time 05:28:12.160348 duration_in_ms=8.598
2019-12-11 05:28:12,164 [salt.state       :1780][INFO    ][14310] Running state [/etc/maas/rackd.conf] at time 05:28:12.163976
2019-12-11 05:28:12,164 [salt.state       :1813][INFO    ][14310] Executing state file.line for [/etc/maas/rackd.conf]
2019-12-11 05:28:12,165 [salt.state       :300 ][INFO    ][14310] No changes needed to be made
2019-12-11 05:28:12,165 [salt.state       :1951][INFO    ][14310] Completed state [/etc/maas/rackd.conf] at time 05:28:12.165805 duration_in_ms=1.828
2019-12-11 05:28:12,166 [salt.state       :1780][INFO    ][14310] Running state [/etc/maas/rackd.conf] at time 05:28:12.166077
2019-12-11 05:28:12,166 [salt.state       :1813][INFO    ][14310] Executing state file.managed for [/etc/maas/rackd.conf]
2019-12-11 05:28:12,166 [salt.loaded.int.states.file:2298][WARNING ][14310] 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-12-11 05:28:12,167 [salt.state       :300 ][INFO    ][14310] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-12-11 05:28:12,167 [salt.state       :1951][INFO    ][14310] Completed state [/etc/maas/rackd.conf] at time 05:28:12.167568 duration_in_ms=1.49
2019-12-11 05:28:12,168 [salt.state       :1780][INFO    ][14310] Running state [maas-rackd] at time 05:28:12.168694
2019-12-11 05:28:12,169 [salt.state       :1813][INFO    ][14310] Executing state service.running for [maas-rackd]
2019-12-11 05:28:12,169 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14310] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:12,206 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14310] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-12-11 05:28:12,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14310] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-12-11 05:28:12,242 [salt.state       :300 ][INFO    ][14310] The service maas-rackd is already running
2019-12-11 05:28:12,242 [salt.state       :1951][INFO    ][14310] Completed state [maas-rackd] at time 05:28:12.242808 duration_in_ms=74.114
2019-12-11 05:28:12,245 [salt.minion      :1711][INFO    ][14310] Returning information for job: 20191211052810571572
2019-12-11 05:28:12,800 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211052812786990
2019-12-11 05:28:12,821 [salt.minion      :1432][INFO    ][14333] Starting a new job with PID 14333
2019-12-11 05:28:13,559 [salt.state       :915 ][INFO    ][14333] Loading fresh modules for state activity
2019-12-11 05:28:14,258 [salt.state       :1780][INFO    ][14333] Running state [maas-region-controller] at time 05:28:14.258039
2019-12-11 05:28:14,258 [salt.state       :1813][INFO    ][14333] Executing state pkg.installed for [maas-region-controller]
2019-12-11 05:28:14,258 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-11 05:28:14,332 [salt.state       :300 ][INFO    ][14333] All specified packages are already installed
2019-12-11 05:28:14,333 [salt.state       :1951][INFO    ][14333] Completed state [maas-region-controller] at time 05:28:14.333172 duration_in_ms=75.133
2019-12-11 05:28:14,333 [salt.state       :1780][INFO    ][14333] Running state [python-oauth] at time 05:28:14.333420
2019-12-11 05:28:14,333 [salt.state       :1813][INFO    ][14333] Executing state pkg.installed for [python-oauth]
2019-12-11 05:28:14,338 [salt.state       :300 ][INFO    ][14333] All specified packages are already installed
2019-12-11 05:28:14,338 [salt.state       :1951][INFO    ][14333] Completed state [python-oauth] at time 05:28:14.338256 duration_in_ms=4.837
2019-12-11 05:28:14,340 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/regiond.conf] at time 05:28:14.340646
2019-12-11 05:28:14,340 [salt.state       :1813][INFO    ][14333] Executing state file.replace for [/etc/maas/regiond.conf]
2019-12-11 05:28:14,397 [salt.state       :300 ][INFO    ][14333] No changes needed to be made
2019-12-11 05:28:14,397 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/regiond.conf] at time 05:28:14.397334 duration_in_ms=56.688
2019-12-11 05:28:14,397 [salt.state       :1780][INFO    ][14333] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:28:14.397939
2019-12-11 05:28:14,398 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-12-11 05:28:14,462 [salt.state       :300 ][INFO    ][14333] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-12-11 05:28:14,462 [salt.state       :1951][INFO    ][14333] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:28:14.462604 duration_in_ms=64.665
2019-12-11 05:28:14,463 [salt.state       :1780][INFO    ][14333] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:28:14.463139
2019-12-11 05:28:14,463 [salt.state       :1813][INFO    ][14333] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-11 05:28:14,475 [salt.state       :300 ][INFO    ][14333] No changes needed to be made
2019-12-11 05:28:14,476 [salt.state       :1951][INFO    ][14333] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:28:14.476029 duration_in_ms=12.89
2019-12-11 05:28:14,476 [salt.state       :1780][INFO    ][14333] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:28:14.476580
2019-12-11 05:28:14,476 [salt.state       :1813][INFO    ][14333] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-11 05:28:14,499 [salt.state       :300 ][INFO    ][14333] No changes needed to be made
2019-12-11 05:28:14,500 [salt.state       :1951][INFO    ][14333] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:28:14.500110 duration_in_ms=23.531
2019-12-11 05:28:14,500 [salt.state       :1780][INFO    ][14333] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:28:14.500667
2019-12-11 05:28:14,501 [salt.state       :1813][INFO    ][14333] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-12-11 05:28:14,526 [salt.state       :300 ][INFO    ][14333] No changes needed to be made
2019-12-11 05:28:14,526 [salt.state       :1951][INFO    ][14333] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:28:14.526824 duration_in_ms=26.157
2019-12-11 05:28:14,527 [salt.state       :1780][INFO    ][14333] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:28:14.527318
2019-12-11 05:28:14,527 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-12-11 05:28:14,538 [salt.state       :300 ][INFO    ][14333] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-12-11 05:28:14,538 [salt.state       :1951][INFO    ][14333] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:28:14.538937 duration_in_ms=11.618
2019-12-11 05:28:14,540 [salt.state       :1780][INFO    ][14333] Running state [a2enmod headers] at time 05:28:14.540119
2019-12-11 05:28:14,540 [salt.state       :1813][INFO    ][14333] Executing state cmd.run for [a2enmod headers]
2019-12-11 05:28:14,541 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command 'a2enmod headers' in directory '/root'
2019-12-11 05:28:14,610 [salt.state       :300 ][INFO    ][14333] {'pid': 14352, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-12-11 05:28:14,611 [salt.state       :1951][INFO    ][14333] Completed state [a2enmod headers] at time 05:28:14.610968 duration_in_ms=70.848
2019-12-11 05:28:14,611 [salt.state       :1780][INFO    ][14333] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:28:14.611569
2019-12-11 05:28:14,612 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-12-11 05:28:14,630 [salt.state       :300 ][INFO    ][14333] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-12-11 05:28:14,631 [salt.state       :1951][INFO    ][14333] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:28:14.630923 duration_in_ms=19.354
2019-12-11 05:28:14,631 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:28:14.631805
2019-12-11 05:28:14,632 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-12-11 05:28:14,720 [salt.state       :300 ][INFO    ][14333] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-12-11 05:28:14,721 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:28:14.720910 duration_in_ms=89.104
2019-12-11 05:28:14,721 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:28:14.721708
2019-12-11 05:28:14,722 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-12-11 05:28:14,779 [salt.state       :300 ][INFO    ][14333] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-12-11 05:28:14,780 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:28:14.780108 duration_in_ms=58.4
2019-12-11 05:28:14,780 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:28:14.780562
2019-12-11 05:28:14,780 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-12-11 05:28:14,833 [salt.state       :300 ][INFO    ][14333] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-12-11 05:28:14,833 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:28:14.833815 duration_in_ms=53.253
2019-12-11 05:28:14,834 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:28:14.834232
2019-12-11 05:28:14,834 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-12-11 05:28:14,887 [salt.state       :300 ][INFO    ][14333] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-12-11 05:28:14,887 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:28:14.887789 duration_in_ms=53.556
2019-12-11 05:28:14,888 [salt.state       :1780][INFO    ][14333] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:28:14.888194
2019-12-11 05:28:14,888 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-12-11 05:28:14,929 [salt.state       :300 ][INFO    ][14333] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-12-11 05:28:14,929 [salt.state       :1951][INFO    ][14333] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:28:14.929535 duration_in_ms=41.341
2019-12-11 05:28:14,929 [salt.state       :1780][INFO    ][14333] Running state [/root/.pgpass] at time 05:28:14.929742
2019-12-11 05:28:14,929 [salt.state       :1813][INFO    ][14333] Executing state file.managed for [/root/.pgpass]
2019-12-11 05:28:14,971 [salt.state       :300 ][INFO    ][14333] File /root/.pgpass is in the correct state
2019-12-11 05:28:14,971 [salt.state       :1951][INFO    ][14333] Completed state [/root/.pgpass] at time 05:28:14.971364 duration_in_ms=41.622
2019-12-11 05:28:14,975 [salt.state       :1780][INFO    ][14333] Running state [maas-region syncdb --noinput] at time 05:28:14.974983
2019-12-11 05:28:14,975 [salt.state       :1813][INFO    ][14333] Executing state cmd.run for [maas-region syncdb --noinput]
2019-12-11 05:28:14,975 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-12-11 05:28:17,121 [salt.state       :300 ][INFO    ][14333] {'pid': 14369, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, contenttypes, metadataserver, piston3, maasserver, auth, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-12-11 05:28:17,122 [salt.state       :1951][INFO    ][14333] Completed state [maas-region syncdb --noinput] at time 05:28:17.122568 duration_in_ms=2147.584
2019-12-11 05:28:17,123 [salt.state       :2022][WARNING ][14333] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-11 05:28:17,126 [salt.state       :1780][INFO    ][14333] Running state [maas-regiond] at time 05:28:17.126043
2019-12-11 05:28:17,126 [salt.state       :1813][INFO    ][14333] Executing state service.running for [maas-regiond]
2019-12-11 05:28:17,128 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:17,169 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-12-11 05:28:17,187 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-12-11 05:28:17,204 [salt.state       :300 ][INFO    ][14333] The service maas-regiond is already running
2019-12-11 05:28:17,205 [salt.state       :1951][INFO    ][14333] Completed state [maas-regiond] at time 05:28:17.205241 duration_in_ms=79.198
2019-12-11 05:28:17,207 [salt.state       :1780][INFO    ][14333] Running state [bind9] at time 05:28:17.207705
2019-12-11 05:28:17,208 [salt.state       :1813][INFO    ][14333] Executing state service.running for [bind9]
2019-12-11 05:28:17,209 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:17,227 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-12-11 05:28:17,244 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-12-11 05:28:17,261 [salt.state       :300 ][INFO    ][14333] The service bind9 is already running
2019-12-11 05:28:17,261 [salt.state       :1951][INFO    ][14333] Completed state [bind9] at time 05:28:17.261799 duration_in_ms=54.093
2019-12-11 05:28:17,263 [salt.state       :1780][INFO    ][14333] Running state [apache2] at time 05:28:17.263845
2019-12-11 05:28:17,264 [salt.state       :1813][INFO    ][14333] Executing state service.running for [apache2]
2019-12-11 05:28:17,265 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-12-11 05:28:17,282 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-12-11 05:28:17,299 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-12-11 05:28:17,319 [salt.state       :300 ][INFO    ][14333] The service apache2 is already running
2019-12-11 05:28:17,319 [salt.state       :1951][INFO    ][14333] Completed state [apache2] at time 05:28:17.319688 duration_in_ms=55.843
2019-12-11 05:28:17,321 [salt.state       :1780][INFO    ][14333] Running state [maasng.wait_for_http_code] at time 05:28:17.321289
2019-12-11 05:28:17,321 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maasng.wait_for_http_code]
2019-12-11 05:28:17,322 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:17,430 [salt.state       :300 ][INFO    ][14333] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-12-11 05:28:17,431 [salt.state       :1951][INFO    ][14333] Completed state [maasng.wait_for_http_code] at time 05:28:17.431150 duration_in_ms=109.86
2019-12-11 05:28:17,432 [salt.state       :1780][INFO    ][14333] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:28:17.432354
2019-12-11 05:28:17,432 [salt.state       :1813][INFO    ][14333] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-12-11 05:28:17,433 [salt.state       :300 ][INFO    ][14333] /var/lib/maas/.setup_admin exists
2019-12-11 05:28:17,433 [salt.state       :1951][INFO    ][14333] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:28:17.433560 duration_in_ms=1.207
2019-12-11 05:28:17,434 [salt.state       :1780][INFO    ][14333] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:28:17.434378
2019-12-11 05:28:17,434 [salt.state       :1813][INFO    ][14333] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:28:17,435 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:28:18,840 [salt.state       :300 ][INFO    ][14333] {'pid': 14391, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:28:18,841 [salt.state       :1951][INFO    ][14333] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:28:18.840950 duration_in_ms=1406.571
2019-12-11 05:28:18,852 [salt.state       :1780][INFO    ][14333] Running state [maas_region_boot_source_resources_mirror] at time 05:28:18.852520
2019-12-11 05:28:18,853 [salt.state       :1813][INFO    ][14333] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-12-11 05:28:18,952 [salt.state       :300 ][INFO    ][14333] {'changes': {}}
2019-12-11 05:28:18,953 [salt.state       :1951][INFO    ][14333] Completed state [maas_region_boot_source_resources_mirror] at time 05:28:18.953351 duration_in_ms=100.83
2019-12-11 05:28:18,954 [salt.state       :1780][INFO    ][14333] Running state [maasng.boot_resources_import] at time 05:28:18.954513
2019-12-11 05:28:18,954 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maasng.boot_resources_import]
2019-12-11 05:28:18,955 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:19,029 [salt.loaded.ext.module.maasng:1600][INFO    ][14333] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-12-11 05:28:24,104 [salt.loaded.ext.module.maasng:1600][INFO    ][14333] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-12-11 05:28:27,831 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052827817983
2019-12-11 05:28:27,855 [salt.minion      :1432][INFO    ][14433] Starting a new job with PID 14433
2019-12-11 05:28:27,878 [salt.minion      :1711][INFO    ][14433] Returning information for job: 20191211052827817983
2019-12-11 05:28:29,171 [salt.loaded.ext.module.maasng:1600][INFO    ][14333] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-12-11 05:28:34,283 [salt.state       :300 ][INFO    ][14333] {'ret': True}
2019-12-11 05:28:34,284 [salt.state       :1951][INFO    ][14333] Completed state [maasng.boot_resources_import] at time 05:28:34.284073 duration_in_ms=15329.559
2019-12-11 05:28:34,285 [salt.state       :1780][INFO    ][14333] Running state [maas_region_boot_sources_selection_bionic] at time 05:28:34.285360
2019-12-11 05:28:34,285 [salt.state       :1813][INFO    ][14333] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-12-11 05:28:34,498 [salt.state       :300 ][INFO    ][14333] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-12-11 05:28:34,499 [salt.state       :1951][INFO    ][14333] Completed state [maas_region_boot_sources_selection_bionic] at time 05:28:34.499308 duration_in_ms=213.946
2019-12-11 05:28:34,500 [salt.state       :1780][INFO    ][14333] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:28:34.500790
2019-12-11 05:28:34,501 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-12-11 05:28:34,501 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:34,502 [salt.loaded.ext.module.maasng:1771][INFO    ][14333] boot-sources sync initiated for ALL Rack's
2019-12-11 05:28:35,426 [salt.state       :300 ][INFO    ][14333] {'ret': True}
2019-12-11 05:28:35,427 [salt.state       :1951][INFO    ][14333] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:28:35.426996 duration_in_ms=926.206
2019-12-11 05:28:35,429 [salt.state       :1780][INFO    ][14333] Running state [maas.process_maas_config] at time 05:28:35.429167
2019-12-11 05:28:35,429 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maas.process_maas_config]
2019-12-11 05:28:35,430 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:35,431 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=enable_http_proxy value=True
2019-12-11 05:28:35,495 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=upstream_dns value=8.8.8.8
2019-12-11 05:28:35,558 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=commissioning_distro_series value=bionic
2019-12-11 05:28:35,624 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=default_osystem value=ubuntu
2019-12-11 05:28:35,696 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=active_discovery_interval value=600
2019-12-11 05:28:35,756 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=dnssec_validation value=no
2019-12-11 05:28:38,748 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=maas_name value=mas01
2019-12-11 05:28:38,842 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=network_discovery value=enabled
2019-12-11 05:28:38,968 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=enable_third_party_drivers value=True
2019-12-11 05:28:39,028 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=default_storage_layout value=lvm
2019-12-11 05:28:39,086 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=ntp_external_only value=True
2019-12-11 05:28:39,145 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=disk_erase_with_secure_erase value=False
2019-12-11 05:28:39,199 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=default_distro_series value=bionic
2019-12-11 05:28:39,260 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-12-11 05:28:39,362 [salt.state       :300 ][INFO    ][14333] {'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-12-11 05:28:39,362 [salt.state       :1951][INFO    ][14333] Completed state [maas.process_maas_config] at time 05:28:39.362744 duration_in_ms=3933.577
2019-12-11 05:28:39,363 [salt.state       :1780][INFO    ][14333] Running state [pxe_admin] at time 05:28:39.363459
2019-12-11 05:28:39,363 [salt.state       :1813][INFO    ][14333] Executing state maasng.fabric_present for [pxe_admin]
2019-12-11 05:28:39,426 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:39,493 [salt.loaded.ext.module.maasng:1008][WARNING ][14333] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-12-11 05:28:39,493 [salt.loaded.ext.module.maasng:1011][WARNING ][14333] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-12-11 05:28:39,578 [salt.state       :300 ][INFO    ][14333] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-12-11 05:28:39,578 [salt.state       :1951][INFO    ][14333] Completed state [pxe_admin] at time 05:28:39.578755 duration_in_ms=215.296
2019-12-11 05:28:39,579 [salt.state       :1780][INFO    ][14333] Running state [vlan 0] at time 05:28:39.579124
2019-12-11 05:28:39,579 [salt.state       :1813][INFO    ][14333] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-11 05:28:39,644 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:39,776 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:40,067 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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': True, u'mtu': 1500, u'primary_rack': u'y78gra', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-12-11 05:28:40,166 [salt.state       :300 ][INFO    ][14333] {'new': 'Vlan untagged was updated'}
2019-12-11 05:28:40,166 [salt.state       :1951][INFO    ][14333] Completed state [vlan 0] at time 05:28:40.166484 duration_in_ms=587.358
2019-12-11 05:28:40,168 [salt.state       :1780][INFO    ][14333] Running state [192.168.11.0/24] at time 05:28:40.168041
2019-12-11 05:28:40,168 [salt.state       :1813][INFO    ][14333] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-12-11 05:28:40,374 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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'y78gra', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-12-11 05:28:40,375 [salt.loaded.ext.module.maasng:1235][WARNING ][14333] Ignoring parameter vlan:0
2019-12-11 05:28:40,453 [salt.state       :300 ][INFO    ][14333] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-12-11 05:28:40,454 [salt.state       :1951][INFO    ][14333] Completed state [192.168.11.0/24] at time 05:28:40.454289 duration_in_ms=286.248
2019-12-11 05:28:40,455 [salt.state       :1780][INFO    ][14333] Running state [maas_create_iprange_1] at time 05:28:40.455319
2019-12-11 05:28:40,455 [salt.state       :1813][INFO    ][14333] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-12-11 05:28:40,518 [salt.state       :300 ][INFO    ][14333] Iprange maas_create_iprange_1 already exist.
2019-12-11 05:28:40,519 [salt.state       :1951][INFO    ][14333] Completed state [maas_create_iprange_1] at time 05:28:40.519323 duration_in_ms=64.004
2019-12-11 05:28:40,519 [salt.state       :1780][INFO    ][14333] Running state [vlan 0] at time 05:28:40.519665
2019-12-11 05:28:40,519 [salt.state       :1813][INFO    ][14333] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-11 05:28:40,566 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:40,675 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'y78gra', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:40,883 [salt.loaded.ext.module.maasng:945 ][INFO    ][14333] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'y78gra', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-11 05:28:40,992 [salt.state       :300 ][INFO    ][14333] {'new': 'Vlan untagged was updated'}
2019-12-11 05:28:40,992 [salt.state       :1951][INFO    ][14333] Completed state [vlan 0] at time 05:28:40.992775 duration_in_ms=473.109
2019-12-11 05:28:40,993 [salt.state       :1780][INFO    ][14333] Running state [opnfv] at time 05:28:40.993662
2019-12-11 05:28:40,994 [salt.state       :1813][INFO    ][14333] Executing state maasng.sshkey_present for [opnfv]
2019-12-11 05:28:41,051 [salt.loaded.ext.module.maasng:1903][INFO    ][14333] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-12-11 05:28:41,051 [salt.state       :300 ][INFO    ][14333] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-12-11 05:28:41,052 [salt.state       :1951][INFO    ][14333] Completed state [opnfv] at time 05:28:41.052090 duration_in_ms=58.426
2019-12-11 05:28:41,053 [salt.state       :1780][INFO    ][14333] Running state [maas.process_tags] at time 05:28:41.053133
2019-12-11 05:28:41,053 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maas.process_tags]
2019-12-11 05:28:41,054 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:41,098 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-12-11 05:28:41,153 [salt.state       :300 ][INFO    ][14333] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-12-11 05:28:41,153 [salt.state       :1951][INFO    ][14333] Completed state [maas.process_tags] at time 05:28:41.153420 duration_in_ms=100.286
2019-12-11 05:28:41,156 [salt.minion      :1711][INFO    ][14333] Returning information for job: 20191211052812786990
2019-12-11 05:28:41,665 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211052841653657
2019-12-11 05:28:41,685 [salt.minion      :1432][INFO    ][14710] Starting a new job with PID 14710
2019-12-11 05:28:45,512 [salt.state       :915 ][INFO    ][14710] Loading fresh modules for state activity
2019-12-11 05:28:45,564 [salt.state       :1780][INFO    ][14710] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:28:45.564393
2019-12-11 05:28:45,564 [salt.state       :1813][INFO    ][14710] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:28:45,565 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14710] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:28:47,051 [salt.state       :300 ][INFO    ][14710] {'pid': 14735, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:28:47,052 [salt.state       :1951][INFO    ][14710] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:28:47.052325 duration_in_ms=1487.931
2019-12-11 05:28:47,053 [salt.state       :1780][INFO    ][14710] Running state [maas.process_machines] at time 05:28:47.053539
2019-12-11 05:28:47,053 [salt.state       :1813][INFO    ][14710] Executing state module.run for [maas.process_machines]
2019-12-11 05:28:47,054 [salt.utils.decorators:613 ][WARNING ][14710] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:28:47,747 [salt.loaded.ext.module.maas:412 ][WARNING ][14710] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:28:47,748 [salt.loaded.ext.module.maas:92  ][INFO    ][14710] 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=a8payb architecture=amd64/generic power_parameters_power_user=admin
2019-12-11 05:28:48,868 [salt.loaded.ext.module.maas:412 ][WARNING ][14710] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:28:48,869 [salt.loaded.ext.module.maas:92  ][INFO    ][14710] 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=d7hc4c architecture=amd64/generic power_parameters_power_user=admin
2019-12-11 05:28:50,149 [salt.loaded.ext.module.maas:412 ][WARNING ][14710] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:28:50,150 [salt.loaded.ext.module.maas:92  ][INFO    ][14710] 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=ya4mwd architecture=amd64/generic power_parameters_power_user=admin
2019-12-11 05:28:51,395 [salt.loaded.ext.module.maas:412 ][WARNING ][14710] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:28:51,396 [salt.loaded.ext.module.maas:92  ][INFO    ][14710] 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=8bgpb3 architecture=amd64/generic power_parameters_power_user=admin
2019-12-11 05:28:52,455 [salt.loaded.ext.module.maas:412 ][WARNING ][14710] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-11 05:28:52,456 [salt.loaded.ext.module.maas:92  ][INFO    ][14710] 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=pbfkht architecture=amd64/generic power_parameters_power_user=admin
2019-12-11 05:28:53,677 [salt.state       :300 ][INFO    ][14710] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-11 05:28:53,678 [salt.state       :1951][INFO    ][14710] Completed state [maas.process_machines] at time 05:28:53.678261 duration_in_ms=6624.719
2019-12-11 05:28:53,682 [salt.minion      :1711][INFO    ][14710] Returning information for job: 20191211052841653657
2019-12-11 05:29:26,055 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211052926004163
2019-12-11 05:29:26,073 [salt.minion      :1432][INFO    ][14992] Starting a new job with PID 14992
2019-12-11 05:29:29,850 [salt.state       :915 ][INFO    ][14992] Loading fresh modules for state activity
2019-12-11 05:29:29,948 [salt.state       :1780][INFO    ][14992] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:29:29.948032
2019-12-11 05:29:29,948 [salt.state       :1813][INFO    ][14992] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:29:29,950 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14992] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:29:31,540 [salt.state       :300 ][INFO    ][14992] {'pid': 15003, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:29:31,541 [salt.state       :1951][INFO    ][14992] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:29:31.541071 duration_in_ms=1593.038
2019-12-11 05:29:31,543 [salt.state       :1780][INFO    ][14992] Running state [maas.wait_for_machine_status] at time 05:29:31.543789
2019-12-11 05:29:31,544 [salt.state       :1813][INFO    ][14992] Executing state module.run for [maas.wait_for_machine_status]
2019-12-11 05:29:31,545 [salt.utils.decorators:613 ][WARNING ][14992] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:29:34,778 [salt.loaded.ext.module.maas:993 ][INFO    ][14992] Machine pbfkht mark broken
2019-12-11 05:29:35,413 [salt.loaded.ext.module.maas:996 ][INFO    ][14992] Machine pbfkht mark fixed
2019-12-11 05:29:36,596 [salt.loaded.ext.module.maas:684 ][INFO    ][14992] deploymachines hwe_kernel=ga-18.04 system_id=pbfkht distro_series=bionic
2019-12-11 05:29:38,617 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1492.94338202s left)
2019-12-11 05:29:41,135 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211052941122479
2019-12-11 05:29:41,157 [salt.minion      :1432][INFO    ][15086] Starting a new job with PID 15086
2019-12-11 05:29:41,183 [salt.minion      :1711][INFO    ][15086] Returning information for job: 20191211052941122479
2019-12-11 05:30:11,180 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053011167108
2019-12-11 05:30:11,202 [salt.minion      :1432][INFO    ][15120] Starting a new job with PID 15120
2019-12-11 05:30:11,227 [salt.minion      :1711][INFO    ][15120] Returning information for job: 20191211053011167108
2019-12-11 05:30:12,143 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1459.41760612s left)
2019-12-11 05:30:41,442 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053041391209
2019-12-11 05:30:41,463 [salt.minion      :1432][INFO    ][15161] Starting a new job with PID 15161
2019-12-11 05:30:41,486 [salt.minion      :1711][INFO    ][15161] Returning information for job: 20191211053041391209
2019-12-11 05:30:45,675 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1425.88520217s left)
2019-12-11 05:31:11,488 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053111472566
2019-12-11 05:31:11,510 [salt.minion      :1432][INFO    ][15193] Starting a new job with PID 15193
2019-12-11 05:31:11,534 [salt.minion      :1711][INFO    ][15193] Returning information for job: 20191211053111472566
2019-12-11 05:31:18,725 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1392.83564401s left)
2019-12-11 05:31:41,539 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053141524095
2019-12-11 05:31:41,562 [salt.minion      :1432][INFO    ][15292] Starting a new job with PID 15292
2019-12-11 05:31:41,587 [salt.minion      :1711][INFO    ][15292] Returning information for job: 20191211053141524095
2019-12-11 05:31:51,897 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.66309404s left)
2019-12-11 05:32:11,590 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053211578597
2019-12-11 05:32:11,613 [salt.minion      :1432][INFO    ][15416] Starting a new job with PID 15416
2019-12-11 05:32:11,640 [salt.minion      :1711][INFO    ][15416] Returning information for job: 20191211053211578597
2019-12-11 05:32:25,576 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1325.98425913s left)
2019-12-11 05:32:41,645 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053241632478
2019-12-11 05:32:41,667 [salt.minion      :1432][INFO    ][15504] Starting a new job with PID 15504
2019-12-11 05:32:41,693 [salt.minion      :1711][INFO    ][15504] Returning information for job: 20191211053241632478
2019-12-11 05:32:59,257 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1292.30314016s left)
2019-12-11 05:33:11,704 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053311691853
2019-12-11 05:33:11,727 [salt.minion      :1432][INFO    ][15583] Starting a new job with PID 15583
2019-12-11 05:33:11,753 [salt.minion      :1711][INFO    ][15583] Returning information for job: 20191211053311691853
2019-12-11 05:33:32,888 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1258.67300606s left)
2019-12-11 05:33:41,768 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053341755244
2019-12-11 05:33:41,787 [salt.minion      :1432][INFO    ][15625] Starting a new job with PID 15625
2019-12-11 05:33:41,812 [salt.minion      :1711][INFO    ][15625] Returning information for job: 20191211053341755244
2019-12-11 05:34:06,434 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1225.12642503s left)
2019-12-11 05:34:11,831 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053411817472
2019-12-11 05:34:11,853 [salt.minion      :1432][INFO    ][15675] Starting a new job with PID 15675
2019-12-11 05:34:11,879 [salt.minion      :1711][INFO    ][15675] Returning information for job: 20191211053411817472
2019-12-11 05:34:39,984 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.57693601s left)
2019-12-11 05:34:41,910 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053441896437
2019-12-11 05:34:41,931 [salt.minion      :1432][INFO    ][15737] Starting a new job with PID 15737
2019-12-11 05:34:41,957 [salt.minion      :1711][INFO    ][15737] Returning information for job: 20191211053441896437
2019-12-11 05:35:11,983 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053511971309
2019-12-11 05:35:12,004 [salt.minion      :1432][INFO    ][15821] Starting a new job with PID 15821
2019-12-11 05:35:12,030 [salt.minion      :1711][INFO    ][15821] Returning information for job: 20191211053511971309
2019-12-11 05:35:13,662 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1157.89904308s left)
2019-12-11 05:35:42,062 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053542049165
2019-12-11 05:35:42,085 [salt.minion      :1432][INFO    ][15892] Starting a new job with PID 15892
2019-12-11 05:35:42,111 [salt.minion      :1711][INFO    ][15892] Returning information for job: 20191211053542049165
2019-12-11 05:35:47,292 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.26814413s left)
2019-12-11 05:36:12,152 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053612138430
2019-12-11 05:36:12,174 [salt.minion      :1432][INFO    ][15985] Starting a new job with PID 15985
2019-12-11 05:36:12,199 [salt.minion      :1711][INFO    ][15985] Returning information for job: 20191211053612138430
2019-12-11 05:36:20,924 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1090.63614297s left)
2019-12-11 05:36:42,245 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053642232313
2019-12-11 05:36:42,269 [salt.minion      :1432][INFO    ][16031] Starting a new job with PID 16031
2019-12-11 05:36:42,296 [salt.minion      :1711][INFO    ][16031] Returning information for job: 20191211053642232313
2019-12-11 05:36:54,110 [salt.loaded.ext.module.maas:1023][INFO    ][14992] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1057.45069408s left)
2019-12-11 05:37:12,350 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command saltutil.find_job with jid 20191211053712334005
2019-12-11 05:37:12,375 [salt.minion      :1432][INFO    ][16098] Starting a new job with PID 16098
2019-12-11 05:37:12,414 [salt.minion      :1711][INFO    ][16098] Returning information for job: 20191211053712334005
2019-12-11 05:37:27,704 [salt.state       :300 ][INFO    ][14992] {'ret': True}
2019-12-11 05:37:27,704 [salt.state       :1951][INFO    ][14992] Completed state [maas.wait_for_machine_status] at time 05:37:27.704572 duration_in_ms=476160.782
2019-12-11 05:37:27,708 [salt.minion      :1711][INFO    ][14992] Returning information for job: 20191211052926004163
2019-12-11 05:37:28,350 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211053728337065
2019-12-11 05:37:28,371 [salt.minion      :1432][INFO    ][16152] Starting a new job with PID 16152
2019-12-11 05:37:32,198 [salt.state       :915 ][INFO    ][16152] Loading fresh modules for state activity
2019-12-11 05:37:32,334 [salt.state       :1780][INFO    ][16152] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:32.333959
2019-12-11 05:37:32,334 [salt.state       :1813][INFO    ][16152] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:37:32,336 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16152] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:37:33,792 [salt.state       :300 ][INFO    ][16152] {'pid': 16159, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:37:33,793 [salt.state       :1951][INFO    ][16152] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:33.793518 duration_in_ms=1459.559
2019-12-11 05:37:33,796 [salt.state       :1780][INFO    ][16152] Running state [maas_machines_storage_cmp002_lvm] at time 05:37:33.796540
2019-12-11 05:37:33,797 [salt.state       :1813][INFO    ][16152] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-11 05:37:34,477 [salt.state       :300 ][INFO    ][16152] Machine cmp002 is not in Ready state.
2019-12-11 05:37:34,477 [salt.state       :1951][INFO    ][16152] Completed state [maas_machines_storage_cmp002_lvm] at time 05:37:34.477480 duration_in_ms=680.94
2019-12-11 05:37:34,478 [salt.state       :1780][INFO    ][16152] Running state [maas_machines_storage_cmp001_lvm] at time 05:37:34.478021
2019-12-11 05:37:34,478 [salt.state       :1813][INFO    ][16152] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-11 05:37:35,134 [salt.state       :300 ][INFO    ][16152] Machine cmp001 is not in Ready state.
2019-12-11 05:37:35,134 [salt.state       :1951][INFO    ][16152] Completed state [maas_machines_storage_cmp001_lvm] at time 05:37:35.134727 duration_in_ms=656.706
2019-12-11 05:37:35,138 [salt.minion      :1711][INFO    ][16152] Returning information for job: 20191211053728337065
2019-12-11 05:37:35,729 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211053735720317
2019-12-11 05:37:35,753 [salt.minion      :1432][INFO    ][16169] Starting a new job with PID 16169
2019-12-11 05:37:36,548 [salt.state       :915 ][INFO    ][16169] Loading fresh modules for state activity
2019-12-11 05:37:36,640 [salt.state       :1780][INFO    ][16169] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:36.640053
2019-12-11 05:37:36,640 [salt.state       :1813][INFO    ][16169] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:37:36,642 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16169] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:37:38,098 [salt.state       :300 ][INFO    ][16169] {'pid': 16177, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:37:38,099 [salt.state       :1951][INFO    ][16169] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:38.099362 duration_in_ms=1459.309
2019-12-11 05:37:38,100 [salt.state       :1780][INFO    ][16169] Running state [maas.deploy_machines] at time 05:37:38.100603
2019-12-11 05:37:38,100 [salt.state       :1813][INFO    ][16169] Executing state module.run for [maas.deploy_machines]
2019-12-11 05:37:38,101 [salt.utils.decorators:613 ][WARNING ][16169] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:37:39,053 [salt.state       :300 ][INFO    ][16169] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-11 05:37:39,054 [salt.state       :1951][INFO    ][16169] Completed state [maas.deploy_machines] at time 05:37:39.054080 duration_in_ms=953.475
2019-12-11 05:37:39,057 [salt.minion      :1711][INFO    ][16169] Returning information for job: 20191211053735720317
2019-12-11 05:37:39,686 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command state.apply with jid 20191211053739676838
2019-12-11 05:37:39,707 [salt.minion      :1432][INFO    ][16189] Starting a new job with PID 16189
2019-12-11 05:37:40,451 [salt.state       :915 ][INFO    ][16189] Loading fresh modules for state activity
2019-12-11 05:37:40,544 [salt.state       :1780][INFO    ][16189] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:40.544365
2019-12-11 05:37:40,544 [salt.state       :1813][INFO    ][16189] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-11 05:37:40,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16189] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-11 05:37:42,072 [salt.state       :300 ][INFO    ][16189] {'pid': 16212, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-11 05:37:42,073 [salt.state       :1951][INFO    ][16189] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:42.073089 duration_in_ms=1528.723
2019-12-11 05:37:42,076 [salt.state       :1780][INFO    ][16189] Running state [maas.wait_for_machine_status] at time 05:37:42.076661
2019-12-11 05:37:42,077 [salt.state       :1813][INFO    ][16189] Executing state module.run for [maas.wait_for_machine_status]
2019-12-11 05:37:42,078 [salt.utils.decorators:613 ][WARNING ][16189] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-11 05:37:45,722 [salt.state       :300 ][INFO    ][16189] {'ret': True}
2019-12-11 05:37:45,722 [salt.state       :1951][INFO    ][16189] Completed state [maas.wait_for_machine_status] at time 05:37:45.722832 duration_in_ms=3646.169
2019-12-11 05:37:45,726 [salt.minion      :1711][INFO    ][16189] Returning information for job: 20191211053739676838
2019-12-11 06:07:21,216 [salt.utils.schedule:1377][INFO    ][8375] Running scheduled job: __mine_interval
2019-12-11 07:07:21,217 [salt.utils.schedule:1377][INFO    ][8375] Running scheduled job: __mine_interval
2019-12-11 07:07:29,382 [salt.minion      :1308][INFO    ][8375] User sudo_ubuntu Executing command cp.push_dir with jid 20191211070729370568
2019-12-11 07:07:29,399 [salt.minion      :1432][INFO    ][22585] Starting a new job with PID 22585
