2019-09-13 05:08:11,991 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-13 05:09:02,024 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-13 05:09:52,065 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-13 05:10:42,110 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-13 05:11:32,158 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-13 05:13:41,752 [salt.utils.decorators:613 ][WARNING ][2624] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 05:13:42,327 [salt.utils.decorators:613 ][WARNING ][2624] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 05:13:44,555 [salt.loaded.int.states.file:2298][WARNING ][2768] 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-09-13 05:13:50,238 [salt.state       :2022][WARNING ][2873] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-13 05:13:52,866 [salt.utils.decorators:613 ][WARNING ][2873] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 05:29:01,604 [salt.utils.decorators:613 ][WARNING ][2873] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 05:53:55,416 [salt.utils.decorators:613 ][WARNING ][2873] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:08:57,045 [salt.utils.decorators:613 ][WARNING ][2873] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:09:01,032 [salt.loaded.ext.module.maasng:1008][WARNING ][2873] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-09-13 06:09:01,032 [salt.loaded.ext.module.maasng:1011][WARNING ][2873] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-09-13 06:09:01,694 [salt.loaded.ext.module.maasng:1235][WARNING ][2873] Ignoring parameter vlan:0
2019-09-13 06:09:02,547 [salt.utils.decorators:613 ][WARNING ][2873] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:09:08,499 [salt.utils.decorators:613 ][WARNING ][5996] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:09:08,579 [salt.loaded.ext.module.maas:412 ][WARNING ][5996] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:09:12,478 [salt.loaded.ext.module.maas:412 ][WARNING ][5996] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:09:16,059 [salt.loaded.ext.module.maas:412 ][WARNING ][5996] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:09:18,659 [salt.loaded.ext.module.maas:412 ][WARNING ][5996] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:09:22,759 [salt.loaded.ext.module.maas:412 ][WARNING ][5996] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:09:27,661 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6845] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-13 06:09:27,690 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6845] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-09-13 06:09:27,711 [salt.utils.parsers:1051][WARNING ][361] Minion received a SIGTERM. Exiting.
2019-09-13 06:09:28,770 [salt.cli.daemons :293 ][INFO    ][6894] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-09-13 06:09:28,870 [salt.cli.daemons :82  ][INFO    ][6894] Starting up the Salt Minion
2019-09-13 06:09:28,870 [salt.utils.event :1017][INFO    ][6894] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-09-13 06:09:29,793 [salt.minion      :976 ][INFO    ][6894] Creating minion process manager
2019-09-13 06:09:31,299 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6894] Executing command ['date', '+%z'] in directory '/root'
2019-09-13 06:09:31,318 [salt.utils.schedule:568 ][INFO    ][6894] Updating job settings for scheduled job: __mine_interval
2019-09-13 06:09:31,319 [salt.minion      :1108][INFO    ][6894] Added mine.update to scheduler
2019-09-13 06:09:31,323 [salt.minion      :1975][INFO    ][6894] Minion is starting as user 'root'
2019-09-13 06:09:31,337 [salt.minion      :2336][INFO    ][6894] Minion is ready to receive requests!
2019-09-13 06:09:56,884 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913060956871507
2019-09-13 06:09:56,906 [salt.minion      :1432][INFO    ][7020] Starting a new job with PID 7020
2019-09-13 06:10:00,784 [salt.state       :915 ][INFO    ][7020] Loading fresh modules for state activity
2019-09-13 06:10:00,812 [salt.fileclient  :1219][INFO    ][7020] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-09-13 06:10:00,839 [salt.state       :1780][INFO    ][7020] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:10:00.839136
2019-09-13 06:10:00,839 [salt.state       :1813][INFO    ][7020] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:10:00,840 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7020] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:10:02,311 [salt.state       :300 ][INFO    ][7020] {'pid': 7028, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:10:02,312 [salt.state       :1951][INFO    ][7020] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:10:02.312283 duration_in_ms=1473.145
2019-09-13 06:10:02,315 [salt.state       :1780][INFO    ][7020] Running state [maas.wait_for_machine_status] at time 06:10:02.315659
2019-09-13 06:10:02,316 [salt.state       :1813][INFO    ][7020] Executing state module.run for [maas.wait_for_machine_status]
2019-09-13 06:10:02,316 [salt.utils.decorators:613 ][WARNING ][7020] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:10:03,299 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.02750301s left)
2019-09-13 06:10:11,965 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061011951781
2019-09-13 06:10:11,988 [salt.minion      :1432][INFO    ][7040] Starting a new job with PID 7040
2019-09-13 06:10:12,013 [salt.minion      :1711][INFO    ][7040] Returning information for job: 20190913061011951781
2019-09-13 06:10:34,251 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.07550907s left)
2019-09-13 06:10:42,016 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061042003785
2019-09-13 06:10:42,039 [salt.minion      :1432][INFO    ][7059] Starting a new job with PID 7059
2019-09-13 06:10:42,063 [salt.minion      :1711][INFO    ][7059] Returning information for job: 20190913061042003785
2019-09-13 06:11:05,438 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.88886213s left)
2019-09-13 06:11:12,065 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061112052159
2019-09-13 06:11:12,084 [salt.minion      :1432][INFO    ][7255] Starting a new job with PID 7255
2019-09-13 06:11:12,104 [salt.minion      :1711][INFO    ][7255] Returning information for job: 20190913061112052159
2019-09-13 06:11:36,857 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.46926594s left)
2019-09-13 06:11:42,108 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061142095753
2019-09-13 06:11:42,131 [salt.minion      :1432][INFO    ][7374] Starting a new job with PID 7374
2019-09-13 06:11:42,155 [salt.minion      :1711][INFO    ][7374] Returning information for job: 20190913061142095753
2019-09-13 06:12:08,637 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.68915796s left)
2019-09-13 06:12:12,160 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061212148307
2019-09-13 06:12:12,183 [salt.minion      :1432][INFO    ][8093] Starting a new job with PID 8093
2019-09-13 06:12:12,205 [salt.minion      :1711][INFO    ][8093] Returning information for job: 20190913061212148307
2019-09-13 06:12:40,249 [salt.loaded.ext.module.maas:1023][INFO    ][7020] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.077425s left)
2019-09-13 06:12:42,211 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061242197289
2019-09-13 06:12:42,233 [salt.minion      :1432][INFO    ][8114] Starting a new job with PID 8114
2019-09-13 06:12:42,258 [salt.minion      :1711][INFO    ][8114] Returning information for job: 20190913061242197289
2019-09-13 06:13:12,273 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061312260746
2019-09-13 06:13:12,296 [salt.minion      :1432][INFO    ][8339] Starting a new job with PID 8339
2019-09-13 06:13:12,320 [salt.minion      :1711][INFO    ][8339] Returning information for job: 20190913061312260746
2019-09-13 06:13:13,720 [salt.state       :300 ][INFO    ][7020] {'ret': True}
2019-09-13 06:13:13,720 [salt.state       :1951][INFO    ][7020] Completed state [maas.wait_for_machine_status] at time 06:13:13.720810 duration_in_ms=191405.149
2019-09-13 06:13:13,724 [salt.minion      :1711][INFO    ][7020] Returning information for job: 20190913060956871507
2019-09-13 06:13:14,331 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913061314317762
2019-09-13 06:13:14,354 [salt.minion      :1432][INFO    ][8348] Starting a new job with PID 8348
2019-09-13 06:13:18,063 [salt.state       :915 ][INFO    ][8348] Loading fresh modules for state activity
2019-09-13 06:13:18,116 [salt.fileclient  :1219][INFO    ][8348] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-09-13 06:13:18,208 [salt.state       :1780][INFO    ][8348] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:13:18.208845
2019-09-13 06:13:18,209 [salt.state       :1813][INFO    ][8348] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:13:18,210 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8348] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:13:19,762 [salt.state       :300 ][INFO    ][8348] {'pid': 8359, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:13:19,763 [salt.state       :1951][INFO    ][8348] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:13:19.763382 duration_in_ms=1554.536
2019-09-13 06:13:19,766 [salt.state       :1780][INFO    ][8348] Running state [maas_machines_storage_cmp002_lvm] at time 06:13:19.766524
2019-09-13 06:13:19,767 [salt.state       :1813][INFO    ][8348] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-13 06:13:21,300 [salt.loaded.ext.module.maasng:610 ][INFO    ][8348] 8xy7cb
2019-09-13 06:13:21,301 [salt.loaded.ext.module.maasng:626 ][INFO    ][8348] sda
2019-09-13 06:13:22,024 [salt.loaded.ext.module.maasng:361 ][INFO    ][8348] 8xy7cb
2019-09-13 06:13:22,159 [salt.loaded.ext.module.maasng:367 ][INFO    ][8348] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'5d77fb6c-1cca-4c4e-91eb-6e746dd730c8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8xy7cb', u'device_id': 3, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'46b9f241-a699-4526-9358-5ce9b2bc1e2a', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/partition/5'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'system_id': u'8xy7cb', u'partition_table_type': u'GPT', u'available_size': 0, u'id': 3, u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/10/', u'uuid': u'33d95bb1-5431-4ad8-a857-d40aeff549fd', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'03aa9fb3-cb26-4823-8f98-84de649d487e', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'8xy7cb', u'partition_table_type': None, u'available_size': 0, u'id': 10, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'name': u'vgroot-lvroot'}]
2019-09-13 06:13:22,160 [salt.loaded.ext.module.maasng:632 ][INFO    ][8348] vgroot
2019-09-13 06:13:22,161 [salt.loaded.ext.module.maasng:635 ][INFO    ][8348] lvroot
2019-09-13 06:13:22,161 [salt.loaded.ext.module.maasng:639 ][INFO    ][8348] 107374182400
2019-09-13 06:13:22,850 [salt.loaded.ext.module.maasng:645 ][INFO    ][8348] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.41'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 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': 33}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'effective_mtu': 1500, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'8xy7cb', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/interfaces/4/'}, u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'8xy7cb', 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'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'95065f3b-a4a8-4fe2-9296-ba93fe0e35fc', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'8xy7cb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'54931e18-1381-4e96-b85c-3a1db76a02ea', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/12/', u'type': u'virtual', u'id': 12, u'size': 107374182400}], u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'91d6d2f2-c2ad-423e-bfd8-69b33d73a728', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8xy7cb', u'device_id': 3, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'74b1af30-ae5f-4d42-96f0-955f03a3bf57', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'8xy7cb', 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'block_size': 4096, u'type': u'physical', u'id': 3, u'size': 2397998940160}, {u'model': None, u'uuid': u'95065f3b-a4a8-4fe2-9296-ba93fe0e35fc', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/12/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'8xy7cb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'54931e18-1381-4e96-b85c-3a1db76a02ea', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 12, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'8xy7cb', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'model': u'UCSB-MRAID12G', 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'91d6d2f2-c2ad-423e-bfd8-69b33d73a728', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8xy7cb', u'device_id': 3, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'74b1af30-ae5f-4d42-96f0-955f03a3bf57', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8xy7cb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/', u'type': u'physical', u'id': 3, u'size': 2397998940160}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 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': 33}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'effective_mtu': 1500, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'8xy7cb', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/interfaces/4/'}, {u'name': u'enp8s0', u'links': [{u'id': 35, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'system_id': u'8xy7cb', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/interfaces/15/'}, {u'name': u'enp9s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'system_id': u'8xy7cb', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/interfaces/16/'}, {u'name': u'enp7s0', u'links': [{u'id': 38, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'system_id': u'8xy7cb', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/interfaces/17/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', 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'91d6d2f2-c2ad-423e-bfd8-69b33d73a728', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8xy7cb', u'device_id': 3, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'74b1af30-ae5f-4d42-96f0-955f03a3bf57', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8xy7cb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/8xy7cb/blockdevices/3/', u'type': u'physical', u'id': 3, u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'min_hwe_kernel': u'hwe-16.04', u'current_commissioning_result_id': 2, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/8xy7cb/'}
2019-09-13 06:13:22,853 [salt.state       :300 ][INFO    ][8348] {'new': {'storage_layout': 'lvm'}}
2019-09-13 06:13:22,853 [salt.state       :1951][INFO    ][8348] Completed state [maas_machines_storage_cmp002_lvm] at time 06:13:22.853343 duration_in_ms=3086.817
2019-09-13 06:13:22,854 [salt.state       :1780][INFO    ][8348] Running state [maas_machines_storage_cmp001_lvm] at time 06:13:22.853981
2019-09-13 06:13:22,854 [salt.state       :1813][INFO    ][8348] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-13 06:13:24,266 [salt.loaded.ext.module.maasng:610 ][INFO    ][8348] pkqtxg
2019-09-13 06:13:24,267 [salt.loaded.ext.module.maasng:626 ][INFO    ][8348] sda
2019-09-13 06:13:24,980 [salt.loaded.ext.module.maasng:361 ][INFO    ][8348] pkqtxg
2019-09-13 06:13:25,118 [salt.loaded.ext.module.maasng:367 ][INFO    ][8348] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/', u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'90a27f14-b17a-408b-921e-4618fb1f52aa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pkqtxg', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'81e35303-8ad8-45ea-8229-dd48c71a0073', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/partition/3'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'pkqtxg', u'partition_table_type': u'GPT', u'available_size': 0, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/8/', u'uuid': u'c11e03e0-b815-4b0f-9599-4e8765a281a1', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c3610419-ef42-4491-b84e-453b7802654b', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'pkqtxg', u'partition_table_type': None, u'available_size': 0, u'id': 8, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'name': u'vgroot-lvroot'}]
2019-09-13 06:13:25,118 [salt.loaded.ext.module.maasng:632 ][INFO    ][8348] vgroot
2019-09-13 06:13:25,119 [salt.loaded.ext.module.maasng:635 ][INFO    ][8348] lvroot
2019-09-13 06:13:25,119 [salt.loaded.ext.module.maasng:639 ][INFO    ][8348] 107374182400
2019-09-13 06:13:25,850 [salt.loaded.ext.module.maasng:645 ][INFO    ][8348] {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'swap_size': None, u'ip_addresses': [u'192.168.11.38'], u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.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'boot_disk': {u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pkqtxg', 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'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'626c001b-2d03-4456-a9a2-f2083dfa882e', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pkqtxg', u'filesystem': {u'uuid': u'31812445-b60a-4cba-9ac1-ec699fe28e62', 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'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/partition/8'}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'pkqtxg', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/13/', u'available_size': 0, u'uuid': u'65ebbf3b-c880-471b-9b11-8f482ed3b84e', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pkqtxg', u'partition_table_type': None, u'filesystem': {u'uuid': u'f43db88c-29a5-410a-b0fd-90bf9dcb2fa2', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 13, u'serial': None, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pkqtxg', 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'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'626c001b-2d03-4456-a9a2-f2083dfa882e', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pkqtxg', u'filesystem': {u'uuid': u'31812445-b60a-4cba-9ac1-ec699fe28e62', 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'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/partition/8'}]}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/13/', u'available_size': 0, u'uuid': u'65ebbf3b-c880-471b-9b11-8f482ed3b84e', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pkqtxg', u'partition_table_type': None, u'filesystem': {u'uuid': u'f43db88c-29a5-410a-b0fd-90bf9dcb2fa2', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 13, u'serial': None, u'partitions': []}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'pkqtxg', u'id': 8}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pkqtxg', 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'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'626c001b-2d03-4456-a9a2-f2083dfa882e', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pkqtxg', u'filesystem': {u'uuid': u'31812445-b60a-4cba-9ac1-ec699fe28e62', 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'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/blockdevices/1/partition/8'}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'commissioning_status': 2, 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'primary_rack': u'c88d4w', 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.38', u'id': 24, u'mode': u'dhcp'}], 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'primary_rack': u'c88d4w', 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'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'primary_rack': u'c88d4w', 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.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'pkqtxg', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/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'primary_rack': u'c88d4w', 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.38', u'id': 24, u'mode': u'dhcp'}], 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'primary_rack': u'c88d4w', 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'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'primary_rack': u'c88d4w', 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.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'pkqtxg', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'id': 25, u'mode': u'link_up'}], 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'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'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'pkqtxg', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/interfaces/9/'}, {u'name': u'enp9s0', u'links': [{u'id': 26, u'mode': u'link_up'}], 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'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'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'pkqtxg', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'id': 27, u'mode': u'link_up'}], 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'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'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'pkqtxg', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/pkqtxg/interfaces/13/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/pkqtxg/'}
2019-09-13 06:13:25,853 [salt.state       :300 ][INFO    ][8348] {'new': {'storage_layout': 'lvm'}}
2019-09-13 06:13:25,854 [salt.state       :1951][INFO    ][8348] Completed state [maas_machines_storage_cmp001_lvm] at time 06:13:25.854102 duration_in_ms=3000.119
2019-09-13 06:13:25,859 [salt.minion      :1711][INFO    ][8348] Returning information for job: 20190913061314317762
2019-09-13 06:13:26,469 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913061326458110
2019-09-13 06:13:26,488 [salt.minion      :1432][INFO    ][8407] Starting a new job with PID 8407
2019-09-13 06:13:27,153 [salt.state       :915 ][INFO    ][8407] Loading fresh modules for state activity
2019-09-13 06:13:27,203 [salt.fileclient  :1219][INFO    ][8407] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-09-13 06:13:27,243 [salt.state       :1780][INFO    ][8407] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:13:27.243764
2019-09-13 06:13:27,244 [salt.state       :1813][INFO    ][8407] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:13:27,245 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8407] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:13:28,716 [salt.state       :300 ][INFO    ][8407] {'pid': 8414, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:13:28,717 [salt.state       :1951][INFO    ][8407] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:13:28.717397 duration_in_ms=1473.634
2019-09-13 06:13:28,718 [salt.state       :1780][INFO    ][8407] Running state [maas.deploy_machines] at time 06:13:28.718610
2019-09-13 06:13:28,718 [salt.state       :1813][INFO    ][8407] Executing state module.run for [maas.deploy_machines]
2019-09-13 06:13:28,719 [salt.utils.decorators:613 ][WARNING ][8407] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:13:29,168 [salt.loaded.ext.module.maas:684 ][INFO    ][8407] deploymachines hwe_kernel=hwe-16.04 system_id=8xy7cb distro_series=xenial
2019-09-13 06:13:35,834 [salt.loaded.ext.module.maas:684 ][INFO    ][8407] deploymachines hwe_kernel=hwe-16.04 system_id=pkqtxg distro_series=xenial
2019-09-13 06:13:41,538 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061341525461
2019-09-13 06:13:41,562 [salt.minion      :1432][INFO    ][8519] Starting a new job with PID 8519
2019-09-13 06:13:41,585 [salt.minion      :1711][INFO    ][8519] Returning information for job: 20190913061341525461
2019-09-13 06:13:42,641 [salt.loaded.ext.module.maas:684 ][INFO    ][8407] deploymachines hwe_kernel=hwe-16.04 system_id=gp4agm distro_series=xenial
2019-09-13 06:13:48,928 [salt.loaded.ext.module.maas:684 ][INFO    ][8407] deploymachines hwe_kernel=hwe-16.04 system_id=g3mwft distro_series=xenial
2019-09-13 06:13:55,626 [salt.loaded.ext.module.maas:684 ][INFO    ][8407] deploymachines hwe_kernel=hwe-16.04 system_id=tbqhmq distro_series=xenial
2019-09-13 06:14:00,988 [salt.state       :300 ][INFO    ][8407] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-09-13 06:14:00,989 [salt.state       :1951][INFO    ][8407] Completed state [maas.deploy_machines] at time 06:14:00.989194 duration_in_ms=32270.582
2019-09-13 06:14:00,992 [salt.minion      :1711][INFO    ][8407] Returning information for job: 20190913061326458110
2019-09-13 06:14:01,509 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913061401493533
2019-09-13 06:14:01,526 [salt.minion      :1432][INFO    ][8783] Starting a new job with PID 8783
2019-09-13 06:14:05,074 [salt.state       :915 ][INFO    ][8783] Loading fresh modules for state activity
2019-09-13 06:14:05,098 [salt.fileclient  :1219][INFO    ][8783] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-09-13 06:14:05,123 [salt.state       :1780][INFO    ][8783] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:05.123041
2019-09-13 06:14:05,123 [salt.state       :1813][INFO    ][8783] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:14:05,124 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8783] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:14:06,579 [salt.state       :300 ][INFO    ][8783] {'pid': 8800, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:14:06,579 [salt.state       :1951][INFO    ][8783] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:06.579837 duration_in_ms=1456.796
2019-09-13 06:14:06,581 [salt.state       :1780][INFO    ][8783] Running state [maas.wait_for_machine_status] at time 06:14:06.581714
2019-09-13 06:14:06,582 [salt.state       :1813][INFO    ][8783] Executing state module.run for [maas.wait_for_machine_status]
2019-09-13 06:14:06,582 [salt.utils.decorators:613 ][WARNING ][8783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:14:16,596 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061416585197
2019-09-13 06:14:16,617 [salt.minion      :1432][INFO    ][8851] Starting a new job with PID 8851
2019-09-13 06:14:16,639 [salt.minion      :1711][INFO    ][8851] Returning information for job: 20190913061416585197
2019-09-13 06:14:46,659 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061446650472
2019-09-13 06:14:46,681 [salt.minion      :1432][INFO    ][8914] Starting a new job with PID 8914
2019-09-13 06:14:46,702 [salt.minion      :1711][INFO    ][8914] Returning information for job: 20190913061446650472
2019-09-13 06:15:16,773 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061516762713
2019-09-13 06:15:16,795 [salt.minion      :1432][INFO    ][8969] Starting a new job with PID 8969
2019-09-13 06:15:16,817 [salt.minion      :1711][INFO    ][8969] Returning information for job: 20190913061516762713
2019-09-13 06:15:46,818 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061546809622
2019-09-13 06:15:46,832 [salt.minion      :1432][INFO    ][9115] Starting a new job with PID 9115
2019-09-13 06:15:46,850 [salt.minion      :1711][INFO    ][9115] Returning information for job: 20190913061546809622
2019-09-13 06:16:16,879 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061616867570
2019-09-13 06:16:16,900 [salt.minion      :1432][INFO    ][9189] Starting a new job with PID 9189
2019-09-13 06:16:16,922 [salt.minion      :1711][INFO    ][9189] Returning information for job: 20190913061616867570
2019-09-13 06:16:46,955 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061646945186
2019-09-13 06:16:46,975 [salt.minion      :1432][INFO    ][9217] Starting a new job with PID 9217
2019-09-13 06:16:46,999 [salt.minion      :1711][INFO    ][9217] Returning information for job: 20190913061646945186
2019-09-13 06:17:17,034 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061717022791
2019-09-13 06:17:17,059 [salt.minion      :1432][INFO    ][9289] Starting a new job with PID 9289
2019-09-13 06:17:17,089 [salt.minion      :1711][INFO    ][9289] Returning information for job: 20190913061717022791
2019-09-13 06:17:47,134 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061747121507
2019-09-13 06:17:47,153 [salt.minion      :1432][INFO    ][9321] Starting a new job with PID 9321
2019-09-13 06:17:47,172 [salt.minion      :1711][INFO    ][9321] Returning information for job: 20190913061747121507
2019-09-13 06:18:17,213 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061817200349
2019-09-13 06:18:17,236 [salt.minion      :1432][INFO    ][9377] Starting a new job with PID 9377
2019-09-13 06:18:17,257 [salt.minion      :1711][INFO    ][9377] Returning information for job: 20190913061817200349
2019-09-13 06:18:47,303 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061847293924
2019-09-13 06:18:47,321 [salt.minion      :1432][INFO    ][9411] Starting a new job with PID 9411
2019-09-13 06:18:47,345 [salt.minion      :1711][INFO    ][9411] Returning information for job: 20190913061847293924
2019-09-13 06:19:17,403 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913061917390538
2019-09-13 06:19:17,425 [salt.minion      :1432][INFO    ][9527] Starting a new job with PID 9527
2019-09-13 06:19:17,449 [salt.minion      :1711][INFO    ][9527] Returning information for job: 20190913061917390538
2019-09-13 06:19:39,765 [salt.state       :302 ][ERROR   ][8783] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-09-13 06:19:39,766 [salt.state       :1951][INFO    ][8783] Completed state [maas.wait_for_machine_status] at time 06:19:39.766003 duration_in_ms=333184.287
2019-09-13 06:19:39,769 [salt.minion      :1711][INFO    ][8783] Returning information for job: 20190913061401493533
2019-09-13 06:19:50,524 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command pillar.get with jid 20190913061950511441
2019-09-13 06:19:50,547 [salt.minion      :1432][INFO    ][9897] Starting a new job with PID 9897
2019-09-13 06:19:50,554 [salt.minion      :1711][INFO    ][9897] Returning information for job: 20190913061950511441
2019-09-13 06:19:51,063 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command service.status with jid 20190913061951051316
2019-09-13 06:19:51,085 [salt.minion      :1432][INFO    ][9902] Starting a new job with PID 9902
2019-09-13 06:19:51,479 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9902] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-13 06:19:51,514 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9902] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-13 06:19:51,529 [salt.minion      :1711][INFO    ][9902] Returning information for job: 20190913061951051316
2019-09-13 06:19:52,032 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913061952019162
2019-09-13 06:19:52,053 [salt.minion      :1432][INFO    ][9913] Starting a new job with PID 9913
2019-09-13 06:19:55,547 [salt.state       :915 ][INFO    ][9913] Loading fresh modules for state activity
2019-09-13 06:19:55,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:19:56,269 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:19:57,230 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:19:57,600 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:19:59,038 [salt.state       :1780][INFO    ][9913] Running state [salt-minion] at time 06:19:59.038704
2019-09-13 06:19:59,039 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [salt-minion]
2019-09-13 06:19:59,039 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:19:59,123 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,123 [salt.state       :1951][INFO    ][9913] Completed state [salt-minion] at time 06:19:59.123783 duration_in_ms=85.079
2019-09-13 06:19:59,124 [salt.state       :1780][INFO    ][9913] Running state [salt_minion_dependency_packages] at time 06:19:59.124103
2019-09-13 06:19:59,124 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-13 06:19:59,130 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,130 [salt.state       :1951][INFO    ][9913] Completed state [salt_minion_dependency_packages] at time 06:19:59.130835 duration_in_ms=6.732
2019-09-13 06:19:59,133 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/minion.d/minion.conf] at time 06:19:59.133815
2019-09-13 06:19:59,134 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-13 06:19:59,357 [salt.state       :300 ][INFO    ][9913] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-13 06:19:59,357 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/minion.d/minion.conf] at time 06:19:59.357745 duration_in_ms=223.929
2019-09-13 06:19:59,358 [salt.state       :1780][INFO    ][9913] Running state [python-netaddr] at time 06:19:59.358049
2019-09-13 06:19:59,358 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [python-netaddr]
2019-09-13 06:19:59,366 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,366 [salt.state       :1951][INFO    ][9913] Completed state [python-netaddr] at time 06:19:59.366761 duration_in_ms=8.712
2019-09-13 06:19:59,370 [salt.state       :1780][INFO    ][9913] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:19:59.370474
2019-09-13 06:19:59,370 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-13 06:19:59,382 [salt.state       :300 ][INFO    ][9913] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-13 06:19:59,383 [salt.state       :1951][INFO    ][9913] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:19:59.383079 duration_in_ms=12.605
2019-09-13 06:19:59,384 [salt.state       :1780][INFO    ][9913] Running state [salt-minion] at time 06:19:59.384312
2019-09-13 06:19:59,384 [salt.state       :1813][INFO    ][9913] Executing state service.running for [salt-minion]
2019-09-13 06:19:59,385 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-13 06:19:59,428 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-13 06:19:59,447 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-13 06:19:59,465 [salt.state       :300 ][INFO    ][9913] The service salt-minion is already running
2019-09-13 06:19:59,465 [salt.state       :1951][INFO    ][9913] Completed state [salt-minion] at time 06:19:59.465625 duration_in_ms=81.312
2019-09-13 06:19:59,467 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains.d] at time 06:19:59.467711
2019-09-13 06:19:59,468 [salt.state       :1813][INFO    ][9913] Executing state file.directory for [/etc/salt/grains.d]
2019-09-13 06:19:59,469 [salt.state       :300 ][INFO    ][9913] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-13 06:19:59,469 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains.d] at time 06:19:59.469699 duration_in_ms=1.989
2019-09-13 06:19:59,470 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains] at time 06:19:59.470626
2019-09-13 06:19:59,471 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/grains]
2019-09-13 06:19:59,471 [salt.state       :300 ][INFO    ][9913] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-13 06:19:59,472 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains] at time 06:19:59.472038 duration_in_ms=1.411
2019-09-13 06:19:59,472 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains.d/placeholder] at time 06:19:59.472678
2019-09-13 06:19:59,473 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-13 06:19:59,473 [salt.state       :300 ][INFO    ][9913] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-13 06:19:59,474 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains.d/placeholder] at time 06:19:59.474051 duration_in_ms=1.374
2019-09-13 06:19:59,474 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains.d/sphinx] at time 06:19:59.474692
2019-09-13 06:19:59,475 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-13 06:19:59,512 [salt.state       :300 ][INFO    ][9913] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-13 06:19:59,513 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains.d/sphinx] at time 06:19:59.513310 duration_in_ms=38.617
2019-09-13 06:19:59,517 [salt.state       :1780][INFO    ][9913] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.517064
2019-09-13 06:19:59,517 [salt.state       :1813][INFO    ][9913] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:19:59,518 [salt.state       :300 ][INFO    ][9913] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:19:59,518 [salt.state       :1951][INFO    ][9913] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.518520 duration_in_ms=1.456
2019-09-13 06:19:59,519 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains.d/dns_records] at time 06:19:59.519354
2019-09-13 06:19:59,519 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-13 06:19:59,530 [salt.state       :300 ][INFO    ][9913] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-13 06:19:59,531 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains.d/dns_records] at time 06:19:59.531208 duration_in_ms=11.855
2019-09-13 06:19:59,532 [salt.state       :1780][INFO    ][9913] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.532734
2019-09-13 06:19:59,533 [salt.state       :1813][INFO    ][9913] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:19:59,533 [salt.state       :300 ][INFO    ][9913] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:19:59,534 [salt.state       :1951][INFO    ][9913] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.534062 duration_in_ms=1.327
2019-09-13 06:19:59,534 [salt.state       :1780][INFO    ][9913] Running state [/etc/salt/grains.d/salt] at time 06:19:59.534837
2019-09-13 06:19:59,535 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-13 06:19:59,548 [salt.state       :300 ][INFO    ][9913] File /etc/salt/grains.d/salt is in the correct state
2019-09-13 06:19:59,549 [salt.state       :1951][INFO    ][9913] Completed state [/etc/salt/grains.d/salt] at time 06:19:59.549188 duration_in_ms=14.351
2019-09-13 06:19:59,550 [salt.state       :1780][INFO    ][9913] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.550662
2019-09-13 06:19:59,551 [salt.state       :1813][INFO    ][9913] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:19:59,551 [salt.state       :300 ][INFO    ][9913] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:19:59,552 [salt.state       :1951][INFO    ][9913] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:19:59.551999 duration_in_ms=1.337
2019-09-13 06:19:59,555 [salt.state       :1780][INFO    ][9913] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:19:59.555146
2019-09-13 06:19:59,555 [salt.state       :1813][INFO    ][9913] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-13 06:19:59,556 [salt.state       :300 ][INFO    ][9913] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-13 06:19:59,556 [salt.state       :1951][INFO    ][9913] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:19:59.556507 duration_in_ms=1.361
2019-09-13 06:19:59,557 [salt.state       :1780][INFO    ][9913] Running state [mine.update] at time 06:19:59.557614
2019-09-13 06:19:59,558 [salt.state       :1813][INFO    ][9913] Executing state module.wait for [mine.update]
2019-09-13 06:19:59,558 [salt.state       :300 ][INFO    ][9913] No changes made for mine.update
2019-09-13 06:19:59,558 [salt.state       :1951][INFO    ][9913] Completed state [mine.update] at time 06:19:59.558845 duration_in_ms=1.232
2019-09-13 06:19:59,559 [salt.state       :1780][INFO    ][9913] Running state [ca-certificates] at time 06:19:59.559233
2019-09-13 06:19:59,559 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [ca-certificates]
2019-09-13 06:19:59,570 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,571 [salt.state       :1951][INFO    ][9913] Completed state [ca-certificates] at time 06:19:59.571121 duration_in_ms=11.887
2019-09-13 06:19:59,572 [salt.state       :1780][INFO    ][9913] Running state [update-ca-certificates] at time 06:19:59.572148
2019-09-13 06:19:59,572 [salt.state       :1813][INFO    ][9913] Executing state cmd.wait for [update-ca-certificates]
2019-09-13 06:19:59,573 [salt.state       :300 ][INFO    ][9913] No changes made for update-ca-certificates
2019-09-13 06:19:59,573 [salt.state       :1951][INFO    ][9913] Completed state [update-ca-certificates] at time 06:19:59.573282 duration_in_ms=1.135
2019-09-13 06:19:59,573 [salt.state       :1780][INFO    ][9913] Running state [iptables] at time 06:19:59.573646
2019-09-13 06:19:59,574 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [iptables]
2019-09-13 06:19:59,583 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,584 [salt.state       :1951][INFO    ][9913] Completed state [iptables] at time 06:19:59.584209 duration_in_ms=10.562
2019-09-13 06:19:59,584 [salt.state       :1780][INFO    ][9913] Running state [iptables-persistent] at time 06:19:59.584558
2019-09-13 06:19:59,584 [salt.state       :1813][INFO    ][9913] Executing state pkg.installed for [iptables-persistent]
2019-09-13 06:19:59,594 [salt.state       :300 ][INFO    ][9913] All specified packages are already installed
2019-09-13 06:19:59,594 [salt.state       :1951][INFO    ][9913] Completed state [iptables-persistent] at time 06:19:59.594593 duration_in_ms=10.035
2019-09-13 06:19:59,595 [salt.state       :1780][INFO    ][9913] Running state [iptables_modules_v4_load] at time 06:19:59.595927
2019-09-13 06:19:59,596 [salt.state       :1813][INFO    ][9913] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-13 06:19:59,597 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'lsmod' in directory '/root'
2019-09-13 06:19:59,621 [salt.state       :300 ][INFO    ][9913] Kernel modules iptable_filter, ip_tables are already present
2019-09-13 06:19:59,621 [salt.state       :1951][INFO    ][9913] Completed state [iptables_modules_v4_load] at time 06:19:59.621708 duration_in_ms=25.781
2019-09-13 06:19:59,622 [salt.state       :1780][INFO    ][9913] Running state [/etc/iptables/rules.v4] at time 06:19:59.622661
2019-09-13 06:19:59,623 [salt.state       :1813][INFO    ][9913] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-13 06:19:59,728 [salt.state       :300 ][INFO    ][9913] File /etc/iptables/rules.v4 is in the correct state
2019-09-13 06:19:59,728 [salt.state       :1951][INFO    ][9913] Completed state [/etc/iptables/rules.v4] at time 06:19:59.728735 duration_in_ms=106.074
2019-09-13 06:19:59,729 [salt.state       :1780][INFO    ][9913] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:19:59.729796
2019-09-13 06:19:59,730 [salt.state       :1813][INFO    ][9913] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-13 06:19:59,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-13 06:19:59,749 [salt.state       :300 ][INFO    ][9913] onlyif execution failed
2019-09-13 06:19:59,749 [salt.state       :1951][INFO    ][9913] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:19:59.749619 duration_in_ms=19.822
2019-09-13 06:19:59,750 [salt.state       :1780][INFO    ][9913] Running state [netfilter-persistent] at time 06:19:59.750621
2019-09-13 06:19:59,751 [salt.state       :1813][INFO    ][9913] Executing state service.running for [netfilter-persistent]
2019-09-13 06:19:59,751 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-13 06:19:59,771 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-13 06:19:59,789 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-13 06:19:59,807 [salt.state       :300 ][INFO    ][9913] The service netfilter-persistent is already running
2019-09-13 06:19:59,807 [salt.state       :1951][INFO    ][9913] Completed state [netfilter-persistent] at time 06:19:59.807639 duration_in_ms=57.018
2019-09-13 06:19:59,809 [salt.state       :1780][INFO    ][9913] Running state [iptables_extra.remove_stale_tables] at time 06:19:59.808988
2019-09-13 06:19:59,809 [salt.state       :1813][INFO    ][9913] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-13 06:19:59,810 [salt.state       :300 ][INFO    ][9913] No changes made for iptables_extra.remove_stale_tables
2019-09-13 06:19:59,810 [salt.state       :1951][INFO    ][9913] Completed state [iptables_extra.remove_stale_tables] at time 06:19:59.810345 duration_in_ms=1.356
2019-09-13 06:19:59,810 [salt.state       :1780][INFO    ][9913] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:19:59.810746
2019-09-13 06:19:59,811 [salt.state       :1813][INFO    ][9913] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-13 06:19:59,812 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9913] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-13 06:19:59,826 [salt.state       :300 ][INFO    ][9913] onlyif execution failed
2019-09-13 06:19:59,827 [salt.state       :1951][INFO    ][9913] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:19:59.827145 duration_in_ms=16.398
2019-09-13 06:19:59,828 [salt.state       :1780][INFO    ][9913] Running state [/etc/iptables/rules.v6] at time 06:19:59.828592
2019-09-13 06:19:59,829 [salt.state       :1813][INFO    ][9913] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-13 06:19:59,829 [salt.state       :300 ][INFO    ][9913] File /etc/iptables/rules.v6 is not present
2019-09-13 06:19:59,830 [salt.state       :1951][INFO    ][9913] Completed state [/etc/iptables/rules.v6] at time 06:19:59.830040 duration_in_ms=1.448
2019-09-13 06:19:59,831 [salt.state       :1780][INFO    ][9913] Running state [iptables_extra.flush_all] at time 06:19:59.831059
2019-09-13 06:19:59,831 [salt.state       :1813][INFO    ][9913] Executing state module.wait for [iptables_extra.flush_all]
2019-09-13 06:19:59,831 [salt.state       :300 ][INFO    ][9913] No changes made for iptables_extra.flush_all
2019-09-13 06:19:59,832 [salt.state       :1951][INFO    ][9913] Completed state [iptables_extra.flush_all] at time 06:19:59.832205 duration_in_ms=1.146
2019-09-13 06:19:59,836 [salt.minion      :1711][INFO    ][9913] Returning information for job: 20190913061952019162
2019-09-13 06:20:00,469 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062000455958
2019-09-13 06:20:00,491 [salt.minion      :1432][INFO    ][10339] Starting a new job with PID 10339
2019-09-13 06:20:01,250 [salt.state       :915 ][INFO    ][10339] Loading fresh modules for state activity
2019-09-13 06:20:01,893 [salt.state       :1780][INFO    ][10339] Running state [maas-rack-controller] at time 06:20:01.893645
2019-09-13 06:20:01,894 [salt.state       :1813][INFO    ][10339] Executing state pkg.installed for [maas-rack-controller]
2019-09-13 06:20:01,894 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10339] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:20:01,978 [salt.state       :300 ][INFO    ][10339] All specified packages are already installed
2019-09-13 06:20:01,978 [salt.state       :1951][INFO    ][10339] Completed state [maas-rack-controller] at time 06:20:01.978385 duration_in_ms=84.741
2019-09-13 06:20:01,978 [salt.state       :1780][INFO    ][10339] Running state [ipmitool] at time 06:20:01.978696
2019-09-13 06:20:01,978 [salt.state       :1813][INFO    ][10339] Executing state pkg.installed for [ipmitool]
2019-09-13 06:20:01,984 [salt.state       :300 ][INFO    ][10339] All specified packages are already installed
2019-09-13 06:20:01,984 [salt.state       :1951][INFO    ][10339] Completed state [ipmitool] at time 06:20:01.984751 duration_in_ms=6.054
2019-09-13 06:20:01,987 [salt.state       :1780][INFO    ][10339] Running state [/etc/maas/rackd.conf] at time 06:20:01.987416
2019-09-13 06:20:01,987 [salt.state       :1813][INFO    ][10339] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-13 06:20:01,988 [salt.state       :300 ][INFO    ][10339] No changes needed to be made
2019-09-13 06:20:01,988 [salt.state       :1951][INFO    ][10339] Completed state [/etc/maas/rackd.conf] at time 06:20:01.988788 duration_in_ms=1.373
2019-09-13 06:20:01,989 [salt.state       :1780][INFO    ][10339] Running state [/etc/maas/rackd.conf] at time 06:20:01.988991
2019-09-13 06:20:01,989 [salt.state       :1813][INFO    ][10339] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-13 06:20:01,989 [salt.loaded.int.states.file:2298][WARNING ][10339] 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-09-13 06:20:01,989 [salt.state       :300 ][INFO    ][10339] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-13 06:20:01,990 [salt.state       :1951][INFO    ][10339] Completed state [/etc/maas/rackd.conf] at time 06:20:01.990106 duration_in_ms=1.116
2019-09-13 06:20:01,990 [salt.state       :1780][INFO    ][10339] Running state [maas-rackd] at time 06:20:01.990929
2019-09-13 06:20:01,991 [salt.state       :1813][INFO    ][10339] Executing state service.running for [maas-rackd]
2019-09-13 06:20:01,991 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10339] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-13 06:20:02,024 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10339] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-13 06:20:02,038 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10339] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-13 06:20:02,051 [salt.state       :300 ][INFO    ][10339] The service maas-rackd is already running
2019-09-13 06:20:02,052 [salt.state       :1951][INFO    ][10339] Completed state [maas-rackd] at time 06:20:02.052099 duration_in_ms=61.17
2019-09-13 06:20:02,053 [salt.minion      :1711][INFO    ][10339] Returning information for job: 20190913062000455958
2019-09-13 06:20:02,521 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062002511324
2019-09-13 06:20:02,535 [salt.minion      :1432][INFO    ][10370] Starting a new job with PID 10370
2019-09-13 06:20:03,152 [salt.state       :915 ][INFO    ][10370] Loading fresh modules for state activity
2019-09-13 06:20:03,831 [salt.state       :1780][INFO    ][10370] Running state [maas-region-controller] at time 06:20:03.831466
2019-09-13 06:20:03,831 [salt.state       :1813][INFO    ][10370] Executing state pkg.installed for [maas-region-controller]
2019-09-13 06:20:03,832 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:20:03,901 [salt.state       :300 ][INFO    ][10370] All specified packages are already installed
2019-09-13 06:20:03,902 [salt.state       :1951][INFO    ][10370] Completed state [maas-region-controller] at time 06:20:03.901981 duration_in_ms=70.514
2019-09-13 06:20:03,902 [salt.state       :1780][INFO    ][10370] Running state [python-oauth] at time 06:20:03.902311
2019-09-13 06:20:03,902 [salt.state       :1813][INFO    ][10370] Executing state pkg.installed for [python-oauth]
2019-09-13 06:20:03,907 [salt.state       :300 ][INFO    ][10370] All specified packages are already installed
2019-09-13 06:20:03,907 [salt.state       :1951][INFO    ][10370] Completed state [python-oauth] at time 06:20:03.907372 duration_in_ms=5.061
2019-09-13 06:20:03,909 [salt.state       :1780][INFO    ][10370] Running state [/etc/maas/regiond.conf] at time 06:20:03.909744
2019-09-13 06:20:03,910 [salt.state       :1813][INFO    ][10370] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-13 06:20:03,985 [salt.state       :300 ][INFO    ][10370] No changes needed to be made
2019-09-13 06:20:03,985 [salt.state       :1951][INFO    ][10370] Completed state [/etc/maas/regiond.conf] at time 06:20:03.985563 duration_in_ms=75.817
2019-09-13 06:20:03,986 [salt.state       :1780][INFO    ][10370] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:20:03.986327
2019-09-13 06:20:03,986 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-13 06:20:04,050 [salt.state       :300 ][INFO    ][10370] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-13 06:20:04,050 [salt.state       :1951][INFO    ][10370] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:20:04.050661 duration_in_ms=64.333
2019-09-13 06:20:04,051 [salt.state       :1780][INFO    ][10370] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:20:04.051364
2019-09-13 06:20:04,051 [salt.state       :1813][INFO    ][10370] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-13 06:20:04,063 [salt.state       :300 ][INFO    ][10370] No changes needed to be made
2019-09-13 06:20:04,063 [salt.state       :1951][INFO    ][10370] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:20:04.063767 duration_in_ms=12.402
2019-09-13 06:20:04,064 [salt.state       :1780][INFO    ][10370] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:20:04.064385
2019-09-13 06:20:04,064 [salt.state       :1813][INFO    ][10370] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-13 06:20:04,087 [salt.state       :300 ][INFO    ][10370] No changes needed to be made
2019-09-13 06:20:04,087 [salt.state       :1951][INFO    ][10370] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:20:04.087761 duration_in_ms=23.375
2019-09-13 06:20:04,088 [salt.state       :1780][INFO    ][10370] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:20:04.088390
2019-09-13 06:20:04,088 [salt.state       :1813][INFO    ][10370] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-13 06:20:04,110 [salt.state       :300 ][INFO    ][10370] No changes needed to be made
2019-09-13 06:20:04,110 [salt.state       :1951][INFO    ][10370] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:20:04.110655 duration_in_ms=22.264
2019-09-13 06:20:04,111 [salt.state       :1780][INFO    ][10370] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:20:04.111225
2019-09-13 06:20:04,111 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-13 06:20:04,122 [salt.state       :300 ][INFO    ][10370] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-13 06:20:04,122 [salt.state       :1951][INFO    ][10370] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:20:04.122447 duration_in_ms=11.222
2019-09-13 06:20:04,123 [salt.state       :1780][INFO    ][10370] Running state [a2enmod headers] at time 06:20:04.123719
2019-09-13 06:20:04,124 [salt.state       :1813][INFO    ][10370] Executing state cmd.run for [a2enmod headers]
2019-09-13 06:20:04,124 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command 'a2enmod headers' in directory '/root'
2019-09-13 06:20:04,170 [salt.state       :300 ][INFO    ][10370] {'pid': 10394, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-13 06:20:04,171 [salt.state       :1951][INFO    ][10370] Completed state [a2enmod headers] at time 06:20:04.171228 duration_in_ms=47.509
2019-09-13 06:20:04,171 [salt.state       :1780][INFO    ][10370] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:20:04.171629
2019-09-13 06:20:04,172 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-13 06:20:04,183 [salt.state       :300 ][INFO    ][10370] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-13 06:20:04,183 [salt.state       :1951][INFO    ][10370] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:20:04.183917 duration_in_ms=12.287
2019-09-13 06:20:04,184 [salt.state       :1780][INFO    ][10370] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:20:04.184449
2019-09-13 06:20:04,184 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-13 06:20:04,260 [salt.state       :300 ][INFO    ][10370] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-13 06:20:04,260 [salt.state       :1951][INFO    ][10370] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:20:04.260748 duration_in_ms=76.298
2019-09-13 06:20:04,261 [salt.state       :1780][INFO    ][10370] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:20:04.261558
2019-09-13 06:20:04,262 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-13 06:20:04,320 [salt.state       :300 ][INFO    ][10370] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-13 06:20:04,320 [salt.state       :1951][INFO    ][10370] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:20:04.320439 duration_in_ms=58.88
2019-09-13 06:20:04,321 [salt.state       :1780][INFO    ][10370] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:20:04.321154
2019-09-13 06:20:04,321 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-13 06:20:04,404 [salt.state       :300 ][INFO    ][10370] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-13 06:20:04,404 [salt.state       :1951][INFO    ][10370] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:20:04.404875 duration_in_ms=83.718
2019-09-13 06:20:04,405 [salt.state       :1780][INFO    ][10370] Running state [/root/.pgpass] at time 06:20:04.405440
2019-09-13 06:20:04,406 [salt.state       :1813][INFO    ][10370] Executing state file.managed for [/root/.pgpass]
2019-09-13 06:20:04,451 [salt.state       :300 ][INFO    ][10370] File /root/.pgpass is in the correct state
2019-09-13 06:20:04,451 [salt.state       :1951][INFO    ][10370] Completed state [/root/.pgpass] at time 06:20:04.451928 duration_in_ms=46.487
2019-09-13 06:20:04,456 [salt.state       :1780][INFO    ][10370] Running state [maas-region syncdb --noinput] at time 06:20:04.456666
2019-09-13 06:20:04,457 [salt.state       :1813][INFO    ][10370] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-13 06:20:04,457 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-13 06:20:06,363 [salt.state       :300 ][INFO    ][10370] {'pid': 10407, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: contenttypes, piston3, sites, maasserver, auth, sessions, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-09-13 06:20:06,364 [salt.state       :1951][INFO    ][10370] Completed state [maas-region syncdb --noinput] at time 06:20:06.364424 duration_in_ms=1907.756
2019-09-13 06:20:06,364 [salt.state       :2022][WARNING ][10370] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-13 06:20:06,368 [salt.state       :1780][INFO    ][10370] Running state [maas-regiond] at time 06:20:06.368024
2019-09-13 06:20:06,368 [salt.state       :1813][INFO    ][10370] Executing state service.running for [maas-regiond]
2019-09-13 06:20:06,370 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-13 06:20:06,411 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-13 06:20:06,430 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-13 06:20:06,449 [salt.state       :300 ][INFO    ][10370] The service maas-regiond is already running
2019-09-13 06:20:06,449 [salt.state       :1951][INFO    ][10370] Completed state [maas-regiond] at time 06:20:06.449660 duration_in_ms=81.635
2019-09-13 06:20:06,452 [salt.state       :1780][INFO    ][10370] Running state [bind9] at time 06:20:06.452545
2019-09-13 06:20:06,453 [salt.state       :1813][INFO    ][10370] Executing state service.running for [bind9]
2019-09-13 06:20:06,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-13 06:20:06,474 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-13 06:20:06,491 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-13 06:20:06,509 [salt.state       :300 ][INFO    ][10370] The service bind9 is already running
2019-09-13 06:20:06,509 [salt.state       :1951][INFO    ][10370] Completed state [bind9] at time 06:20:06.509460 duration_in_ms=56.915
2019-09-13 06:20:06,512 [salt.state       :1780][INFO    ][10370] Running state [apache2] at time 06:20:06.512106
2019-09-13 06:20:06,512 [salt.state       :1813][INFO    ][10370] Executing state service.running for [apache2]
2019-09-13 06:20:06,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-13 06:20:06,532 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-13 06:20:06,549 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-13 06:20:06,570 [salt.state       :300 ][INFO    ][10370] The service apache2 is already running
2019-09-13 06:20:06,571 [salt.state       :1951][INFO    ][10370] Completed state [apache2] at time 06:20:06.570960 duration_in_ms=58.854
2019-09-13 06:20:06,573 [salt.state       :1780][INFO    ][10370] Running state [maasng.wait_for_http_code] at time 06:20:06.573225
2019-09-13 06:20:06,573 [salt.state       :1813][INFO    ][10370] Executing state module.run for [maasng.wait_for_http_code]
2019-09-13 06:20:06,574 [salt.utils.decorators:613 ][WARNING ][10370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:06,583 [salt.state       :300 ][INFO    ][10370] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-13 06:20:06,584 [salt.state       :1951][INFO    ][10370] Completed state [maasng.wait_for_http_code] at time 06:20:06.583972 duration_in_ms=10.747
2019-09-13 06:20:06,585 [salt.state       :1780][INFO    ][10370] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:20:06.585400
2019-09-13 06:20:06,585 [salt.state       :1813][INFO    ][10370] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-13 06:20:06,586 [salt.state       :300 ][INFO    ][10370] /var/lib/maas/.setup_admin exists
2019-09-13 06:20:06,587 [salt.state       :1951][INFO    ][10370] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:20:06.587071 duration_in_ms=1.67
2019-09-13 06:20:06,588 [salt.state       :1780][INFO    ][10370] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:20:06.588287
2019-09-13 06:20:06,588 [salt.state       :1813][INFO    ][10370] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:20:06,589 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10370] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:20:07,961 [salt.state       :300 ][INFO    ][10370] {'pid': 10426, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:20:07,962 [salt.state       :1951][INFO    ][10370] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:20:07.962322 duration_in_ms=1374.036
2019-09-13 06:20:07,966 [salt.state       :1780][INFO    ][10370] Running state [maas_region_boot_source_resources_mirror] at time 06:20:07.966172
2019-09-13 06:20:07,966 [salt.state       :1813][INFO    ][10370] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-13 06:20:08,074 [salt.state       :300 ][INFO    ][10370] {'changes': {}}
2019-09-13 06:20:08,074 [salt.state       :1951][INFO    ][10370] Completed state [maas_region_boot_source_resources_mirror] at time 06:20:08.074807 duration_in_ms=108.634
2019-09-13 06:20:08,075 [salt.state       :1780][INFO    ][10370] Running state [maasng.boot_resources_import] at time 06:20:08.075910
2019-09-13 06:20:08,076 [salt.state       :1813][INFO    ][10370] Executing state module.run for [maasng.boot_resources_import]
2019-09-13 06:20:08,077 [salt.utils.decorators:613 ][WARNING ][10370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:08,177 [salt.loaded.ext.module.maasng:1600][INFO    ][10370] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-13 06:20:13,239 [salt.loaded.ext.module.maasng:1600][INFO    ][10370] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-13 06:20:17,639 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062017626957
2019-09-13 06:20:17,663 [salt.minion      :1432][INFO    ][10468] Starting a new job with PID 10468
2019-09-13 06:20:17,688 [salt.minion      :1711][INFO    ][10468] Returning information for job: 20190913062017626957
2019-09-13 06:20:18,299 [salt.loaded.ext.module.maasng:1600][INFO    ][10370] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-13 06:20:23,395 [salt.state       :300 ][INFO    ][10370] {'ret': True}
2019-09-13 06:20:23,396 [salt.state       :1951][INFO    ][10370] Completed state [maasng.boot_resources_import] at time 06:20:23.396237 duration_in_ms=15320.326
2019-09-13 06:20:23,397 [salt.state       :1780][INFO    ][10370] Running state [maas_region_boot_sources_selection_xenial] at time 06:20:23.397514
2019-09-13 06:20:23,398 [salt.state       :1813][INFO    ][10370] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-13 06:20:23,611 [salt.state       :300 ][INFO    ][10370] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-13 06:20:23,611 [salt.state       :1951][INFO    ][10370] Completed state [maas_region_boot_sources_selection_xenial] at time 06:20:23.611394 duration_in_ms=213.882
2019-09-13 06:20:23,612 [salt.state       :1780][INFO    ][10370] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:20:23.612802
2019-09-13 06:20:23,613 [salt.state       :1813][INFO    ][10370] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-13 06:20:23,613 [salt.utils.decorators:613 ][WARNING ][10370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:23,614 [salt.loaded.ext.module.maasng:1771][INFO    ][10370] boot-sources sync initiated for ALL Rack's
2019-09-13 06:20:24,754 [salt.state       :300 ][INFO    ][10370] {'ret': True}
2019-09-13 06:20:24,755 [salt.state       :1951][INFO    ][10370] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:20:24.755260 duration_in_ms=1142.458
2019-09-13 06:20:24,757 [salt.state       :1780][INFO    ][10370] Running state [maas.process_maas_config] at time 06:20:24.757356
2019-09-13 06:20:24,757 [salt.state       :1813][INFO    ][10370] Executing state module.run for [maas.process_maas_config]
2019-09-13 06:20:24,758 [salt.utils.decorators:613 ][WARNING ][10370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:24,759 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=enable_http_proxy value=True
2019-09-13 06:20:24,824 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=upstream_dns value=8.8.8.8
2019-09-13 06:20:24,893 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=commissioning_distro_series value=xenial
2019-09-13 06:20:24,977 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=default_osystem value=ubuntu
2019-09-13 06:20:25,042 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=active_discovery_interval value=600
2019-09-13 06:20:25,102 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=dnssec_validation value=no
2019-09-13 06:20:25,156 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=maas_name value=mas01
2019-09-13 06:20:25,210 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=network_discovery value=enabled
2019-09-13 06:20:25,330 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=enable_third_party_drivers value=True
2019-09-13 06:20:25,384 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=default_storage_layout value=lvm
2019-09-13 06:20:25,444 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=ntp_external_only value=True
2019-09-13 06:20:28,133 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-13 06:20:28,186 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=default_distro_series value=xenial
2019-09-13 06:20:28,246 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-09-13 06:20:28,397 [salt.state       :300 ][INFO    ][10370] {'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-09-13 06:20:28,398 [salt.state       :1951][INFO    ][10370] Completed state [maas.process_maas_config] at time 06:20:28.397933 duration_in_ms=3640.577
2019-09-13 06:20:28,398 [salt.state       :1780][INFO    ][10370] Running state [pxe_admin] at time 06:20:28.398920
2019-09-13 06:20:28,399 [salt.state       :1813][INFO    ][10370] Executing state maasng.fabric_present for [pxe_admin]
2019-09-13 06:20:28,467 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:28,539 [salt.loaded.ext.module.maasng:1008][WARNING ][10370] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-13 06:20:28,539 [salt.loaded.ext.module.maasng:1011][WARNING ][10370] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-13 06:20:28,599 [salt.state       :300 ][INFO    ][10370] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-13 06:20:28,599 [salt.state       :1951][INFO    ][10370] Completed state [pxe_admin] at time 06:20:28.599829 duration_in_ms=200.908
2019-09-13 06:20:28,600 [salt.state       :1780][INFO    ][10370] Running state [vlan 0] at time 06:20:28.600286
2019-09-13 06:20:28,600 [salt.state       :1813][INFO    ][10370] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-13 06:20:28,665 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:28,785 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:29,063 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-09-13 06:20:29,156 [salt.state       :300 ][INFO    ][10370] {'new': 'Vlan untagged was updated'}
2019-09-13 06:20:29,157 [salt.state       :1951][INFO    ][10370] Completed state [vlan 0] at time 06:20:29.157319 duration_in_ms=557.033
2019-09-13 06:20:29,158 [salt.state       :1780][INFO    ][10370] Running state [192.168.11.0/24] at time 06:20:29.158682
2019-09-13 06:20:29,159 [salt.state       :1813][INFO    ][10370] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-13 06:20:29,377 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:29,378 [salt.loaded.ext.module.maasng:1235][WARNING ][10370] Ignoring parameter vlan:0
2019-09-13 06:20:29,468 [salt.state       :300 ][INFO    ][10370] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-13 06:20:29,468 [salt.state       :1951][INFO    ][10370] Completed state [192.168.11.0/24] at time 06:20:29.468808 duration_in_ms=310.126
2019-09-13 06:20:29,469 [salt.state       :1780][INFO    ][10370] Running state [maas_create_iprange_1] at time 06:20:29.469759
2019-09-13 06:20:29,470 [salt.state       :1813][INFO    ][10370] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-13 06:20:29,606 [salt.state       :300 ][INFO    ][10370] Iprange maas_create_iprange_1 already exist.
2019-09-13 06:20:29,606 [salt.state       :1951][INFO    ][10370] Completed state [maas_create_iprange_1] at time 06:20:29.606555 duration_in_ms=136.795
2019-09-13 06:20:29,607 [salt.state       :1780][INFO    ][10370] Running state [vlan 0] at time 06:20:29.607007
2019-09-13 06:20:29,607 [salt.state       :1813][INFO    ][10370] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-13 06:20:29,666 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:29,773 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:30,042 [salt.loaded.ext.module.maasng:945 ][INFO    ][10370] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:20:30,127 [salt.state       :300 ][INFO    ][10370] {'new': 'Vlan untagged was updated'}
2019-09-13 06:20:30,128 [salt.state       :1951][INFO    ][10370] Completed state [vlan 0] at time 06:20:30.128049 duration_in_ms=521.042
2019-09-13 06:20:30,128 [salt.state       :1780][INFO    ][10370] Running state [opnfv] at time 06:20:30.128906
2019-09-13 06:20:30,129 [salt.state       :1813][INFO    ][10370] Executing state maasng.sshkey_present for [opnfv]
2019-09-13 06:20:30,174 [salt.loaded.ext.module.maasng:1903][INFO    ][10370] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-09-13 06:20:30,175 [salt.state       :300 ][INFO    ][10370] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-13 06:20:30,175 [salt.state       :1951][INFO    ][10370] Completed state [opnfv] at time 06:20:30.175317 duration_in_ms=46.412
2019-09-13 06:20:30,176 [salt.state       :1780][INFO    ][10370] Running state [maas.process_tags] at time 06:20:30.175977
2019-09-13 06:20:30,176 [salt.state       :1813][INFO    ][10370] Executing state module.run for [maas.process_tags]
2019-09-13 06:20:30,176 [salt.utils.decorators:613 ][WARNING ][10370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:30,223 [salt.loaded.ext.module.maas:92  ][INFO    ][10370] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-09-13 06:20:30,283 [salt.state       :300 ][INFO    ][10370] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-09-13 06:20:30,284 [salt.state       :1951][INFO    ][10370] Completed state [maas.process_tags] at time 06:20:30.284223 duration_in_ms=108.246
2019-09-13 06:20:30,288 [salt.minion      :1711][INFO    ][10370] Returning information for job: 20190913062002511324
2019-09-13 06:20:30,848 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062030836338
2019-09-13 06:20:30,872 [salt.minion      :1432][INFO    ][10836] Starting a new job with PID 10836
2019-09-13 06:20:34,564 [salt.state       :915 ][INFO    ][10836] Loading fresh modules for state activity
2019-09-13 06:20:34,655 [salt.state       :1780][INFO    ][10836] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:20:34.655439
2019-09-13 06:20:34,655 [salt.state       :1813][INFO    ][10836] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:20:34,658 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10836] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:20:36,134 [salt.state       :300 ][INFO    ][10836] {'pid': 10859, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:20:36,135 [salt.state       :1951][INFO    ][10836] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:20:36.135197 duration_in_ms=1479.756
2019-09-13 06:20:36,137 [salt.state       :1780][INFO    ][10836] Running state [maas.process_machines] at time 06:20:36.137810
2019-09-13 06:20:36,138 [salt.state       :1813][INFO    ][10836] Executing state module.run for [maas.process_machines]
2019-09-13 06:20:36,139 [salt.utils.decorators:613 ][WARNING ][10836] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:20:36,917 [salt.loaded.ext.module.maas:412 ][WARNING ][10836] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:20:36,918 [salt.loaded.ext.module.maas:92  ][INFO    ][10836] 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=8xy7cb architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:20:38,248 [salt.loaded.ext.module.maas:412 ][WARNING ][10836] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:20:38,248 [salt.loaded.ext.module.maas:92  ][INFO    ][10836] 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=pkqtxg architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:20:39,543 [salt.loaded.ext.module.maas:412 ][WARNING ][10836] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:20:39,545 [salt.loaded.ext.module.maas:92  ][INFO    ][10836] 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=gp4agm architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:20:40,817 [salt.loaded.ext.module.maas:412 ][WARNING ][10836] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:20:40,818 [salt.loaded.ext.module.maas:92  ][INFO    ][10836] 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=g3mwft architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:20:42,110 [salt.loaded.ext.module.maas:412 ][WARNING ][10836] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:20:42,111 [salt.loaded.ext.module.maas:92  ][INFO    ][10836] 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=tbqhmq architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:20:43,105 [salt.state       :300 ][INFO    ][10836] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-13 06:20:43,105 [salt.state       :1951][INFO    ][10836] Completed state [maas.process_machines] at time 06:20:43.105637 duration_in_ms=6967.825
2019-09-13 06:20:43,109 [salt.minion      :1711][INFO    ][10836] Returning information for job: 20190913062030836338
2019-09-13 06:21:14,089 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062114075868
2019-09-13 06:21:14,111 [salt.minion      :1432][INFO    ][11512] Starting a new job with PID 11512
2019-09-13 06:21:17,791 [salt.state       :915 ][INFO    ][11512] Loading fresh modules for state activity
2019-09-13 06:21:17,875 [salt.state       :1780][INFO    ][11512] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:17.875831
2019-09-13 06:21:17,876 [salt.state       :1813][INFO    ][11512] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:21:17,878 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11512] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:21:19,387 [salt.state       :300 ][INFO    ][11512] {'pid': 11524, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:21:19,388 [salt.state       :1951][INFO    ][11512] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:19.388051 duration_in_ms=1512.22
2019-09-13 06:21:19,391 [salt.state       :1780][INFO    ][11512] Running state [maas.wait_for_machine_status] at time 06:21:19.391392
2019-09-13 06:21:19,392 [salt.state       :1813][INFO    ][11512] Executing state module.run for [maas.wait_for_machine_status]
2019-09-13 06:21:19,392 [salt.utils.decorators:613 ][WARNING ][11512] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:21:23,119 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1496.28395009s left)
2019-09-13 06:21:29,188 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062129175954
2019-09-13 06:21:29,211 [salt.minion      :1432][INFO    ][11542] Starting a new job with PID 11542
2019-09-13 06:21:29,236 [salt.minion      :1711][INFO    ][11542] Returning information for job: 20190913062129175954
2019-09-13 06:21:56,367 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1463.03621197s left)
2019-09-13 06:21:59,237 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062159225089
2019-09-13 06:21:59,259 [salt.minion      :1432][INFO    ][11799] Starting a new job with PID 11799
2019-09-13 06:21:59,283 [salt.minion      :1711][INFO    ][11799] Returning information for job: 20190913062159225089
2019-09-13 06:22:29,337 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062229319380
2019-09-13 06:22:29,359 [salt.minion      :1432][INFO    ][11825] Starting a new job with PID 11825
2019-09-13 06:22:29,382 [salt.minion      :1711][INFO    ][11825] Returning information for job: 20190913062229319380
2019-09-13 06:22:29,998 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1429.40521216s left)
2019-09-13 06:22:59,384 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062259371885
2019-09-13 06:22:59,405 [salt.minion      :1432][INFO    ][12253] Starting a new job with PID 12253
2019-09-13 06:22:59,429 [salt.minion      :1711][INFO    ][12253] Returning information for job: 20190913062259371885
2019-09-13 06:23:03,132 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1396.27112412s left)
2019-09-13 06:23:29,431 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062329419338
2019-09-13 06:23:29,454 [salt.minion      :1432][INFO    ][12290] Starting a new job with PID 12290
2019-09-13 06:23:29,478 [salt.minion      :1711][INFO    ][12290] Returning information for job: 20190913062329419338
2019-09-13 06:23:36,836 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1362.56724s left)
2019-09-13 06:23:59,485 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062359473055
2019-09-13 06:23:59,508 [salt.minion      :1432][INFO    ][12575] Starting a new job with PID 12575
2019-09-13 06:23:59,532 [salt.minion      :1711][INFO    ][12575] Returning information for job: 20190913062359473055
2019-09-13 06:24:10,470 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1328.93302608s left)
2019-09-13 06:24:29,542 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062429526631
2019-09-13 06:24:29,565 [salt.minion      :1432][INFO    ][12602] Starting a new job with PID 12602
2019-09-13 06:24:29,589 [salt.minion      :1711][INFO    ][12602] Returning information for job: 20190913062429526631
2019-09-13 06:24:43,944 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1295.45928097s left)
2019-09-13 06:24:59,610 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062459598002
2019-09-13 06:24:59,634 [salt.minion      :1432][INFO    ][12763] Starting a new job with PID 12763
2019-09-13 06:24:59,657 [salt.minion      :1711][INFO    ][12763] Returning information for job: 20190913062459598002
2019-09-13 06:25:17,592 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1261.81065011s left)
2019-09-13 06:25:29,754 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062529741256
2019-09-13 06:25:29,777 [salt.minion      :1432][INFO    ][12963] Starting a new job with PID 12963
2019-09-13 06:25:29,800 [salt.minion      :1711][INFO    ][12963] Returning information for job: 20190913062529741256
2019-09-13 06:25:51,101 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1228.30165315s left)
2019-09-13 06:25:59,826 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062559813717
2019-09-13 06:25:59,848 [salt.minion      :1432][INFO    ][13473] Starting a new job with PID 13473
2019-09-13 06:25:59,869 [salt.minion      :1711][INFO    ][13473] Returning information for job: 20190913062559813717
2019-09-13 06:26:24,613 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1194.78976798s left)
2019-09-13 06:26:29,892 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062629879561
2019-09-13 06:26:29,909 [salt.minion      :1432][INFO    ][13497] Starting a new job with PID 13497
2019-09-13 06:26:29,930 [salt.minion      :1711][INFO    ][13497] Returning information for job: 20190913062629879561
2019-09-13 06:26:58,076 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1161.32710814s left)
2019-09-13 06:26:59,967 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062659953590
2019-09-13 06:26:59,990 [salt.minion      :1432][INFO    ][13554] Starting a new job with PID 13554
2019-09-13 06:27:00,013 [salt.minion      :1711][INFO    ][13554] Returning information for job: 20190913062659953590
2019-09-13 06:27:30,052 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062730039815
2019-09-13 06:27:30,076 [salt.minion      :1432][INFO    ][13571] Starting a new job with PID 13571
2019-09-13 06:27:30,099 [salt.minion      :1711][INFO    ][13571] Returning information for job: 20190913062730039815
2019-09-13 06:27:31,564 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1127.83880901s left)
2019-09-13 06:28:00,141 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062800128522
2019-09-13 06:28:00,164 [salt.minion      :1432][INFO    ][13625] Starting a new job with PID 13625
2019-09-13 06:28:00,186 [salt.minion      :1711][INFO    ][13625] Returning information for job: 20190913062800128522
2019-09-13 06:28:04,998 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1094.40436316s left)
2019-09-13 06:28:30,235 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062830222946
2019-09-13 06:28:30,258 [salt.minion      :1432][INFO    ][13644] Starting a new job with PID 13644
2019-09-13 06:28:30,281 [salt.minion      :1711][INFO    ][13644] Returning information for job: 20190913062830222946
2019-09-13 06:28:37,745 [salt.loaded.ext.module.maas:1023][INFO    ][11512] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1061.65763903s left)
2019-09-13 06:29:00,337 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062900324566
2019-09-13 06:29:00,360 [salt.minion      :1432][INFO    ][13706] Starting a new job with PID 13706
2019-09-13 06:29:00,384 [salt.minion      :1711][INFO    ][13706] Returning information for job: 20190913062900324566
2019-09-13 06:29:09,858 [salt.loaded.ext.module.maas:993 ][INFO    ][11512] Machine gp4agm mark broken
2019-09-13 06:29:10,613 [salt.loaded.ext.module.maas:996 ][INFO    ][11512] Machine gp4agm mark fixed
2019-09-13 06:29:11,592 [salt.loaded.ext.module.maas:684 ][INFO    ][11512] deploymachines hwe_kernel=hwe-16.04 system_id=gp4agm distro_series=xenial
2019-09-13 06:29:14,285 [salt.loaded.ext.module.maas:160 ][ERROR   ][11512] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-09-13 06:29:14,286 [salt.state       :302 ][ERROR   ][11512] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-09-13 06:29:14,287 [salt.state       :1951][INFO    ][11512] Completed state [maas.wait_for_machine_status] at time 06:29:14.286928 duration_in_ms=474895.533
2019-09-13 06:29:14,290 [salt.minion      :1711][INFO    ][11512] Returning information for job: 20190913062114075868
2019-09-13 06:29:25,050 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command pillar.get with jid 20190913062925037295
2019-09-13 06:29:25,073 [salt.minion      :1432][INFO    ][13796] Starting a new job with PID 13796
2019-09-13 06:29:25,079 [salt.minion      :1711][INFO    ][13796] Returning information for job: 20190913062925037295
2019-09-13 06:29:25,572 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command service.status with jid 20190913062925559441
2019-09-13 06:29:25,593 [salt.minion      :1432][INFO    ][13801] Starting a new job with PID 13801
2019-09-13 06:29:25,967 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13801] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:26,000 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13801] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-13 06:29:26,015 [salt.minion      :1711][INFO    ][13801] Returning information for job: 20190913062925559441
2019-09-13 06:29:26,612 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062926600122
2019-09-13 06:29:26,634 [salt.minion      :1432][INFO    ][13812] Starting a new job with PID 13812
2019-09-13 06:29:30,289 [salt.state       :915 ][INFO    ][13812] Loading fresh modules for state activity
2019-09-13 06:29:30,748 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:29:31,059 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:29:31,958 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:29:32,292 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'salt-minion --version' in directory '/root'
2019-09-13 06:29:33,628 [salt.state       :1780][INFO    ][13812] Running state [salt-minion] at time 06:29:33.627960
2019-09-13 06:29:33,628 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [salt-minion]
2019-09-13 06:29:33,628 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:29:33,709 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:33,709 [salt.state       :1951][INFO    ][13812] Completed state [salt-minion] at time 06:29:33.709589 duration_in_ms=81.63
2019-09-13 06:29:33,709 [salt.state       :1780][INFO    ][13812] Running state [salt_minion_dependency_packages] at time 06:29:33.709860
2019-09-13 06:29:33,710 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-13 06:29:33,715 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:33,715 [salt.state       :1951][INFO    ][13812] Completed state [salt_minion_dependency_packages] at time 06:29:33.715425 duration_in_ms=5.566
2019-09-13 06:29:33,718 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/minion.d/minion.conf] at time 06:29:33.718001
2019-09-13 06:29:33,718 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-13 06:29:33,915 [salt.state       :300 ][INFO    ][13812] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-13 06:29:33,915 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/minion.d/minion.conf] at time 06:29:33.915424 duration_in_ms=197.423
2019-09-13 06:29:33,915 [salt.state       :1780][INFO    ][13812] Running state [python-netaddr] at time 06:29:33.915632
2019-09-13 06:29:33,915 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [python-netaddr]
2019-09-13 06:29:33,922 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:33,922 [salt.state       :1951][INFO    ][13812] Completed state [python-netaddr] at time 06:29:33.922767 duration_in_ms=7.134
2019-09-13 06:29:33,925 [salt.state       :1780][INFO    ][13812] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:29:33.925869
2019-09-13 06:29:33,926 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-13 06:29:33,937 [salt.state       :300 ][INFO    ][13812] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-13 06:29:33,937 [salt.state       :1951][INFO    ][13812] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:29:33.937199 duration_in_ms=11.33
2019-09-13 06:29:33,938 [salt.state       :1780][INFO    ][13812] Running state [salt-minion] at time 06:29:33.938162
2019-09-13 06:29:33,938 [salt.state       :1813][INFO    ][13812] Executing state service.running for [salt-minion]
2019-09-13 06:29:33,939 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:33,977 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-13 06:29:33,995 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-13 06:29:34,013 [salt.state       :300 ][INFO    ][13812] The service salt-minion is already running
2019-09-13 06:29:34,013 [salt.state       :1951][INFO    ][13812] Completed state [salt-minion] at time 06:29:34.013789 duration_in_ms=75.626
2019-09-13 06:29:34,016 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains.d] at time 06:29:34.016475
2019-09-13 06:29:34,017 [salt.state       :1813][INFO    ][13812] Executing state file.directory for [/etc/salt/grains.d]
2019-09-13 06:29:34,018 [salt.state       :300 ][INFO    ][13812] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-13 06:29:34,019 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains.d] at time 06:29:34.018944 duration_in_ms=2.469
2019-09-13 06:29:34,020 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains] at time 06:29:34.020150
2019-09-13 06:29:34,020 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/grains]
2019-09-13 06:29:34,021 [salt.state       :300 ][INFO    ][13812] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-13 06:29:34,022 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains] at time 06:29:34.021951 duration_in_ms=1.801
2019-09-13 06:29:34,022 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains.d/placeholder] at time 06:29:34.022799
2019-09-13 06:29:34,023 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-13 06:29:34,024 [salt.state       :300 ][INFO    ][13812] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-13 06:29:34,024 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains.d/placeholder] at time 06:29:34.024441 duration_in_ms=1.641
2019-09-13 06:29:34,025 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains.d/sphinx] at time 06:29:34.025215
2019-09-13 06:29:34,025 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-13 06:29:34,041 [salt.state       :300 ][INFO    ][13812] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-13 06:29:34,041 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains.d/sphinx] at time 06:29:34.041635 duration_in_ms=16.42
2019-09-13 06:29:34,045 [salt.state       :1780][INFO    ][13812] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.045086
2019-09-13 06:29:34,045 [salt.state       :1813][INFO    ][13812] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:29:34,046 [salt.state       :300 ][INFO    ][13812] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:29:34,046 [salt.state       :1951][INFO    ][13812] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.046431 duration_in_ms=1.345
2019-09-13 06:29:34,047 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains.d/dns_records] at time 06:29:34.047224
2019-09-13 06:29:34,047 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-13 06:29:34,055 [salt.state       :300 ][INFO    ][13812] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-13 06:29:34,056 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains.d/dns_records] at time 06:29:34.056202 duration_in_ms=8.979
2019-09-13 06:29:34,057 [salt.state       :1780][INFO    ][13812] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.057635
2019-09-13 06:29:34,058 [salt.state       :1813][INFO    ][13812] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:29:34,058 [salt.state       :300 ][INFO    ][13812] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:29:34,058 [salt.state       :1951][INFO    ][13812] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.058888 duration_in_ms=1.253
2019-09-13 06:29:34,059 [salt.state       :1780][INFO    ][13812] Running state [/etc/salt/grains.d/salt] at time 06:29:34.059629
2019-09-13 06:29:34,060 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-13 06:29:34,073 [salt.state       :300 ][INFO    ][13812] File /etc/salt/grains.d/salt is in the correct state
2019-09-13 06:29:34,074 [salt.state       :1951][INFO    ][13812] Completed state [/etc/salt/grains.d/salt] at time 06:29:34.074215 duration_in_ms=14.585
2019-09-13 06:29:34,075 [salt.state       :1780][INFO    ][13812] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.075588
2019-09-13 06:29:34,076 [salt.state       :1813][INFO    ][13812] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-13 06:29:34,076 [salt.state       :300 ][INFO    ][13812] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-13 06:29:34,076 [salt.state       :1951][INFO    ][13812] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:29:34.076843 duration_in_ms=1.256
2019-09-13 06:29:34,079 [salt.state       :1780][INFO    ][13812] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:29:34.079804
2019-09-13 06:29:34,080 [salt.state       :1813][INFO    ][13812] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-13 06:29:34,080 [salt.state       :300 ][INFO    ][13812] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-13 06:29:34,081 [salt.state       :1951][INFO    ][13812] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:29:34.081062 duration_in_ms=1.258
2019-09-13 06:29:34,082 [salt.state       :1780][INFO    ][13812] Running state [mine.update] at time 06:29:34.082093
2019-09-13 06:29:34,082 [salt.state       :1813][INFO    ][13812] Executing state module.wait for [mine.update]
2019-09-13 06:29:34,083 [salt.state       :300 ][INFO    ][13812] No changes made for mine.update
2019-09-13 06:29:34,083 [salt.state       :1951][INFO    ][13812] Completed state [mine.update] at time 06:29:34.083261 duration_in_ms=1.167
2019-09-13 06:29:34,083 [salt.state       :1780][INFO    ][13812] Running state [ca-certificates] at time 06:29:34.083643
2019-09-13 06:29:34,084 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [ca-certificates]
2019-09-13 06:29:34,094 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:34,094 [salt.state       :1951][INFO    ][13812] Completed state [ca-certificates] at time 06:29:34.094737 duration_in_ms=11.093
2019-09-13 06:29:34,095 [salt.state       :1780][INFO    ][13812] Running state [update-ca-certificates] at time 06:29:34.095745
2019-09-13 06:29:34,096 [salt.state       :1813][INFO    ][13812] Executing state cmd.wait for [update-ca-certificates]
2019-09-13 06:29:34,096 [salt.state       :300 ][INFO    ][13812] No changes made for update-ca-certificates
2019-09-13 06:29:34,096 [salt.state       :1951][INFO    ][13812] Completed state [update-ca-certificates] at time 06:29:34.096833 duration_in_ms=1.087
2019-09-13 06:29:34,097 [salt.state       :1780][INFO    ][13812] Running state [iptables] at time 06:29:34.097151
2019-09-13 06:29:34,097 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [iptables]
2019-09-13 06:29:34,106 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:34,107 [salt.state       :1951][INFO    ][13812] Completed state [iptables] at time 06:29:34.107239 duration_in_ms=10.087
2019-09-13 06:29:34,107 [salt.state       :1780][INFO    ][13812] Running state [iptables-persistent] at time 06:29:34.107575
2019-09-13 06:29:34,107 [salt.state       :1813][INFO    ][13812] Executing state pkg.installed for [iptables-persistent]
2019-09-13 06:29:34,116 [salt.state       :300 ][INFO    ][13812] All specified packages are already installed
2019-09-13 06:29:34,117 [salt.state       :1951][INFO    ][13812] Completed state [iptables-persistent] at time 06:29:34.117225 duration_in_ms=9.65
2019-09-13 06:29:34,118 [salt.state       :1780][INFO    ][13812] Running state [iptables_modules_v4_load] at time 06:29:34.118532
2019-09-13 06:29:34,118 [salt.state       :1813][INFO    ][13812] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-13 06:29:34,119 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'lsmod' in directory '/root'
2019-09-13 06:29:34,144 [salt.state       :300 ][INFO    ][13812] Kernel modules iptable_filter, ip_tables are already present
2019-09-13 06:29:34,144 [salt.state       :1951][INFO    ][13812] Completed state [iptables_modules_v4_load] at time 06:29:34.144562 duration_in_ms=26.03
2019-09-13 06:29:34,145 [salt.state       :1780][INFO    ][13812] Running state [/etc/iptables/rules.v4] at time 06:29:34.145523
2019-09-13 06:29:34,146 [salt.state       :1813][INFO    ][13812] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-13 06:29:34,259 [salt.state       :300 ][INFO    ][13812] File /etc/iptables/rules.v4 is in the correct state
2019-09-13 06:29:34,260 [salt.state       :1951][INFO    ][13812] Completed state [/etc/iptables/rules.v4] at time 06:29:34.260027 duration_in_ms=114.504
2019-09-13 06:29:34,261 [salt.state       :1780][INFO    ][13812] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:29:34.261204
2019-09-13 06:29:34,261 [salt.state       :1813][INFO    ][13812] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-13 06:29:34,262 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-13 06:29:34,281 [salt.state       :300 ][INFO    ][13812] onlyif execution failed
2019-09-13 06:29:34,281 [salt.state       :1951][INFO    ][13812] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:29:34.281777 duration_in_ms=20.572
2019-09-13 06:29:34,282 [salt.state       :1780][INFO    ][13812] Running state [netfilter-persistent] at time 06:29:34.282892
2019-09-13 06:29:34,283 [salt.state       :1813][INFO    ][13812] Executing state service.running for [netfilter-persistent]
2019-09-13 06:29:34,284 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:34,303 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-13 06:29:34,322 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-13 06:29:34,339 [salt.state       :300 ][INFO    ][13812] The service netfilter-persistent is already running
2019-09-13 06:29:34,340 [salt.state       :1951][INFO    ][13812] Completed state [netfilter-persistent] at time 06:29:34.340248 duration_in_ms=57.355
2019-09-13 06:29:34,341 [salt.state       :1780][INFO    ][13812] Running state [iptables_extra.remove_stale_tables] at time 06:29:34.341428
2019-09-13 06:29:34,341 [salt.state       :1813][INFO    ][13812] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-13 06:29:34,342 [salt.state       :300 ][INFO    ][13812] No changes made for iptables_extra.remove_stale_tables
2019-09-13 06:29:34,342 [salt.state       :1951][INFO    ][13812] Completed state [iptables_extra.remove_stale_tables] at time 06:29:34.342677 duration_in_ms=1.249
2019-09-13 06:29:34,343 [salt.state       :1780][INFO    ][13812] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:29:34.343016
2019-09-13 06:29:34,343 [salt.state       :1813][INFO    ][13812] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-13 06:29:34,344 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13812] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-13 06:29:34,358 [salt.state       :300 ][INFO    ][13812] onlyif execution failed
2019-09-13 06:29:34,359 [salt.state       :1951][INFO    ][13812] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:29:34.359077 duration_in_ms=16.061
2019-09-13 06:29:34,360 [salt.state       :1780][INFO    ][13812] Running state [/etc/iptables/rules.v6] at time 06:29:34.360342
2019-09-13 06:29:34,360 [salt.state       :1813][INFO    ][13812] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-13 06:29:34,361 [salt.state       :300 ][INFO    ][13812] File /etc/iptables/rules.v6 is not present
2019-09-13 06:29:34,361 [salt.state       :1951][INFO    ][13812] Completed state [/etc/iptables/rules.v6] at time 06:29:34.361693 duration_in_ms=1.351
2019-09-13 06:29:34,362 [salt.state       :1780][INFO    ][13812] Running state [iptables_extra.flush_all] at time 06:29:34.362611
2019-09-13 06:29:34,363 [salt.state       :1813][INFO    ][13812] Executing state module.wait for [iptables_extra.flush_all]
2019-09-13 06:29:34,363 [salt.state       :300 ][INFO    ][13812] No changes made for iptables_extra.flush_all
2019-09-13 06:29:34,363 [salt.state       :1951][INFO    ][13812] Completed state [iptables_extra.flush_all] at time 06:29:34.363672 duration_in_ms=1.06
2019-09-13 06:29:34,367 [salt.minion      :1711][INFO    ][13812] Returning information for job: 20190913062926600122
2019-09-13 06:29:34,960 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062934947889
2019-09-13 06:29:34,982 [salt.minion      :1432][INFO    ][13889] Starting a new job with PID 13889
2019-09-13 06:29:35,717 [salt.state       :915 ][INFO    ][13889] Loading fresh modules for state activity
2019-09-13 06:29:36,349 [salt.state       :1780][INFO    ][13889] Running state [maas-rack-controller] at time 06:29:36.349084
2019-09-13 06:29:36,349 [salt.state       :1813][INFO    ][13889] Executing state pkg.installed for [maas-rack-controller]
2019-09-13 06:29:36,350 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13889] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:29:36,429 [salt.state       :300 ][INFO    ][13889] All specified packages are already installed
2019-09-13 06:29:36,430 [salt.state       :1951][INFO    ][13889] Completed state [maas-rack-controller] at time 06:29:36.430040 duration_in_ms=80.956
2019-09-13 06:29:36,430 [salt.state       :1780][INFO    ][13889] Running state [ipmitool] at time 06:29:36.430324
2019-09-13 06:29:36,430 [salt.state       :1813][INFO    ][13889] Executing state pkg.installed for [ipmitool]
2019-09-13 06:29:36,435 [salt.state       :300 ][INFO    ][13889] All specified packages are already installed
2019-09-13 06:29:36,436 [salt.state       :1951][INFO    ][13889] Completed state [ipmitool] at time 06:29:36.435966 duration_in_ms=5.642
2019-09-13 06:29:36,438 [salt.state       :1780][INFO    ][13889] Running state [/etc/maas/rackd.conf] at time 06:29:36.438364
2019-09-13 06:29:36,438 [salt.state       :1813][INFO    ][13889] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-13 06:29:36,439 [salt.state       :300 ][INFO    ][13889] No changes needed to be made
2019-09-13 06:29:36,439 [salt.state       :1951][INFO    ][13889] Completed state [/etc/maas/rackd.conf] at time 06:29:36.439553 duration_in_ms=1.189
2019-09-13 06:29:36,439 [salt.state       :1780][INFO    ][13889] Running state [/etc/maas/rackd.conf] at time 06:29:36.439739
2019-09-13 06:29:36,439 [salt.state       :1813][INFO    ][13889] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-13 06:29:36,440 [salt.loaded.int.states.file:2298][WARNING ][13889] 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-09-13 06:29:36,440 [salt.state       :300 ][INFO    ][13889] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-13 06:29:36,440 [salt.state       :1951][INFO    ][13889] Completed state [/etc/maas/rackd.conf] at time 06:29:36.440732 duration_in_ms=0.992
2019-09-13 06:29:36,441 [salt.state       :1780][INFO    ][13889] Running state [maas-rackd] at time 06:29:36.441478
2019-09-13 06:29:36,441 [salt.state       :1813][INFO    ][13889] Executing state service.running for [maas-rackd]
2019-09-13 06:29:36,442 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13889] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:36,474 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13889] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-13 06:29:36,490 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13889] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-13 06:29:36,505 [salt.state       :300 ][INFO    ][13889] The service maas-rackd is already running
2019-09-13 06:29:36,505 [salt.state       :1951][INFO    ][13889] Completed state [maas-rackd] at time 06:29:36.505874 duration_in_ms=64.396
2019-09-13 06:29:36,507 [salt.minion      :1711][INFO    ][13889] Returning information for job: 20190913062934947889
2019-09-13 06:29:37,095 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913062937082250
2019-09-13 06:29:37,116 [salt.minion      :1432][INFO    ][13912] Starting a new job with PID 13912
2019-09-13 06:29:37,870 [salt.state       :915 ][INFO    ][13912] Loading fresh modules for state activity
2019-09-13 06:29:38,570 [salt.state       :1780][INFO    ][13912] Running state [maas-region-controller] at time 06:29:38.570611
2019-09-13 06:29:38,570 [salt.state       :1813][INFO    ][13912] Executing state pkg.installed for [maas-region-controller]
2019-09-13 06:29:38,571 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-13 06:29:38,649 [salt.state       :300 ][INFO    ][13912] All specified packages are already installed
2019-09-13 06:29:38,649 [salt.state       :1951][INFO    ][13912] Completed state [maas-region-controller] at time 06:29:38.649269 duration_in_ms=78.658
2019-09-13 06:29:38,649 [salt.state       :1780][INFO    ][13912] Running state [python-oauth] at time 06:29:38.649515
2019-09-13 06:29:38,649 [salt.state       :1813][INFO    ][13912] Executing state pkg.installed for [python-oauth]
2019-09-13 06:29:38,654 [salt.state       :300 ][INFO    ][13912] All specified packages are already installed
2019-09-13 06:29:38,654 [salt.state       :1951][INFO    ][13912] Completed state [python-oauth] at time 06:29:38.654340 duration_in_ms=4.826
2019-09-13 06:29:38,656 [salt.state       :1780][INFO    ][13912] Running state [/etc/maas/regiond.conf] at time 06:29:38.656645
2019-09-13 06:29:38,656 [salt.state       :1813][INFO    ][13912] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-13 06:29:38,697 [salt.state       :300 ][INFO    ][13912] No changes needed to be made
2019-09-13 06:29:38,697 [salt.state       :1951][INFO    ][13912] Completed state [/etc/maas/regiond.conf] at time 06:29:38.697189 duration_in_ms=40.543
2019-09-13 06:29:38,697 [salt.state       :1780][INFO    ][13912] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:29:38.697535
2019-09-13 06:29:38,697 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-13 06:29:38,750 [salt.state       :300 ][INFO    ][13912] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-13 06:29:38,750 [salt.state       :1951][INFO    ][13912] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:29:38.750881 duration_in_ms=53.345
2019-09-13 06:29:38,751 [salt.state       :1780][INFO    ][13912] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:29:38.751253
2019-09-13 06:29:38,751 [salt.state       :1813][INFO    ][13912] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-13 06:29:38,763 [salt.state       :300 ][INFO    ][13912] No changes needed to be made
2019-09-13 06:29:38,763 [salt.state       :1951][INFO    ][13912] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:29:38.763602 duration_in_ms=12.349
2019-09-13 06:29:38,764 [salt.state       :1780][INFO    ][13912] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:29:38.763964
2019-09-13 06:29:38,764 [salt.state       :1813][INFO    ][13912] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-13 06:29:38,787 [salt.state       :300 ][INFO    ][13912] No changes needed to be made
2019-09-13 06:29:38,787 [salt.state       :1951][INFO    ][13912] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:29:38.787598 duration_in_ms=23.634
2019-09-13 06:29:38,788 [salt.state       :1780][INFO    ][13912] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:29:38.787964
2019-09-13 06:29:38,788 [salt.state       :1813][INFO    ][13912] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-13 06:29:38,805 [salt.state       :300 ][INFO    ][13912] No changes needed to be made
2019-09-13 06:29:38,805 [salt.state       :1951][INFO    ][13912] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:29:38.805800 duration_in_ms=17.835
2019-09-13 06:29:38,806 [salt.state       :1780][INFO    ][13912] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:29:38.806150
2019-09-13 06:29:38,806 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-13 06:29:38,816 [salt.state       :300 ][INFO    ][13912] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-13 06:29:38,816 [salt.state       :1951][INFO    ][13912] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:29:38.816772 duration_in_ms=10.621
2019-09-13 06:29:38,817 [salt.state       :1780][INFO    ][13912] Running state [a2enmod headers] at time 06:29:38.817707
2019-09-13 06:29:38,817 [salt.state       :1813][INFO    ][13912] Executing state cmd.run for [a2enmod headers]
2019-09-13 06:29:38,818 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command 'a2enmod headers' in directory '/root'
2019-09-13 06:29:38,891 [salt.state       :300 ][INFO    ][13912] {'pid': 13932, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-13 06:29:38,892 [salt.state       :1951][INFO    ][13912] Completed state [a2enmod headers] at time 06:29:38.891951 duration_in_ms=74.242
2019-09-13 06:29:38,892 [salt.state       :1780][INFO    ][13912] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:29:38.892535
2019-09-13 06:29:38,893 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-13 06:29:38,912 [salt.state       :300 ][INFO    ][13912] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-13 06:29:38,912 [salt.state       :1951][INFO    ][13912] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:29:38.912518 duration_in_ms=19.984
2019-09-13 06:29:38,913 [salt.state       :1780][INFO    ][13912] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:29:38.913365
2019-09-13 06:29:38,913 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-13 06:29:38,997 [salt.state       :300 ][INFO    ][13912] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-13 06:29:38,998 [salt.state       :1951][INFO    ][13912] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:29:38.998336 duration_in_ms=84.962
2019-09-13 06:29:38,999 [salt.state       :1780][INFO    ][13912] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:29:38.999314
2019-09-13 06:29:38,999 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-13 06:29:39,068 [salt.state       :300 ][INFO    ][13912] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-13 06:29:39,068 [salt.state       :1951][INFO    ][13912] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:29:39.068749 duration_in_ms=69.435
2019-09-13 06:29:39,069 [salt.state       :1780][INFO    ][13912] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:29:39.069329
2019-09-13 06:29:39,069 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-13 06:29:39,134 [salt.state       :300 ][INFO    ][13912] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-13 06:29:39,134 [salt.state       :1951][INFO    ][13912] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:29:39.134311 duration_in_ms=64.982
2019-09-13 06:29:39,134 [salt.state       :1780][INFO    ][13912] Running state [/root/.pgpass] at time 06:29:39.134607
2019-09-13 06:29:39,134 [salt.state       :1813][INFO    ][13912] Executing state file.managed for [/root/.pgpass]
2019-09-13 06:29:39,182 [salt.state       :300 ][INFO    ][13912] File /root/.pgpass is in the correct state
2019-09-13 06:29:39,182 [salt.state       :1951][INFO    ][13912] Completed state [/root/.pgpass] at time 06:29:39.182388 duration_in_ms=47.781
2019-09-13 06:29:39,187 [salt.state       :1780][INFO    ][13912] Running state [maas-region syncdb --noinput] at time 06:29:39.187924
2019-09-13 06:29:39,188 [salt.state       :1813][INFO    ][13912] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-13 06:29:39,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-13 06:29:41,278 [salt.state       :300 ][INFO    ][13912] {'pid': 13945, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, contenttypes, maasserver, metadataserver, piston3, 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-09-13 06:29:41,278 [salt.state       :1951][INFO    ][13912] Completed state [maas-region syncdb --noinput] at time 06:29:41.278430 duration_in_ms=2090.506
2019-09-13 06:29:41,278 [salt.state       :2022][WARNING ][13912] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-13 06:29:41,279 [salt.state       :1780][INFO    ][13912] Running state [maas-regiond] at time 06:29:41.279784
2019-09-13 06:29:41,280 [salt.state       :1813][INFO    ][13912] Executing state service.running for [maas-regiond]
2019-09-13 06:29:41,280 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:41,316 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-13 06:29:41,334 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-13 06:29:41,351 [salt.state       :300 ][INFO    ][13912] The service maas-regiond is already running
2019-09-13 06:29:41,352 [salt.state       :1951][INFO    ][13912] Completed state [maas-regiond] at time 06:29:41.352372 duration_in_ms=72.587
2019-09-13 06:29:41,354 [salt.state       :1780][INFO    ][13912] Running state [bind9] at time 06:29:41.354807
2019-09-13 06:29:41,355 [salt.state       :1813][INFO    ][13912] Executing state service.running for [bind9]
2019-09-13 06:29:41,356 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:41,373 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-13 06:29:41,389 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-13 06:29:41,404 [salt.state       :300 ][INFO    ][13912] The service bind9 is already running
2019-09-13 06:29:41,404 [salt.state       :1951][INFO    ][13912] Completed state [bind9] at time 06:29:41.404611 duration_in_ms=49.804
2019-09-13 06:29:41,406 [salt.state       :1780][INFO    ][13912] Running state [apache2] at time 06:29:41.406892
2019-09-13 06:29:41,407 [salt.state       :1813][INFO    ][13912] Executing state service.running for [apache2]
2019-09-13 06:29:41,408 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-13 06:29:41,424 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-13 06:29:41,438 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-13 06:29:41,456 [salt.state       :300 ][INFO    ][13912] The service apache2 is already running
2019-09-13 06:29:41,457 [salt.state       :1951][INFO    ][13912] Completed state [apache2] at time 06:29:41.457264 duration_in_ms=50.37
2019-09-13 06:29:41,459 [salt.state       :1780][INFO    ][13912] Running state [maasng.wait_for_http_code] at time 06:29:41.459581
2019-09-13 06:29:41,460 [salt.state       :1813][INFO    ][13912] Executing state module.run for [maasng.wait_for_http_code]
2019-09-13 06:29:41,460 [salt.utils.decorators:613 ][WARNING ][13912] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:29:41,570 [salt.state       :300 ][INFO    ][13912] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-13 06:29:41,571 [salt.state       :1951][INFO    ][13912] Completed state [maasng.wait_for_http_code] at time 06:29:41.571300 duration_in_ms=111.718
2019-09-13 06:29:41,572 [salt.state       :1780][INFO    ][13912] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:29:41.572629
2019-09-13 06:29:41,573 [salt.state       :1813][INFO    ][13912] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-13 06:29:41,573 [salt.state       :300 ][INFO    ][13912] /var/lib/maas/.setup_admin exists
2019-09-13 06:29:41,574 [salt.state       :1951][INFO    ][13912] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:29:41.574118 duration_in_ms=1.49
2019-09-13 06:29:41,575 [salt.state       :1780][INFO    ][13912] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:29:41.575223
2019-09-13 06:29:41,575 [salt.state       :1813][INFO    ][13912] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:29:41,576 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13912] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:29:42,880 [salt.state       :300 ][INFO    ][13912] {'pid': 13966, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:29:42,881 [salt.state       :1951][INFO    ][13912] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:29:42.881117 duration_in_ms=1305.895
2019-09-13 06:29:42,886 [salt.state       :1780][INFO    ][13912] Running state [maas_region_boot_source_resources_mirror] at time 06:29:42.886256
2019-09-13 06:29:42,886 [salt.state       :1813][INFO    ][13912] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-13 06:29:42,987 [salt.state       :300 ][INFO    ][13912] {'changes': {}}
2019-09-13 06:29:42,987 [salt.state       :1951][INFO    ][13912] Completed state [maas_region_boot_source_resources_mirror] at time 06:29:42.987778 duration_in_ms=101.522
2019-09-13 06:29:42,989 [salt.state       :1780][INFO    ][13912] Running state [maasng.boot_resources_import] at time 06:29:42.989005
2019-09-13 06:29:42,989 [salt.state       :1813][INFO    ][13912] Executing state module.run for [maasng.boot_resources_import]
2019-09-13 06:29:42,990 [salt.utils.decorators:613 ][WARNING ][13912] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:29:43,090 [salt.loaded.ext.module.maasng:1600][INFO    ][13912] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-13 06:29:48,154 [salt.loaded.ext.module.maasng:1600][INFO    ][13912] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-13 06:29:52,139 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913062952126524
2019-09-13 06:29:52,161 [salt.minion      :1432][INFO    ][14012] Starting a new job with PID 14012
2019-09-13 06:29:52,186 [salt.minion      :1711][INFO    ][14012] Returning information for job: 20190913062952126524
2019-09-13 06:29:53,212 [salt.loaded.ext.module.maasng:1600][INFO    ][13912] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-13 06:29:58,334 [salt.state       :300 ][INFO    ][13912] {'ret': True}
2019-09-13 06:29:58,335 [salt.state       :1951][INFO    ][13912] Completed state [maasng.boot_resources_import] at time 06:29:58.335257 duration_in_ms=15346.252
2019-09-13 06:29:58,336 [salt.state       :1780][INFO    ][13912] Running state [maas_region_boot_sources_selection_xenial] at time 06:29:58.336525
2019-09-13 06:29:58,337 [salt.state       :1813][INFO    ][13912] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-13 06:29:58,550 [salt.state       :300 ][INFO    ][13912] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-13 06:29:58,550 [salt.state       :1951][INFO    ][13912] Completed state [maas_region_boot_sources_selection_xenial] at time 06:29:58.550426 duration_in_ms=213.901
2019-09-13 06:29:58,552 [salt.state       :1780][INFO    ][13912] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:29:58.551947
2019-09-13 06:29:58,552 [salt.state       :1813][INFO    ][13912] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-13 06:29:58,553 [salt.utils.decorators:613 ][WARNING ][13912] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:29:58,553 [salt.loaded.ext.module.maasng:1771][INFO    ][13912] boot-sources sync initiated for ALL Rack's
2019-09-13 06:29:59,633 [salt.state       :300 ][INFO    ][13912] {'ret': True}
2019-09-13 06:29:59,634 [salt.state       :1951][INFO    ][13912] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:29:59.634109 duration_in_ms=1082.162
2019-09-13 06:29:59,636 [salt.state       :1780][INFO    ][13912] Running state [maas.process_maas_config] at time 06:29:59.636265
2019-09-13 06:29:59,636 [salt.state       :1813][INFO    ][13912] Executing state module.run for [maas.process_maas_config]
2019-09-13 06:29:59,637 [salt.utils.decorators:613 ][WARNING ][13912] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:29:59,638 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=enable_http_proxy value=True
2019-09-13 06:29:59,701 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=upstream_dns value=8.8.8.8
2019-09-13 06:29:59,778 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=commissioning_distro_series value=xenial
2019-09-13 06:29:59,849 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=default_osystem value=ubuntu
2019-09-13 06:29:59,921 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=active_discovery_interval value=600
2019-09-13 06:30:02,540 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=dnssec_validation value=no
2019-09-13 06:30:02,601 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=maas_name value=mas01
2019-09-13 06:30:02,671 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=network_discovery value=enabled
2019-09-13 06:30:02,784 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=enable_third_party_drivers value=True
2019-09-13 06:30:02,864 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=default_storage_layout value=lvm
2019-09-13 06:30:02,922 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=ntp_external_only value=True
2019-09-13 06:30:02,975 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-13 06:30:03,036 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=default_distro_series value=xenial
2019-09-13 06:30:03,109 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-09-13 06:30:03,264 [salt.state       :300 ][INFO    ][13912] {'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-09-13 06:30:03,265 [salt.state       :1951][INFO    ][13912] Completed state [maas.process_maas_config] at time 06:30:03.264919 duration_in_ms=3628.653
2019-09-13 06:30:03,265 [salt.state       :1780][INFO    ][13912] Running state [pxe_admin] at time 06:30:03.265889
2019-09-13 06:30:03,266 [salt.state       :1813][INFO    ][13912] Executing state maasng.fabric_present for [pxe_admin]
2019-09-13 06:30:03,325 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:03,391 [salt.loaded.ext.module.maasng:1008][WARNING ][13912] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-13 06:30:03,391 [salt.loaded.ext.module.maasng:1011][WARNING ][13912] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-13 06:30:03,463 [salt.state       :300 ][INFO    ][13912] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-13 06:30:03,464 [salt.state       :1951][INFO    ][13912] Completed state [pxe_admin] at time 06:30:03.464110 duration_in_ms=198.22
2019-09-13 06:30:03,464 [salt.state       :1780][INFO    ][13912] Running state [vlan 0] at time 06:30:03.464633
2019-09-13 06:30:03,465 [salt.state       :1813][INFO    ][13912] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-13 06:30:03,529 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:03,660 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:03,989 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'c88d4w', 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'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:04,096 [salt.state       :300 ][INFO    ][13912] {'new': 'Vlan untagged was updated'}
2019-09-13 06:30:04,097 [salt.state       :1951][INFO    ][13912] Completed state [vlan 0] at time 06:30:04.097401 duration_in_ms=632.759
2019-09-13 06:30:04,099 [salt.state       :1780][INFO    ][13912] Running state [192.168.11.0/24] at time 06:30:04.099130
2019-09-13 06:30:04,099 [salt.state       :1813][INFO    ][13912] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-13 06:30:04,340 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:04,341 [salt.loaded.ext.module.maasng:1235][WARNING ][13912] Ignoring parameter vlan:0
2019-09-13 06:30:04,444 [salt.state       :300 ][INFO    ][13912] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-13 06:30:04,444 [salt.state       :1951][INFO    ][13912] Completed state [192.168.11.0/24] at time 06:30:04.444628 duration_in_ms=345.497
2019-09-13 06:30:04,445 [salt.state       :1780][INFO    ][13912] Running state [maas_create_iprange_1] at time 06:30:04.445889
2019-09-13 06:30:04,446 [salt.state       :1813][INFO    ][13912] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-13 06:30:04,502 [salt.state       :300 ][INFO    ][13912] Iprange maas_create_iprange_1 already exist.
2019-09-13 06:30:04,503 [salt.state       :1951][INFO    ][13912] Completed state [maas_create_iprange_1] at time 06:30:04.503034 duration_in_ms=57.145
2019-09-13 06:30:04,503 [salt.state       :1780][INFO    ][13912] Running state [vlan 0] at time 06:30:04.503440
2019-09-13 06:30:04,503 [salt.state       :1813][INFO    ][13912] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-13 06:30:04,547 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:04,661 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', 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'primary_rack': u'c88d4w', 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'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:04,876 [salt.loaded.ext.module.maasng:945 ][INFO    ][13912] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'c88d4w', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-13 06:30:04,944 [salt.state       :300 ][INFO    ][13912] {'new': 'Vlan untagged was updated'}
2019-09-13 06:30:04,945 [salt.state       :1951][INFO    ][13912] Completed state [vlan 0] at time 06:30:04.945187 duration_in_ms=441.747
2019-09-13 06:30:04,945 [salt.state       :1780][INFO    ][13912] Running state [opnfv] at time 06:30:04.945856
2019-09-13 06:30:04,946 [salt.state       :1813][INFO    ][13912] Executing state maasng.sshkey_present for [opnfv]
2019-09-13 06:30:04,981 [salt.loaded.ext.module.maasng:1903][INFO    ][13912] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-09-13 06:30:04,981 [salt.state       :300 ][INFO    ][13912] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-13 06:30:04,981 [salt.state       :1951][INFO    ][13912] Completed state [opnfv] at time 06:30:04.981837 duration_in_ms=35.98
2019-09-13 06:30:04,982 [salt.state       :1780][INFO    ][13912] Running state [maas.process_tags] at time 06:30:04.982751
2019-09-13 06:30:04,983 [salt.state       :1813][INFO    ][13912] Executing state module.run for [maas.process_tags]
2019-09-13 06:30:04,983 [salt.utils.decorators:613 ][WARNING ][13912] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:30:05,029 [salt.loaded.ext.module.maas:92  ][INFO    ][13912] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-09-13 06:30:05,089 [salt.state       :300 ][INFO    ][13912] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-09-13 06:30:05,090 [salt.state       :1951][INFO    ][13912] Completed state [maas.process_tags] at time 06:30:05.090067 duration_in_ms=107.316
2019-09-13 06:30:05,094 [salt.minion      :1711][INFO    ][13912] Returning information for job: 20190913062937082250
2019-09-13 06:30:05,634 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913063005625052
2019-09-13 06:30:05,653 [salt.minion      :1432][INFO    ][14397] Starting a new job with PID 14397
2019-09-13 06:30:09,325 [salt.state       :915 ][INFO    ][14397] Loading fresh modules for state activity
2019-09-13 06:30:09,421 [salt.state       :1780][INFO    ][14397] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:09.421376
2019-09-13 06:30:09,421 [salt.state       :1813][INFO    ][14397] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:30:09,424 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14397] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:30:10,862 [salt.state       :300 ][INFO    ][14397] {'pid': 14420, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:30:10,862 [salt.state       :1951][INFO    ][14397] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:10.862589 duration_in_ms=1441.215
2019-09-13 06:30:10,863 [salt.state       :1780][INFO    ][14397] Running state [maas.process_machines] at time 06:30:10.863798
2019-09-13 06:30:10,864 [salt.state       :1813][INFO    ][14397] Executing state module.run for [maas.process_machines]
2019-09-13 06:30:10,864 [salt.utils.decorators:613 ][WARNING ][14397] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:30:11,568 [salt.loaded.ext.module.maas:412 ][WARNING ][14397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:30:11,569 [salt.loaded.ext.module.maas:92  ][INFO    ][14397] 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=8xy7cb architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:30:12,770 [salt.loaded.ext.module.maas:412 ][WARNING ][14397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:30:12,771 [salt.loaded.ext.module.maas:92  ][INFO    ][14397] 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=pkqtxg architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:30:14,057 [salt.loaded.ext.module.maas:412 ][WARNING ][14397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:30:14,058 [salt.loaded.ext.module.maas:92  ][INFO    ][14397] 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=gp4agm architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:30:15,309 [salt.loaded.ext.module.maas:412 ][WARNING ][14397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:30:15,309 [salt.loaded.ext.module.maas:92  ][INFO    ][14397] 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=g3mwft architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:30:16,333 [salt.loaded.ext.module.maas:412 ][WARNING ][14397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-13 06:30:16,334 [salt.loaded.ext.module.maas:92  ][INFO    ][14397] 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=tbqhmq architecture=amd64/generic power_parameters_power_user=admin
2019-09-13 06:30:17,321 [salt.state       :300 ][INFO    ][14397] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-13 06:30:17,322 [salt.state       :1951][INFO    ][14397] Completed state [maas.process_machines] at time 06:30:17.322055 duration_in_ms=6458.255
2019-09-13 06:30:17,325 [salt.minion      :1711][INFO    ][14397] Returning information for job: 20190913063005625052
2019-09-13 06:30:50,254 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913063050200503
2019-09-13 06:30:50,275 [salt.minion      :1432][INFO    ][14660] Starting a new job with PID 14660
2019-09-13 06:30:54,019 [salt.state       :915 ][INFO    ][14660] Loading fresh modules for state activity
2019-09-13 06:30:54,110 [salt.state       :1780][INFO    ][14660] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:54.110287
2019-09-13 06:30:54,110 [salt.state       :1813][INFO    ][14660] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:30:54,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14660] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:30:55,473 [salt.state       :300 ][INFO    ][14660] {'pid': 14701, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:30:55,473 [salt.state       :1951][INFO    ][14660] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:55.473392 duration_in_ms=1363.106
2019-09-13 06:30:55,474 [salt.state       :1780][INFO    ][14660] Running state [maas.wait_for_machine_status] at time 06:30:55.474476
2019-09-13 06:30:55,474 [salt.state       :1813][INFO    ][14660] Executing state module.run for [maas.wait_for_machine_status]
2019-09-13 06:30:55,474 [salt.utils.decorators:613 ][WARNING ][14660] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:30:57,617 [salt.loaded.ext.module.maas:993 ][INFO    ][14660] Machine gp4agm mark broken
2019-09-13 06:30:58,249 [salt.loaded.ext.module.maas:996 ][INFO    ][14660] Machine gp4agm mark fixed
2019-09-13 06:30:59,505 [salt.loaded.ext.module.maas:684 ][INFO    ][14660] deploymachines hwe_kernel=hwe-16.04 system_id=gp4agm distro_series=xenial
2019-09-13 06:31:03,412 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.0668869s left)
2019-09-13 06:31:05,305 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063105292448
2019-09-13 06:31:05,328 [salt.minion      :1432][INFO    ][14769] Starting a new job with PID 14769
2019-09-13 06:31:05,352 [salt.minion      :1711][INFO    ][14769] Returning information for job: 20190913063105292448
2019-09-13 06:31:35,355 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063135341865
2019-09-13 06:31:35,373 [salt.minion      :1432][INFO    ][14790] Starting a new job with PID 14790
2019-09-13 06:31:35,398 [salt.minion      :1711][INFO    ][14790] Returning information for job: 20190913063135341865
2019-09-13 06:31:36,778 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1458.70074201s left)
2019-09-13 06:32:05,425 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063205366082
2019-09-13 06:32:05,446 [salt.minion      :1432][INFO    ][14850] Starting a new job with PID 14850
2019-09-13 06:32:05,471 [salt.minion      :1711][INFO    ][14850] Returning information for job: 20190913063205366082
2019-09-13 06:32:10,233 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.24580193s left)
2019-09-13 06:32:35,473 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063235460064
2019-09-13 06:32:35,496 [salt.minion      :1432][INFO    ][14870] Starting a new job with PID 14870
2019-09-13 06:32:35,523 [salt.minion      :1711][INFO    ][14870] Returning information for job: 20190913063235460064
2019-09-13 06:32:43,090 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.38897491s left)
2019-09-13 06:33:05,510 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063305495873
2019-09-13 06:33:05,533 [salt.minion      :1432][INFO    ][14978] Starting a new job with PID 14978
2019-09-13 06:33:05,559 [salt.minion      :1711][INFO    ][14978] Returning information for job: 20190913063305495873
2019-09-13 06:33:16,431 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.04808497s left)
2019-09-13 06:33:35,568 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063335555421
2019-09-13 06:33:35,591 [salt.minion      :1432][INFO    ][15004] Starting a new job with PID 15004
2019-09-13 06:33:35,617 [salt.minion      :1711][INFO    ][15004] Returning information for job: 20190913063335555421
2019-09-13 06:33:49,970 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.50866795s left)
2019-09-13 06:34:05,633 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063405620604
2019-09-13 06:34:05,656 [salt.minion      :1432][INFO    ][15233] Starting a new job with PID 15233
2019-09-13 06:34:05,682 [salt.minion      :1711][INFO    ][15233] Returning information for job: 20190913063405620604
2019-09-13 06:34:23,798 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1291.68132591s left)
2019-09-13 06:34:35,699 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063435686955
2019-09-13 06:34:35,723 [salt.minion      :1432][INFO    ][15265] Starting a new job with PID 15265
2019-09-13 06:34:35,749 [salt.minion      :1711][INFO    ][15265] Returning information for job: 20190913063435686955
2019-09-13 06:34:57,334 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.14451694s left)
2019-09-13 06:35:05,770 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063505757762
2019-09-13 06:35:05,794 [salt.minion      :1432][INFO    ][15340] Starting a new job with PID 15340
2019-09-13 06:35:05,819 [salt.minion      :1711][INFO    ][15340] Returning information for job: 20190913063505757762
2019-09-13 06:35:30,675 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1224.80437994s left)
2019-09-13 06:35:35,840 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063535828048
2019-09-13 06:35:35,864 [salt.minion      :1432][INFO    ][15359] Starting a new job with PID 15359
2019-09-13 06:35:35,890 [salt.minion      :1711][INFO    ][15359] Returning information for job: 20190913063535828048
2019-09-13 06:36:04,218 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.26094508s left)
2019-09-13 06:36:05,914 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063605901879
2019-09-13 06:36:05,934 [salt.minion      :1432][INFO    ][15520] Starting a new job with PID 15520
2019-09-13 06:36:05,960 [salt.minion      :1711][INFO    ][15520] Returning information for job: 20190913063605901879
2019-09-13 06:36:35,990 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063635976980
2019-09-13 06:36:36,012 [salt.minion      :1432][INFO    ][15544] Starting a new job with PID 15544
2019-09-13 06:36:36,038 [salt.minion      :1711][INFO    ][15544] Returning information for job: 20190913063635976980
2019-09-13 06:36:38,033 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1157.44567609s left)
2019-09-13 06:37:06,075 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063706060945
2019-09-13 06:37:06,102 [salt.minion      :1432][INFO    ][15660] Starting a new job with PID 15660
2019-09-13 06:37:06,131 [salt.minion      :1711][INFO    ][15660] Returning information for job: 20190913063706060945
2019-09-13 06:37:11,077 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.40174508s left)
2019-09-13 06:37:36,166 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063736153956
2019-09-13 06:37:36,189 [salt.minion      :1432][INFO    ][15679] Starting a new job with PID 15679
2019-09-13 06:37:36,219 [salt.minion      :1711][INFO    ][15679] Returning information for job: 20190913063736153956
2019-09-13 06:37:44,818 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1090.66080499s left)
2019-09-13 06:38:06,266 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063806253677
2019-09-13 06:38:06,289 [salt.minion      :1432][INFO    ][15759] Starting a new job with PID 15759
2019-09-13 06:38:06,318 [salt.minion      :1711][INFO    ][15759] Returning information for job: 20190913063806253677
2019-09-13 06:38:18,150 [salt.loaded.ext.module.maas:1023][INFO    ][14660] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1057.32907295s left)
2019-09-13 06:38:36,337 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command saltutil.find_job with jid 20190913063836323852
2019-09-13 06:38:36,360 [salt.minion      :1432][INFO    ][15801] Starting a new job with PID 15801
2019-09-13 06:38:36,390 [salt.minion      :1711][INFO    ][15801] Returning information for job: 20190913063836323852
2019-09-13 06:38:51,597 [salt.state       :300 ][INFO    ][14660] {'ret': True}
2019-09-13 06:38:51,597 [salt.state       :1951][INFO    ][14660] Completed state [maas.wait_for_machine_status] at time 06:38:51.597454 duration_in_ms=476122.975
2019-09-13 06:38:51,600 [salt.minion      :1711][INFO    ][14660] Returning information for job: 20190913063050200503
2019-09-13 06:38:52,275 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913063852264969
2019-09-13 06:38:52,293 [salt.minion      :1432][INFO    ][15862] Starting a new job with PID 15862
2019-09-13 06:38:55,918 [salt.state       :915 ][INFO    ][15862] Loading fresh modules for state activity
2019-09-13 06:38:56,057 [salt.state       :1780][INFO    ][15862] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:56.057571
2019-09-13 06:38:56,057 [salt.state       :1813][INFO    ][15862] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:38:56,059 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15862] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:38:57,503 [salt.state       :300 ][INFO    ][15862] {'pid': 15999, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:38:57,504 [salt.state       :1951][INFO    ][15862] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:38:57.504442 duration_in_ms=1446.87
2019-09-13 06:38:57,507 [salt.state       :1780][INFO    ][15862] Running state [maas_machines_storage_cmp002_lvm] at time 06:38:57.507707
2019-09-13 06:38:57,508 [salt.state       :1813][INFO    ][15862] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-13 06:38:58,279 [salt.state       :300 ][INFO    ][15862] Machine cmp002 is not in Ready state.
2019-09-13 06:38:58,279 [salt.state       :1951][INFO    ][15862] Completed state [maas_machines_storage_cmp002_lvm] at time 06:38:58.279557 duration_in_ms=771.848
2019-09-13 06:38:58,280 [salt.state       :1780][INFO    ][15862] Running state [maas_machines_storage_cmp001_lvm] at time 06:38:58.280391
2019-09-13 06:38:58,281 [salt.state       :1813][INFO    ][15862] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-13 06:38:59,012 [salt.state       :300 ][INFO    ][15862] Machine cmp001 is not in Ready state.
2019-09-13 06:38:59,013 [salt.state       :1951][INFO    ][15862] Completed state [maas_machines_storage_cmp001_lvm] at time 06:38:59.012943 duration_in_ms=732.55
2019-09-13 06:38:59,017 [salt.minion      :1711][INFO    ][15862] Returning information for job: 20190913063852264969
2019-09-13 06:38:59,652 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913063859639062
2019-09-13 06:38:59,675 [salt.minion      :1432][INFO    ][16010] Starting a new job with PID 16010
2019-09-13 06:39:00,418 [salt.state       :915 ][INFO    ][16010] Loading fresh modules for state activity
2019-09-13 06:39:00,508 [salt.state       :1780][INFO    ][16010] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:00.508724
2019-09-13 06:39:00,509 [salt.state       :1813][INFO    ][16010] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:39:00,511 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16010] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:39:01,995 [salt.state       :300 ][INFO    ][16010] {'pid': 16017, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:39:01,996 [salt.state       :1951][INFO    ][16010] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:01.996519 duration_in_ms=1487.794
2019-09-13 06:39:01,999 [salt.state       :1780][INFO    ][16010] Running state [maas.deploy_machines] at time 06:39:01.999195
2019-09-13 06:39:01,999 [salt.state       :1813][INFO    ][16010] Executing state module.run for [maas.deploy_machines]
2019-09-13 06:39:02,001 [salt.utils.decorators:613 ][WARNING ][16010] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:39:02,733 [salt.state       :300 ][INFO    ][16010] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-13 06:39:02,734 [salt.state       :1951][INFO    ][16010] Completed state [maas.deploy_machines] at time 06:39:02.734069 duration_in_ms=734.873
2019-09-13 06:39:02,737 [salt.minion      :1711][INFO    ][16010] Returning information for job: 20190913063859639062
2019-09-13 06:39:03,347 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command state.apply with jid 20190913063903333786
2019-09-13 06:39:03,370 [salt.minion      :1432][INFO    ][16026] Starting a new job with PID 16026
2019-09-13 06:39:04,154 [salt.state       :915 ][INFO    ][16026] Loading fresh modules for state activity
2019-09-13 06:39:04,247 [salt.state       :1780][INFO    ][16026] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:04.247437
2019-09-13 06:39:04,247 [salt.state       :1813][INFO    ][16026] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-13 06:39:04,250 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16026] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-13 06:39:05,739 [salt.state       :300 ][INFO    ][16026] {'pid': 16033, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-13 06:39:05,740 [salt.state       :1951][INFO    ][16026] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:39:05.740276 duration_in_ms=1492.84
2019-09-13 06:39:05,741 [salt.state       :1780][INFO    ][16026] Running state [maas.wait_for_machine_status] at time 06:39:05.741814
2019-09-13 06:39:05,742 [salt.state       :1813][INFO    ][16026] Executing state module.run for [maas.wait_for_machine_status]
2019-09-13 06:39:05,742 [salt.utils.decorators:613 ][WARNING ][16026] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-13 06:39:09,384 [salt.state       :300 ][INFO    ][16026] {'ret': True}
2019-09-13 06:39:09,385 [salt.state       :1951][INFO    ][16026] Completed state [maas.wait_for_machine_status] at time 06:39:09.384977 duration_in_ms=3643.161
2019-09-13 06:39:09,388 [salt.minion      :1711][INFO    ][16026] Returning information for job: 20190913063903333786
2019-09-13 07:09:32,339 [salt.utils.schedule:1377][INFO    ][6894] Running scheduled job: __mine_interval
2019-09-13 08:04:57,742 [salt.minion      :1308][INFO    ][6894] User sudo_ubuntu Executing command cp.push_dir with jid 20190913080457730609
2019-09-13 08:04:57,761 [salt.minion      :1432][INFO    ][21827] Starting a new job with PID 21827
