2019-05-04 20:07:38,746 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-04 20:08:28,789 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-04 20:09:18,830 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-04 20:10:08,878 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-04 20:10:58,928 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-04 20:13:08,775 [salt.utils.decorators:613 ][WARNING ][2860] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 20:13:09,364 [salt.utils.decorators:613 ][WARNING ][2860] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 20:13:11,590 [salt.loaded.int.states.file:2298][WARNING ][2995] 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-05-04 20:13:17,341 [salt.state       :2022][WARNING ][3111] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-04 20:13:19,926 [salt.utils.decorators:613 ][WARNING ][3111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 20:28:28,308 [salt.utils.decorators:613 ][WARNING ][3111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 20:53:29,526 [salt.utils.decorators:613 ][WARNING ][3111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:08:33,720 [salt.utils.decorators:613 ][WARNING ][3111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:08:37,658 [salt.loaded.ext.module.maasng:1008][WARNING ][3111] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-04 21:08:37,659 [salt.loaded.ext.module.maasng:1011][WARNING ][3111] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-04 21:08:38,312 [salt.loaded.ext.module.maasng:1235][WARNING ][3111] Ignoring parameter vlan:0
2019-05-04 21:08:44,963 [salt.utils.decorators:613 ][WARNING ][5623] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:08:45,025 [salt.loaded.ext.module.maas:412 ][WARNING ][5623] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:08:49,441 [salt.loaded.ext.module.maas:412 ][WARNING ][5623] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:08:53,871 [salt.loaded.ext.module.maas:412 ][WARNING ][5623] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:08:58,230 [salt.loaded.ext.module.maas:412 ][WARNING ][5623] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:09:02,062 [salt.loaded.ext.module.maas:412 ][WARNING ][5623] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:09:09,214 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6581] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-04 21:09:09,246 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6581] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-04 21:09:09,270 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-05-04 21:09:10,319 [salt.cli.daemons :293 ][INFO    ][6626] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-05-04 21:09:10,419 [salt.cli.daemons :82  ][INFO    ][6626] Starting up the Salt Minion
2019-05-04 21:09:10,420 [salt.utils.event :1017][INFO    ][6626] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-05-04 21:09:11,410 [salt.minion      :976 ][INFO    ][6626] Creating minion process manager
2019-05-04 21:09:12,856 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6626] Executing command ['date', '+%z'] in directory '/root'
2019-05-04 21:09:12,875 [salt.utils.schedule:568 ][INFO    ][6626] Updating job settings for scheduled job: __mine_interval
2019-05-04 21:09:12,877 [salt.minion      :1108][INFO    ][6626] Added mine.update to scheduler
2019-05-04 21:09:12,880 [salt.minion      :1975][INFO    ][6626] Minion is starting as user 'root'
2019-05-04 21:09:12,890 [salt.minion      :2336][INFO    ][6626] Minion is ready to receive requests!
2019-05-04 21:09:37,438 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504210937425169
2019-05-04 21:09:37,461 [salt.minion      :1432][INFO    ][6753] Starting a new job with PID 6753
2019-05-04 21:09:41,068 [salt.state       :915 ][INFO    ][6753] Loading fresh modules for state activity
2019-05-04 21:09:41,117 [salt.fileclient  :1219][INFO    ][6753] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-04 21:09:41,152 [salt.state       :1780][INFO    ][6753] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:09:41.152471
2019-05-04 21:09:41,152 [salt.state       :1813][INFO    ][6753] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:09:41,154 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6753] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:09:42,594 [salt.state       :300 ][INFO    ][6753] {'pid': 6760, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:09:42,595 [salt.state       :1951][INFO    ][6753] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:09:42.595243 duration_in_ms=1442.771
2019-05-04 21:09:42,598 [salt.state       :1780][INFO    ][6753] Running state [maas.wait_for_machine_status] at time 21:09:42.598454
2019-05-04 21:09:42,599 [salt.state       :1813][INFO    ][6753] Executing state module.run for [maas.wait_for_machine_status]
2019-05-04 21:09:42,599 [salt.utils.decorators:613 ][WARNING ][6753] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:09:43,386 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.22324896s left)
2019-05-04 21:09:52,463 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504210952450531
2019-05-04 21:09:52,485 [salt.minion      :1432][INFO    ][6780] Starting a new job with PID 6780
2019-05-04 21:09:52,509 [salt.minion      :1711][INFO    ][6780] Returning information for job: 20190504210952450531
2019-05-04 21:10:14,422 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.1871779s left)
2019-05-04 21:10:22,516 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211022503392
2019-05-04 21:10:22,538 [salt.minion      :1432][INFO    ][6835] Starting a new job with PID 6835
2019-05-04 21:10:22,563 [salt.minion      :1711][INFO    ][6835] Returning information for job: 20190504211022503392
2019-05-04 21:10:45,452 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.15696287s left)
2019-05-04 21:10:52,613 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211052600084
2019-05-04 21:10:52,636 [salt.minion      :1432][INFO    ][6991] Starting a new job with PID 6991
2019-05-04 21:10:52,660 [salt.minion      :1711][INFO    ][6991] Returning information for job: 20190504211052600084
2019-05-04 21:11:16,694 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.91535687s left)
2019-05-04 21:11:22,664 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211122651779
2019-05-04 21:11:22,677 [salt.minion      :1432][INFO    ][7600] Starting a new job with PID 7600
2019-05-04 21:11:22,690 [salt.minion      :1711][INFO    ][7600] Returning information for job: 20190504211122651779
2019-05-04 21:11:48,562 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.0475688s left)
2019-05-04 21:11:52,697 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211152684087
2019-05-04 21:11:52,718 [salt.minion      :1432][INFO    ][7801] Starting a new job with PID 7801
2019-05-04 21:11:52,743 [salt.minion      :1711][INFO    ][7801] Returning information for job: 20190504211152684087
2019-05-04 21:12:20,399 [salt.loaded.ext.module.maas:1023][INFO    ][6753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.21012497s left)
2019-05-04 21:12:22,756 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211222740607
2019-05-04 21:12:22,778 [salt.minion      :1432][INFO    ][7928] Starting a new job with PID 7928
2019-05-04 21:12:22,801 [salt.minion      :1711][INFO    ][7928] Returning information for job: 20190504211222740607
2019-05-04 21:12:52,822 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211252810450
2019-05-04 21:12:52,841 [salt.minion      :1432][INFO    ][8127] Starting a new job with PID 8127
2019-05-04 21:12:52,860 [salt.minion      :1711][INFO    ][8127] Returning information for job: 20190504211252810450
2019-05-04 21:12:53,923 [salt.state       :300 ][INFO    ][6753] {'ret': True}
2019-05-04 21:12:53,923 [salt.state       :1951][INFO    ][6753] Completed state [maas.wait_for_machine_status] at time 21:12:53.923679 duration_in_ms=191325.224
2019-05-04 21:12:53,927 [salt.minion      :1711][INFO    ][6753] Returning information for job: 20190504210937425169
2019-05-04 21:12:54,449 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211254437606
2019-05-04 21:12:54,466 [salt.minion      :1432][INFO    ][8144] Starting a new job with PID 8144
2019-05-04 21:12:58,082 [salt.state       :915 ][INFO    ][8144] Loading fresh modules for state activity
2019-05-04 21:12:58,136 [salt.fileclient  :1219][INFO    ][8144] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-04 21:12:58,222 [salt.state       :1780][INFO    ][8144] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:58.222902
2019-05-04 21:12:58,223 [salt.state       :1813][INFO    ][8144] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:12:58,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8144] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:12:59,591 [salt.state       :300 ][INFO    ][8144] {'pid': 8152, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:12:59,591 [salt.state       :1951][INFO    ][8144] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:59.591784 duration_in_ms=1368.882
2019-05-04 21:12:59,593 [salt.state       :1780][INFO    ][8144] Running state [maas_machines_storage_cmp002_lvm] at time 21:12:59.593233
2019-05-04 21:12:59,593 [salt.state       :1813][INFO    ][8144] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-04 21:13:00,940 [salt.loaded.ext.module.maasng:610 ][INFO    ][8144] rh47hp
2019-05-04 21:13:00,940 [salt.loaded.ext.module.maasng:626 ][INFO    ][8144] sda
2019-05-04 21:13:01,618 [salt.loaded.ext.module.maasng:361 ][INFO    ][8144] rh47hp
2019-05-04 21:13:01,744 [salt.loaded.ext.module.maasng:367 ][INFO    ][8144] [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'40cf456c-ed36-4105-9e9c-a52510fb9ea3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rh47hp', u'filesystem': {u'uuid': u'62cf23ca-c42e-45f6-89af-bd984e4f4544', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/partition/4'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rh47hp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}, {u'size': 2397988454400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rh47hp', u'partition_table_type': None, u'filesystem': {u'uuid': u'd8497557-1cbc-4880-bda2-6d5ea107783d', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/9/', u'used_size': 2397988454400, u'id': 9, u'serial': None, u'uuid': u'bffd0f5f-35b7-4efb-ac85-0c45a1bbe716'}]
2019-05-04 21:13:01,745 [salt.loaded.ext.module.maasng:632 ][INFO    ][8144] vgroot
2019-05-04 21:13:01,745 [salt.loaded.ext.module.maasng:635 ][INFO    ][8144] lvroot
2019-05-04 21:13:01,746 [salt.loaded.ext.module.maasng:639 ][INFO    ][8144] 107374182400
2019-05-04 21:13:02,465 [salt.loaded.ext.module.maasng:645 ][INFO    ][8144] {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'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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.40', u'id': 28, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'parents': [], u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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.40'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'rh47hp', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/interfaces/4/'}, u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'rh47hp', 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'ip_addresses': [u'192.168.11.40'], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'ff1906f3-7805-43f9-889e-db4124836a8a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rh47hp', u'filesystem': {u'uuid': u'bdb0a907-8db2-4046-a4a9-eb15900afd1d', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/partition/6'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rh47hp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}, {u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rh47hp', u'partition_table_type': None, u'filesystem': {u'uuid': u'a0f3be38-ce85-4940-adf1-15b4f740b6d8', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/11/', u'used_size': 107374182400, u'id': 11, u'serial': None, u'uuid': u'bd95eb79-c093-4401-8844-ca0da354f7fb'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'rh47hp', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'memory_test_status_name': u'Unknown', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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.40', u'id': 28, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'parents': [], u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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.40'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'rh47hp', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/interfaces/4/'}, {u'name': u'enp8s0', u'links': [{u'id': 30, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'rh47hp', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/interfaces/18/'}, {u'name': u'enp9s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'rh47hp', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/interfaces/19/'}, {u'name': u'enp7s0', u'links': [{u'id': 33, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'rh47hp', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'ff1906f3-7805-43f9-889e-db4124836a8a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rh47hp', u'filesystem': {u'uuid': u'bdb0a907-8db2-4046-a4a9-eb15900afd1d', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/partition/6'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rh47hp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rh47hp', u'partition_table_type': None, u'filesystem': {u'uuid': u'a0f3be38-ce85-4940-adf1-15b4f740b6d8', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/11/', u'used_size': 107374182400, u'id': 11, u'serial': None, u'uuid': u'bd95eb79-c093-4401-8844-ca0da354f7fb'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'ff1906f3-7805-43f9-889e-db4124836a8a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rh47hp', u'filesystem': {u'uuid': u'bdb0a907-8db2-4046-a4a9-eb15900afd1d', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/partition/6'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rh47hp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/rh47hp/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/rh47hp/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-05-04 21:13:02,468 [salt.state       :300 ][INFO    ][8144] {'new': {'storage_layout': 'lvm'}}
2019-05-04 21:13:02,468 [salt.state       :1951][INFO    ][8144] Completed state [maas_machines_storage_cmp002_lvm] at time 21:13:02.468633 duration_in_ms=2875.397
2019-05-04 21:13:02,469 [salt.state       :1780][INFO    ][8144] Running state [maas_machines_storage_cmp001_lvm] at time 21:13:02.469181
2019-05-04 21:13:02,469 [salt.state       :1813][INFO    ][8144] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-04 21:13:03,888 [salt.loaded.ext.module.maasng:610 ][INFO    ][8144] h8xrr4
2019-05-04 21:13:03,888 [salt.loaded.ext.module.maasng:626 ][INFO    ][8144] sda
2019-05-04 21:13:04,535 [salt.loaded.ext.module.maasng:361 ][INFO    ][8144] h8xrr4
2019-05-04 21:13:04,632 [salt.loaded.ext.module.maasng:367 ][INFO    ][8144] [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'd7694f00-8814-4652-ae82-a9c02410d342', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h8xrr4', u'filesystem': {u'mount_options': None, u'uuid': u'50c1f35c-e7dc-4072-982e-c1b171296024', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'device_id': 1}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h8xrr4', 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'size': 2397998940160, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/'}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'uuid': u'595dc76f-c5ab-4eb2-a713-19fe51db1bd7', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'h8xrr4', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'c9e87514-c5aa-4e87-865e-3b278cad790c', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 2397988454400, u'type': u'virtual', u'id': 6, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/6/'}]
2019-05-04 21:13:04,632 [salt.loaded.ext.module.maasng:632 ][INFO    ][8144] vgroot
2019-05-04 21:13:04,632 [salt.loaded.ext.module.maasng:635 ][INFO    ][8144] lvroot
2019-05-04 21:13:04,633 [salt.loaded.ext.module.maasng:639 ][INFO    ][8144] 107374182400
2019-05-04 21:13:05,250 [salt.loaded.ext.module.maasng:645 ][INFO    ][8144] {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'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'parents': [], u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'system_id': u'h8xrr4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'h8xrr4', 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'ip_addresses': [u'192.168.11.38'], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'4d46f965-7b90-43f7-ac81-e314a00eeac3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h8xrr4', u'filesystem': {u'uuid': u'52e66133-cf90-42dc-b881-8e013457bdd4', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h8xrr4', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}, {u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'h8xrr4', u'partition_table_type': None, u'filesystem': {u'uuid': u'96eade81-d9c8-4cce-8e79-8377597f8a65', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/12/', u'used_size': 107374182400, u'id': 12, u'serial': None, u'uuid': u'943312eb-4f0a-47e8-941f-25e6b80d3e41'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'h8xrr4', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'memory_test_status_name': u'Unknown', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'parents': [], u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', 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'system_id': u'h8xrr4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'h8xrr4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/interfaces/9/'}, {u'name': u'enp7s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'h8xrr4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/interfaces/10/'}, {u'name': u'enp8s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'h8xrr4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'4d46f965-7b90-43f7-ac81-e314a00eeac3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h8xrr4', u'filesystem': {u'uuid': u'52e66133-cf90-42dc-b881-8e013457bdd4', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h8xrr4', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'h8xrr4', u'partition_table_type': None, u'filesystem': {u'uuid': u'96eade81-d9c8-4cce-8e79-8377597f8a65', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/12/', u'used_size': 107374182400, u'id': 12, u'serial': None, u'uuid': u'943312eb-4f0a-47e8-941f-25e6b80d3e41'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'4d46f965-7b90-43f7-ac81-e314a00eeac3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'h8xrr4', u'filesystem': {u'uuid': u'52e66133-cf90-42dc-b881-8e013457bdd4', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'h8xrr4', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/h8xrr4/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/h8xrr4/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-05-04 21:13:05,252 [salt.state       :300 ][INFO    ][8144] {'new': {'storage_layout': 'lvm'}}
2019-05-04 21:13:05,252 [salt.state       :1951][INFO    ][8144] Completed state [maas_machines_storage_cmp001_lvm] at time 21:13:05.252751 duration_in_ms=2783.569
2019-05-04 21:13:05,256 [salt.minion      :1711][INFO    ][8144] Returning information for job: 20190504211254437606
2019-05-04 21:13:05,852 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211305839130
2019-05-04 21:13:05,874 [salt.minion      :1432][INFO    ][8171] Starting a new job with PID 8171
2019-05-04 21:13:06,606 [salt.state       :915 ][INFO    ][8171] Loading fresh modules for state activity
2019-05-04 21:13:06,636 [salt.fileclient  :1219][INFO    ][8171] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-04 21:13:06,662 [salt.state       :1780][INFO    ][8171] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:06.662472
2019-05-04 21:13:06,662 [salt.state       :1813][INFO    ][8171] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:13:06,664 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8171] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:13:08,078 [salt.state       :300 ][INFO    ][8171] {'pid': 8178, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:13:08,078 [salt.state       :1951][INFO    ][8171] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:08.078614 duration_in_ms=1416.143
2019-05-04 21:13:08,079 [salt.state       :1780][INFO    ][8171] Running state [maas.deploy_machines] at time 21:13:08.079821
2019-05-04 21:13:08,080 [salt.state       :1813][INFO    ][8171] Executing state module.run for [maas.deploy_machines]
2019-05-04 21:13:08,080 [salt.utils.decorators:613 ][WARNING ][8171] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:13:08,801 [salt.loaded.ext.module.maas:684 ][INFO    ][8171] deploymachines hwe_kernel=hwe-16.04 system_id=rh47hp distro_series=xenial
2019-05-04 21:13:17,030 [salt.loaded.ext.module.maas:684 ][INFO    ][8171] deploymachines hwe_kernel=hwe-16.04 system_id=h8xrr4 distro_series=xenial
2019-05-04 21:13:20,884 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211320871653
2019-05-04 21:13:20,901 [salt.minion      :1432][INFO    ][8363] Starting a new job with PID 8363
2019-05-04 21:13:20,916 [salt.minion      :1711][INFO    ][8363] Returning information for job: 20190504211320871653
2019-05-04 21:13:23,316 [salt.loaded.ext.module.maas:684 ][INFO    ][8171] deploymachines hwe_kernel=hwe-16.04 system_id=t3hn3y distro_series=xenial
2019-05-04 21:13:27,425 [salt.loaded.ext.module.maas:684 ][INFO    ][8171] deploymachines hwe_kernel=hwe-16.04 system_id=hyxybc distro_series=xenial
2019-05-04 21:13:32,134 [salt.loaded.ext.module.maas:684 ][INFO    ][8171] deploymachines hwe_kernel=hwe-16.04 system_id=agxeet distro_series=xenial
2019-05-04 21:13:37,333 [salt.state       :300 ][INFO    ][8171] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-04 21:13:37,334 [salt.state       :1951][INFO    ][8171] Completed state [maas.deploy_machines] at time 21:13:37.334618 duration_in_ms=29254.792
2019-05-04 21:13:37,340 [salt.minion      :1711][INFO    ][8171] Returning information for job: 20190504211305839130
2019-05-04 21:13:37,937 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211337926261
2019-05-04 21:13:37,957 [salt.minion      :1432][INFO    ][8766] Starting a new job with PID 8766
2019-05-04 21:13:41,530 [salt.state       :915 ][INFO    ][8766] Loading fresh modules for state activity
2019-05-04 21:13:41,580 [salt.fileclient  :1219][INFO    ][8766] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-04 21:13:41,622 [salt.state       :1780][INFO    ][8766] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:41.622753
2019-05-04 21:13:41,623 [salt.state       :1813][INFO    ][8766] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:13:41,624 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8766] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:13:42,936 [salt.state       :300 ][INFO    ][8766] {'pid': 8780, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:13:42,936 [salt.state       :1951][INFO    ][8766] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:42.936714 duration_in_ms=1313.961
2019-05-04 21:13:42,938 [salt.state       :1780][INFO    ][8766] Running state [maas.wait_for_machine_status] at time 21:13:42.938143
2019-05-04 21:13:42,938 [salt.state       :1813][INFO    ][8766] Executing state module.run for [maas.wait_for_machine_status]
2019-05-04 21:13:42,938 [salt.utils.decorators:613 ][WARNING ][8766] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:13:48,092 [salt.loaded.ext.module.maas:1023][INFO    ][8766] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2244.85168195s left)
2019-05-04 21:13:53,047 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211353034062
2019-05-04 21:13:53,068 [salt.minion      :1432][INFO    ][8817] Starting a new job with PID 8817
2019-05-04 21:13:53,091 [salt.minion      :1711][INFO    ][8817] Returning information for job: 20190504211353034062
2019-05-04 21:14:23,128 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211423113717
2019-05-04 21:14:23,152 [salt.minion      :1432][INFO    ][8891] Starting a new job with PID 8891
2019-05-04 21:14:23,176 [salt.minion      :1711][INFO    ][8891] Returning information for job: 20190504211423113717
2019-05-04 21:14:53,253 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211453240682
2019-05-04 21:14:53,275 [salt.minion      :1432][INFO    ][8923] Starting a new job with PID 8923
2019-05-04 21:14:53,295 [salt.minion      :1711][INFO    ][8923] Returning information for job: 20190504211453240682
2019-05-04 21:15:23,315 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211523304289
2019-05-04 21:15:23,335 [salt.minion      :1432][INFO    ][9088] Starting a new job with PID 9088
2019-05-04 21:15:23,354 [salt.minion      :1711][INFO    ][9088] Returning information for job: 20190504211523304289
2019-05-04 21:15:53,382 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211553369047
2019-05-04 21:15:53,403 [salt.minion      :1432][INFO    ][9167] Starting a new job with PID 9167
2019-05-04 21:15:53,429 [salt.minion      :1711][INFO    ][9167] Returning information for job: 20190504211553369047
2019-05-04 21:16:23,466 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211623454040
2019-05-04 21:16:23,487 [salt.minion      :1432][INFO    ][9342] Starting a new job with PID 9342
2019-05-04 21:16:23,509 [salt.minion      :1711][INFO    ][9342] Returning information for job: 20190504211623454040
2019-05-04 21:16:53,544 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211653529704
2019-05-04 21:16:53,567 [salt.minion      :1432][INFO    ][9401] Starting a new job with PID 9401
2019-05-04 21:16:53,590 [salt.minion      :1711][INFO    ][9401] Returning information for job: 20190504211653529704
2019-05-04 21:17:23,637 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211723621758
2019-05-04 21:17:23,657 [salt.minion      :1432][INFO    ][9578] Starting a new job with PID 9578
2019-05-04 21:17:23,681 [salt.minion      :1711][INFO    ][9578] Returning information for job: 20190504211723621758
2019-05-04 21:17:53,729 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211753716802
2019-05-04 21:17:53,751 [salt.minion      :1432][INFO    ][9642] Starting a new job with PID 9642
2019-05-04 21:17:53,775 [salt.minion      :1711][INFO    ][9642] Returning information for job: 20190504211753716802
2019-05-04 21:18:23,820 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211823808112
2019-05-04 21:18:23,844 [salt.minion      :1432][INFO    ][9768] Starting a new job with PID 9768
2019-05-04 21:18:23,866 [salt.minion      :1711][INFO    ][9768] Returning information for job: 20190504211823808112
2019-05-04 21:18:53,923 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211853910200
2019-05-04 21:18:53,946 [salt.minion      :1432][INFO    ][9799] Starting a new job with PID 9799
2019-05-04 21:18:53,970 [salt.minion      :1711][INFO    ][9799] Returning information for job: 20190504211853910200
2019-05-04 21:19:24,023 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504211924010579
2019-05-04 21:19:24,045 [salt.minion      :1432][INFO    ][9972] Starting a new job with PID 9972
2019-05-04 21:19:24,064 [salt.minion      :1711][INFO    ][9972] Returning information for job: 20190504211924010579
2019-05-04 21:19:34,650 [salt.state       :302 ][ERROR   ][8766] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-05-04 21:19:34,651 [salt.state       :1951][INFO    ][8766] Completed state [maas.wait_for_machine_status] at time 21:19:34.651282 duration_in_ms=351713.135
2019-05-04 21:19:34,655 [salt.minion      :1711][INFO    ][8766] Returning information for job: 20190504211337926261
2019-05-04 21:19:45,327 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command pillar.get with jid 20190504211945315678
2019-05-04 21:19:45,343 [salt.minion      :1432][INFO    ][10191] Starting a new job with PID 10191
2019-05-04 21:19:45,348 [salt.minion      :1711][INFO    ][10191] Returning information for job: 20190504211945315678
2019-05-04 21:19:45,828 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command service.status with jid 20190504211945816114
2019-05-04 21:19:45,841 [salt.minion      :1432][INFO    ][10196] Starting a new job with PID 10196
2019-05-04 21:19:46,196 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10196] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-04 21:19:46,229 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10196] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-04 21:19:46,245 [salt.minion      :1711][INFO    ][10196] Returning information for job: 20190504211945816114
2019-05-04 21:19:46,839 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211946826943
2019-05-04 21:19:46,859 [salt.minion      :1432][INFO    ][10207] Starting a new job with PID 10207
2019-05-04 21:19:50,537 [salt.state       :915 ][INFO    ][10207] Loading fresh modules for state activity
2019-05-04 21:19:50,886 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:19:51,240 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:19:52,102 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:19:52,459 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:19:53,831 [salt.state       :1780][INFO    ][10207] Running state [salt-minion] at time 21:19:53.831295
2019-05-04 21:19:53,831 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [salt-minion]
2019-05-04 21:19:53,832 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:19:53,926 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:53,926 [salt.state       :1951][INFO    ][10207] Completed state [salt-minion] at time 21:19:53.926446 duration_in_ms=95.15
2019-05-04 21:19:53,927 [salt.state       :1780][INFO    ][10207] Running state [salt_minion_dependency_packages] at time 21:19:53.927015
2019-05-04 21:19:53,927 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-04 21:19:53,934 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:53,935 [salt.state       :1951][INFO    ][10207] Completed state [salt_minion_dependency_packages] at time 21:19:53.935040 duration_in_ms=8.024
2019-05-04 21:19:53,938 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/minion.d/minion.conf] at time 21:19:53.938653
2019-05-04 21:19:53,939 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-04 21:19:54,156 [salt.state       :300 ][INFO    ][10207] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-04 21:19:54,156 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/minion.d/minion.conf] at time 21:19:54.156628 duration_in_ms=217.974
2019-05-04 21:19:54,157 [salt.state       :1780][INFO    ][10207] Running state [python-netaddr] at time 21:19:54.156977
2019-05-04 21:19:54,157 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [python-netaddr]
2019-05-04 21:19:54,163 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:54,163 [salt.state       :1951][INFO    ][10207] Completed state [python-netaddr] at time 21:19:54.163904 duration_in_ms=6.927
2019-05-04 21:19:54,166 [salt.state       :1780][INFO    ][10207] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:54.166309
2019-05-04 21:19:54,166 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-04 21:19:54,177 [salt.state       :300 ][INFO    ][10207] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-04 21:19:54,177 [salt.state       :1951][INFO    ][10207] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:54.177289 duration_in_ms=10.979
2019-05-04 21:19:54,178 [salt.state       :1780][INFO    ][10207] Running state [salt-minion] at time 21:19:54.178150
2019-05-04 21:19:54,178 [salt.state       :1813][INFO    ][10207] Executing state service.running for [salt-minion]
2019-05-04 21:19:54,179 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-04 21:19:54,212 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-04 21:19:54,228 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-04 21:19:54,242 [salt.state       :300 ][INFO    ][10207] The service salt-minion is already running
2019-05-04 21:19:54,243 [salt.state       :1951][INFO    ][10207] Completed state [salt-minion] at time 21:19:54.243159 duration_in_ms=65.008
2019-05-04 21:19:54,244 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains.d] at time 21:19:54.244601
2019-05-04 21:19:54,245 [salt.state       :1813][INFO    ][10207] Executing state file.directory for [/etc/salt/grains.d]
2019-05-04 21:19:54,245 [salt.state       :300 ][INFO    ][10207] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-04 21:19:54,246 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains.d] at time 21:19:54.246160 duration_in_ms=1.559
2019-05-04 21:19:54,247 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains] at time 21:19:54.246978
2019-05-04 21:19:54,247 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/grains]
2019-05-04 21:19:54,247 [salt.state       :300 ][INFO    ][10207] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-04 21:19:54,248 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains] at time 21:19:54.248161 duration_in_ms=1.182
2019-05-04 21:19:54,248 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains.d/placeholder] at time 21:19:54.248749
2019-05-04 21:19:54,249 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-04 21:19:54,249 [salt.state       :300 ][INFO    ][10207] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-04 21:19:54,249 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains.d/placeholder] at time 21:19:54.249921 duration_in_ms=1.171
2019-05-04 21:19:54,250 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains.d/sphinx] at time 21:19:54.250462
2019-05-04 21:19:54,250 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-04 21:19:54,264 [salt.state       :300 ][INFO    ][10207] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-04 21:19:54,264 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains.d/sphinx] at time 21:19:54.264340 duration_in_ms=13.878
2019-05-04 21:19:54,266 [salt.state       :1780][INFO    ][10207] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.266354
2019-05-04 21:19:54,266 [salt.state       :1813][INFO    ][10207] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:19:54,267 [salt.state       :300 ][INFO    ][10207] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:19:54,267 [salt.state       :1951][INFO    ][10207] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.267314 duration_in_ms=0.96
2019-05-04 21:19:54,267 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains.d/dns_records] at time 21:19:54.267870
2019-05-04 21:19:54,268 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-04 21:19:54,275 [salt.state       :300 ][INFO    ][10207] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-04 21:19:54,276 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains.d/dns_records] at time 21:19:54.276066 duration_in_ms=8.195
2019-05-04 21:19:54,277 [salt.state       :1780][INFO    ][10207] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.276957
2019-05-04 21:19:54,277 [salt.state       :1813][INFO    ][10207] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:19:54,277 [salt.state       :300 ][INFO    ][10207] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:19:54,277 [salt.state       :1951][INFO    ][10207] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.277927 duration_in_ms=0.97
2019-05-04 21:19:54,278 [salt.state       :1780][INFO    ][10207] Running state [/etc/salt/grains.d/salt] at time 21:19:54.278472
2019-05-04 21:19:54,278 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-04 21:19:54,294 [salt.state       :300 ][INFO    ][10207] File /etc/salt/grains.d/salt is in the correct state
2019-05-04 21:19:54,294 [salt.state       :1951][INFO    ][10207] Completed state [/etc/salt/grains.d/salt] at time 21:19:54.294241 duration_in_ms=15.769
2019-05-04 21:19:54,295 [salt.state       :1780][INFO    ][10207] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.295128
2019-05-04 21:19:54,295 [salt.state       :1813][INFO    ][10207] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:19:54,295 [salt.state       :300 ][INFO    ][10207] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:19:54,296 [salt.state       :1951][INFO    ][10207] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:54.296108 duration_in_ms=0.979
2019-05-04 21:19:54,297 [salt.state       :1780][INFO    ][10207] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:54.297789
2019-05-04 21:19:54,298 [salt.state       :1813][INFO    ][10207] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-04 21:19:54,298 [salt.state       :300 ][INFO    ][10207] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-04 21:19:54,298 [salt.state       :1951][INFO    ][10207] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:54.298790 duration_in_ms=1.001
2019-05-04 21:19:54,299 [salt.state       :1780][INFO    ][10207] Running state [mine.update] at time 21:19:54.299508
2019-05-04 21:19:54,299 [salt.state       :1813][INFO    ][10207] Executing state module.wait for [mine.update]
2019-05-04 21:19:54,300 [salt.state       :300 ][INFO    ][10207] No changes made for mine.update
2019-05-04 21:19:54,300 [salt.state       :1951][INFO    ][10207] Completed state [mine.update] at time 21:19:54.300434 duration_in_ms=0.926
2019-05-04 21:19:54,300 [salt.state       :1780][INFO    ][10207] Running state [ca-certificates] at time 21:19:54.300799
2019-05-04 21:19:54,301 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [ca-certificates]
2019-05-04 21:19:54,307 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:54,307 [salt.state       :1951][INFO    ][10207] Completed state [ca-certificates] at time 21:19:54.307525 duration_in_ms=6.725
2019-05-04 21:19:54,308 [salt.state       :1780][INFO    ][10207] Running state [update-ca-certificates] at time 21:19:54.308114
2019-05-04 21:19:54,308 [salt.state       :1813][INFO    ][10207] Executing state cmd.wait for [update-ca-certificates]
2019-05-04 21:19:54,308 [salt.state       :300 ][INFO    ][10207] No changes made for update-ca-certificates
2019-05-04 21:19:54,308 [salt.state       :1951][INFO    ][10207] Completed state [update-ca-certificates] at time 21:19:54.308786 duration_in_ms=0.672
2019-05-04 21:19:54,309 [salt.state       :1780][INFO    ][10207] Running state [iptables] at time 21:19:54.308983
2019-05-04 21:19:54,309 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [iptables]
2019-05-04 21:19:54,314 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:54,314 [salt.state       :1951][INFO    ][10207] Completed state [iptables] at time 21:19:54.314790 duration_in_ms=5.806
2019-05-04 21:19:54,315 [salt.state       :1780][INFO    ][10207] Running state [iptables-persistent] at time 21:19:54.314995
2019-05-04 21:19:54,315 [salt.state       :1813][INFO    ][10207] Executing state pkg.installed for [iptables-persistent]
2019-05-04 21:19:54,320 [salt.state       :300 ][INFO    ][10207] All specified packages are already installed
2019-05-04 21:19:54,320 [salt.state       :1951][INFO    ][10207] Completed state [iptables-persistent] at time 21:19:54.320751 duration_in_ms=5.756
2019-05-04 21:19:54,321 [salt.state       :1780][INFO    ][10207] Running state [iptables_modules_v4_load] at time 21:19:54.321567
2019-05-04 21:19:54,321 [salt.state       :1813][INFO    ][10207] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-04 21:19:54,322 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'lsmod' in directory '/root'
2019-05-04 21:19:54,345 [salt.state       :300 ][INFO    ][10207] Kernel modules iptable_filter, ip_tables are already present
2019-05-04 21:19:54,346 [salt.state       :1951][INFO    ][10207] Completed state [iptables_modules_v4_load] at time 21:19:54.345905 duration_in_ms=24.337
2019-05-04 21:19:54,346 [salt.state       :1780][INFO    ][10207] Running state [/etc/iptables/rules.v4] at time 21:19:54.346564
2019-05-04 21:19:54,346 [salt.state       :1813][INFO    ][10207] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-04 21:19:54,438 [salt.state       :300 ][INFO    ][10207] File /etc/iptables/rules.v4 is in the correct state
2019-05-04 21:19:54,438 [salt.state       :1951][INFO    ][10207] Completed state [/etc/iptables/rules.v4] at time 21:19:54.438219 duration_in_ms=91.655
2019-05-04 21:19:54,439 [salt.state       :1780][INFO    ][10207] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:54.439038
2019-05-04 21:19:54,439 [salt.state       :1813][INFO    ][10207] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-04 21:19:54,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-04 21:19:54,458 [salt.state       :300 ][INFO    ][10207] onlyif execution failed
2019-05-04 21:19:54,458 [salt.state       :1951][INFO    ][10207] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:54.458482 duration_in_ms=19.443
2019-05-04 21:19:54,459 [salt.state       :1780][INFO    ][10207] Running state [netfilter-persistent] at time 21:19:54.459251
2019-05-04 21:19:54,459 [salt.state       :1813][INFO    ][10207] Executing state service.running for [netfilter-persistent]
2019-05-04 21:19:54,460 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-04 21:19:54,477 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-04 21:19:54,493 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-04 21:19:54,507 [salt.state       :300 ][INFO    ][10207] The service netfilter-persistent is already running
2019-05-04 21:19:54,508 [salt.state       :1951][INFO    ][10207] Completed state [netfilter-persistent] at time 21:19:54.508230 duration_in_ms=48.979
2019-05-04 21:19:54,508 [salt.state       :1780][INFO    ][10207] Running state [iptables_extra.remove_stale_tables] at time 21:19:54.508870
2019-05-04 21:19:54,509 [salt.state       :1813][INFO    ][10207] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-04 21:19:54,509 [salt.state       :300 ][INFO    ][10207] No changes made for iptables_extra.remove_stale_tables
2019-05-04 21:19:54,509 [salt.state       :1951][INFO    ][10207] Completed state [iptables_extra.remove_stale_tables] at time 21:19:54.509607 duration_in_ms=0.736
2019-05-04 21:19:54,509 [salt.state       :1780][INFO    ][10207] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:54.509808
2019-05-04 21:19:54,510 [salt.state       :1813][INFO    ][10207] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-04 21:19:54,510 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10207] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-04 21:19:54,523 [salt.state       :300 ][INFO    ][10207] onlyif execution failed
2019-05-04 21:19:54,524 [salt.state       :1951][INFO    ][10207] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:54.523968 duration_in_ms=14.16
2019-05-04 21:19:54,524 [salt.state       :1780][INFO    ][10207] Running state [/etc/iptables/rules.v6] at time 21:19:54.524708
2019-05-04 21:19:54,525 [salt.state       :1813][INFO    ][10207] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-04 21:19:54,525 [salt.state       :300 ][INFO    ][10207] File /etc/iptables/rules.v6 is not present
2019-05-04 21:19:54,525 [salt.state       :1951][INFO    ][10207] Completed state [/etc/iptables/rules.v6] at time 21:19:54.525544 duration_in_ms=0.836
2019-05-04 21:19:54,526 [salt.state       :1780][INFO    ][10207] Running state [iptables_extra.flush_all] at time 21:19:54.526060
2019-05-04 21:19:54,526 [salt.state       :1813][INFO    ][10207] Executing state module.wait for [iptables_extra.flush_all]
2019-05-04 21:19:54,526 [salt.state       :300 ][INFO    ][10207] No changes made for iptables_extra.flush_all
2019-05-04 21:19:54,526 [salt.state       :1951][INFO    ][10207] Completed state [iptables_extra.flush_all] at time 21:19:54.526702 duration_in_ms=0.642
2019-05-04 21:19:54,529 [salt.minion      :1711][INFO    ][10207] Returning information for job: 20190504211946826943
2019-05-04 21:19:55,165 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211955152206
2019-05-04 21:19:55,187 [salt.minion      :1432][INFO    ][10283] Starting a new job with PID 10283
2019-05-04 21:19:55,869 [salt.state       :915 ][INFO    ][10283] Loading fresh modules for state activity
2019-05-04 21:19:56,487 [salt.state       :1780][INFO    ][10283] Running state [maas-rack-controller] at time 21:19:56.487649
2019-05-04 21:19:56,488 [salt.state       :1813][INFO    ][10283] Executing state pkg.installed for [maas-rack-controller]
2019-05-04 21:19:56,488 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10283] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:19:56,566 [salt.state       :300 ][INFO    ][10283] All specified packages are already installed
2019-05-04 21:19:56,567 [salt.state       :1951][INFO    ][10283] Completed state [maas-rack-controller] at time 21:19:56.567206 duration_in_ms=79.556
2019-05-04 21:19:56,567 [salt.state       :1780][INFO    ][10283] Running state [ipmitool] at time 21:19:56.567474
2019-05-04 21:19:56,567 [salt.state       :1813][INFO    ][10283] Executing state pkg.installed for [ipmitool]
2019-05-04 21:19:56,572 [salt.state       :300 ][INFO    ][10283] All specified packages are already installed
2019-05-04 21:19:56,572 [salt.state       :1951][INFO    ][10283] Completed state [ipmitool] at time 21:19:56.572779 duration_in_ms=5.304
2019-05-04 21:19:56,575 [salt.state       :1780][INFO    ][10283] Running state [/etc/maas/rackd.conf] at time 21:19:56.575164
2019-05-04 21:19:56,575 [salt.state       :1813][INFO    ][10283] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-04 21:19:56,576 [salt.state       :300 ][INFO    ][10283] No changes needed to be made
2019-05-04 21:19:56,576 [salt.state       :1951][INFO    ][10283] Completed state [/etc/maas/rackd.conf] at time 21:19:56.576380 duration_in_ms=1.216
2019-05-04 21:19:56,576 [salt.state       :1780][INFO    ][10283] Running state [/etc/maas/rackd.conf] at time 21:19:56.576574
2019-05-04 21:19:56,576 [salt.state       :1813][INFO    ][10283] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-04 21:19:56,577 [salt.loaded.int.states.file:2298][WARNING ][10283] 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-05-04 21:19:56,577 [salt.state       :300 ][INFO    ][10283] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-04 21:19:56,577 [salt.state       :1951][INFO    ][10283] Completed state [/etc/maas/rackd.conf] at time 21:19:56.577561 duration_in_ms=0.987
2019-05-04 21:19:56,578 [salt.state       :1780][INFO    ][10283] Running state [maas-rackd] at time 21:19:56.578282
2019-05-04 21:19:56,578 [salt.state       :1813][INFO    ][10283] Executing state service.running for [maas-rackd]
2019-05-04 21:19:56,578 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10283] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-04 21:19:56,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10283] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-04 21:19:56,627 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10283] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-04 21:19:56,642 [salt.state       :300 ][INFO    ][10283] The service maas-rackd is already running
2019-05-04 21:19:56,643 [salt.state       :1951][INFO    ][10283] Completed state [maas-rackd] at time 21:19:56.643087 duration_in_ms=64.804
2019-05-04 21:19:56,644 [salt.minion      :1711][INFO    ][10283] Returning information for job: 20190504211955152206
2019-05-04 21:19:57,234 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504211957221081
2019-05-04 21:19:57,256 [salt.minion      :1432][INFO    ][10309] Starting a new job with PID 10309
2019-05-04 21:19:58,018 [salt.state       :915 ][INFO    ][10309] Loading fresh modules for state activity
2019-05-04 21:19:58,771 [salt.state       :1780][INFO    ][10309] Running state [maas-region-controller] at time 21:19:58.771350
2019-05-04 21:19:58,771 [salt.state       :1813][INFO    ][10309] Executing state pkg.installed for [maas-region-controller]
2019-05-04 21:19:58,772 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:19:58,848 [salt.state       :300 ][INFO    ][10309] All specified packages are already installed
2019-05-04 21:19:58,849 [salt.state       :1951][INFO    ][10309] Completed state [maas-region-controller] at time 21:19:58.849251 duration_in_ms=77.902
2019-05-04 21:19:58,849 [salt.state       :1780][INFO    ][10309] Running state [python-oauth] at time 21:19:58.849566
2019-05-04 21:19:58,849 [salt.state       :1813][INFO    ][10309] Executing state pkg.installed for [python-oauth]
2019-05-04 21:19:58,855 [salt.state       :300 ][INFO    ][10309] All specified packages are already installed
2019-05-04 21:19:58,856 [salt.state       :1951][INFO    ][10309] Completed state [python-oauth] at time 21:19:58.855969 duration_in_ms=6.403
2019-05-04 21:19:58,858 [salt.state       :1780][INFO    ][10309] Running state [/etc/maas/regiond.conf] at time 21:19:58.858900
2019-05-04 21:19:58,859 [salt.state       :1813][INFO    ][10309] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-04 21:19:58,911 [salt.state       :300 ][INFO    ][10309] No changes needed to be made
2019-05-04 21:19:58,912 [salt.state       :1951][INFO    ][10309] Completed state [/etc/maas/regiond.conf] at time 21:19:58.912200 duration_in_ms=53.299
2019-05-04 21:19:58,912 [salt.state       :1780][INFO    ][10309] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:58.912755
2019-05-04 21:19:58,913 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-04 21:19:58,990 [salt.state       :300 ][INFO    ][10309] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-04 21:19:58,991 [salt.state       :1951][INFO    ][10309] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:58.991848 duration_in_ms=79.08
2019-05-04 21:19:58,992 [salt.state       :1780][INFO    ][10309] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:58.992867
2019-05-04 21:19:58,993 [salt.state       :1813][INFO    ][10309] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-04 21:19:59,008 [salt.state       :300 ][INFO    ][10309] No changes needed to be made
2019-05-04 21:19:59,009 [salt.state       :1951][INFO    ][10309] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:59.008973 duration_in_ms=16.107
2019-05-04 21:19:59,009 [salt.state       :1780][INFO    ][10309] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:59.009461
2019-05-04 21:19:59,009 [salt.state       :1813][INFO    ][10309] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-04 21:19:59,038 [salt.state       :300 ][INFO    ][10309] No changes needed to be made
2019-05-04 21:19:59,038 [salt.state       :1951][INFO    ][10309] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:59.038899 duration_in_ms=29.439
2019-05-04 21:19:59,039 [salt.state       :1780][INFO    ][10309] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:59.039439
2019-05-04 21:19:59,039 [salt.state       :1813][INFO    ][10309] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-04 21:19:59,068 [salt.state       :300 ][INFO    ][10309] No changes needed to be made
2019-05-04 21:19:59,068 [salt.state       :1951][INFO    ][10309] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:59.068893 duration_in_ms=29.454
2019-05-04 21:19:59,069 [salt.state       :1780][INFO    ][10309] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:59.069392
2019-05-04 21:19:59,069 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-04 21:19:59,083 [salt.state       :300 ][INFO    ][10309] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-04 21:19:59,083 [salt.state       :1951][INFO    ][10309] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:59.083945 duration_in_ms=14.552
2019-05-04 21:19:59,086 [salt.state       :1780][INFO    ][10309] Running state [a2enmod headers] at time 21:19:59.086794
2019-05-04 21:19:59,087 [salt.state       :1813][INFO    ][10309] Executing state cmd.run for [a2enmod headers]
2019-05-04 21:19:59,087 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command 'a2enmod headers' in directory '/root'
2019-05-04 21:19:59,151 [salt.state       :300 ][INFO    ][10309] {'pid': 10332, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-04 21:19:59,152 [salt.state       :1951][INFO    ][10309] Completed state [a2enmod headers] at time 21:19:59.152158 duration_in_ms=65.364
2019-05-04 21:19:59,152 [salt.state       :1780][INFO    ][10309] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:59.152771
2019-05-04 21:19:59,153 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-04 21:19:59,172 [salt.state       :300 ][INFO    ][10309] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-04 21:19:59,172 [salt.state       :1951][INFO    ][10309] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:59.172800 duration_in_ms=20.029
2019-05-04 21:19:59,173 [salt.state       :1780][INFO    ][10309] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:59.173638
2019-05-04 21:19:59,174 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-04 21:19:59,252 [salt.state       :300 ][INFO    ][10309] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-04 21:19:59,253 [salt.state       :1951][INFO    ][10309] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:59.253262 duration_in_ms=79.624
2019-05-04 21:19:59,253 [salt.state       :1780][INFO    ][10309] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:59.253900
2019-05-04 21:19:59,254 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-04 21:19:59,322 [salt.state       :300 ][INFO    ][10309] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-04 21:19:59,323 [salt.state       :1951][INFO    ][10309] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:59.323198 duration_in_ms=69.298
2019-05-04 21:19:59,323 [salt.state       :1780][INFO    ][10309] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:59.323766
2019-05-04 21:19:59,324 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-04 21:19:59,388 [salt.state       :300 ][INFO    ][10309] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-04 21:19:59,389 [salt.state       :1951][INFO    ][10309] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:59.389127 duration_in_ms=65.362
2019-05-04 21:19:59,389 [salt.state       :1780][INFO    ][10309] Running state [/root/.pgpass] at time 21:19:59.389429
2019-05-04 21:19:59,389 [salt.state       :1813][INFO    ][10309] Executing state file.managed for [/root/.pgpass]
2019-05-04 21:19:59,442 [salt.state       :300 ][INFO    ][10309] File /root/.pgpass is in the correct state
2019-05-04 21:19:59,443 [salt.state       :1951][INFO    ][10309] Completed state [/root/.pgpass] at time 21:19:59.442972 duration_in_ms=53.543
2019-05-04 21:19:59,448 [salt.state       :1780][INFO    ][10309] Running state [maas-region syncdb --noinput] at time 21:19:59.448765
2019-05-04 21:19:59,449 [salt.state       :1813][INFO    ][10309] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-04 21:19:59,449 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-04 21:20:01,651 [salt.state       :300 ][INFO    ][10309] {'pid': 10345, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: auth, sessions, maasserver, sites, metadataserver, contenttypes, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-04 21:20:01,652 [salt.state       :1951][INFO    ][10309] Completed state [maas-region syncdb --noinput] at time 21:20:01.652155 duration_in_ms=2203.389
2019-05-04 21:20:01,652 [salt.state       :2022][WARNING ][10309] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-04 21:20:01,654 [salt.state       :1780][INFO    ][10309] Running state [maas-regiond] at time 21:20:01.654176
2019-05-04 21:20:01,654 [salt.state       :1813][INFO    ][10309] Executing state service.running for [maas-regiond]
2019-05-04 21:20:01,655 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-04 21:20:01,690 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-04 21:20:01,705 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-04 21:20:01,721 [salt.state       :300 ][INFO    ][10309] The service maas-regiond is already running
2019-05-04 21:20:01,721 [salt.state       :1951][INFO    ][10309] Completed state [maas-regiond] at time 21:20:01.721302 duration_in_ms=67.126
2019-05-04 21:20:01,722 [salt.state       :1780][INFO    ][10309] Running state [bind9] at time 21:20:01.722841
2019-05-04 21:20:01,723 [salt.state       :1813][INFO    ][10309] Executing state service.running for [bind9]
2019-05-04 21:20:01,723 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-04 21:20:01,740 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-04 21:20:01,755 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-04 21:20:01,770 [salt.state       :300 ][INFO    ][10309] The service bind9 is already running
2019-05-04 21:20:01,770 [salt.state       :1951][INFO    ][10309] Completed state [bind9] at time 21:20:01.770753 duration_in_ms=47.912
2019-05-04 21:20:01,772 [salt.state       :1780][INFO    ][10309] Running state [apache2] at time 21:20:01.772288
2019-05-04 21:20:01,772 [salt.state       :1813][INFO    ][10309] Executing state service.running for [apache2]
2019-05-04 21:20:01,773 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-04 21:20:01,788 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-04 21:20:01,803 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-04 21:20:01,821 [salt.state       :300 ][INFO    ][10309] The service apache2 is already running
2019-05-04 21:20:01,822 [salt.state       :1951][INFO    ][10309] Completed state [apache2] at time 21:20:01.822227 duration_in_ms=49.94
2019-05-04 21:20:01,823 [salt.state       :1780][INFO    ][10309] Running state [maasng.wait_for_http_code] at time 21:20:01.823754
2019-05-04 21:20:01,824 [salt.state       :1813][INFO    ][10309] Executing state module.run for [maasng.wait_for_http_code]
2019-05-04 21:20:01,824 [salt.utils.decorators:613 ][WARNING ][10309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:20:01,950 [salt.state       :300 ][INFO    ][10309] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-04 21:20:01,951 [salt.state       :1951][INFO    ][10309] Completed state [maasng.wait_for_http_code] at time 21:20:01.951598 duration_in_ms=127.842
2019-05-04 21:20:01,953 [salt.state       :1780][INFO    ][10309] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:20:01.953140
2019-05-04 21:20:01,953 [salt.state       :1813][INFO    ][10309] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-04 21:20:01,954 [salt.state       :300 ][INFO    ][10309] /var/lib/maas/.setup_admin exists
2019-05-04 21:20:01,955 [salt.state       :1951][INFO    ][10309] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:20:01.954983 duration_in_ms=1.842
2019-05-04 21:20:01,956 [salt.state       :1780][INFO    ][10309] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:01.956145
2019-05-04 21:20:01,956 [salt.state       :1813][INFO    ][10309] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:20:01,957 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10309] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:20:03,522 [salt.state       :300 ][INFO    ][10309] {'pid': 10374, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:20:03,523 [salt.state       :1951][INFO    ][10309] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:03.523235 duration_in_ms=1567.09
2019-05-04 21:20:03,532 [salt.state       :1780][INFO    ][10309] Running state [maas_region_boot_source_resources_mirror] at time 21:20:03.532063
2019-05-04 21:20:03,532 [salt.state       :1813][INFO    ][10309] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-04 21:20:03,651 [salt.state       :300 ][INFO    ][10309] {'changes': {}}
2019-05-04 21:20:03,651 [salt.state       :1951][INFO    ][10309] Completed state [maas_region_boot_source_resources_mirror] at time 21:20:03.651665 duration_in_ms=119.601
2019-05-04 21:20:03,652 [salt.state       :1780][INFO    ][10309] Running state [maasng.boot_resources_import] at time 21:20:03.652832
2019-05-04 21:20:03,653 [salt.state       :1813][INFO    ][10309] Executing state module.run for [maasng.boot_resources_import]
2019-05-04 21:20:03,654 [salt.utils.decorators:613 ][WARNING ][10309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:20:03,777 [salt.loaded.ext.module.maasng:1600][INFO    ][10309] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-04 21:20:08,833 [salt.loaded.ext.module.maasng:1600][INFO    ][10309] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-04 21:20:12,295 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212012282656
2019-05-04 21:20:12,318 [salt.minion      :1432][INFO    ][10405] Starting a new job with PID 10405
2019-05-04 21:20:12,340 [salt.minion      :1711][INFO    ][10405] Returning information for job: 20190504212012282656
2019-05-04 21:20:13,899 [salt.loaded.ext.module.maasng:1600][INFO    ][10309] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-04 21:20:19,026 [salt.state       :300 ][INFO    ][10309] {'ret': True}
2019-05-04 21:20:19,026 [salt.state       :1951][INFO    ][10309] Completed state [maasng.boot_resources_import] at time 21:20:19.026621 duration_in_ms=15373.789
2019-05-04 21:20:19,027 [salt.state       :1780][INFO    ][10309] Running state [maas_region_boot_sources_selection_xenial] at time 21:20:19.027827
2019-05-04 21:20:19,028 [salt.state       :1813][INFO    ][10309] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-04 21:20:19,240 [salt.state       :300 ][INFO    ][10309] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-04 21:20:19,241 [salt.state       :1951][INFO    ][10309] Completed state [maas_region_boot_sources_selection_xenial] at time 21:20:19.241238 duration_in_ms=213.409
2019-05-04 21:20:19,243 [salt.state       :1780][INFO    ][10309] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:19.243365
2019-05-04 21:20:19,244 [salt.state       :1813][INFO    ][10309] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-04 21:20:19,244 [salt.utils.decorators:613 ][WARNING ][10309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:20:19,245 [salt.loaded.ext.module.maasng:1771][INFO    ][10309] boot-sources sync initiated for ALL Rack's
2019-05-04 21:20:20,420 [salt.state       :300 ][INFO    ][10309] {'ret': True}
2019-05-04 21:20:20,420 [salt.state       :1951][INFO    ][10309] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:20.420696 duration_in_ms=1177.332
2019-05-04 21:20:20,421 [salt.state       :1780][INFO    ][10309] Running state [maas.process_maas_config] at time 21:20:20.421955
2019-05-04 21:20:20,422 [salt.state       :1813][INFO    ][10309] Executing state module.run for [maas.process_maas_config]
2019-05-04 21:20:20,422 [salt.utils.decorators:613 ][WARNING ][10309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:20:20,423 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=enable_http_proxy value=True
2019-05-04 21:20:20,465 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=upstream_dns value=8.8.8.8
2019-05-04 21:20:20,512 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=commissioning_distro_series value=xenial
2019-05-04 21:20:20,558 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=default_osystem value=ubuntu
2019-05-04 21:20:20,607 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=active_discovery_interval value=600
2019-05-04 21:20:20,649 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=dnssec_validation value=no
2019-05-04 21:20:20,690 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=maas_name value=mas01
2019-05-04 21:20:23,268 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=network_discovery value=enabled
2019-05-04 21:20:23,370 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=enable_third_party_drivers value=True
2019-05-04 21:20:23,424 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=default_storage_layout value=lvm
2019-05-04 21:20:23,458 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=ntp_external_only value=True
2019-05-04 21:20:23,487 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-04 21:20:23,518 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=default_distro_series value=xenial
2019-05-04 21:20:23,559 [salt.loaded.ext.module.maas:92  ][INFO    ][10309] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-04 21:20:23,631 [salt.state       :300 ][INFO    ][10309] {'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-05-04 21:20:23,632 [salt.state       :1951][INFO    ][10309] Completed state [maas.process_maas_config] at time 21:20:23.632097 duration_in_ms=3210.141
2019-05-04 21:20:23,632 [salt.state       :1780][INFO    ][10309] Running state [pxe_admin] at time 21:20:23.632590
2019-05-04 21:20:23,632 [salt.state       :1813][INFO    ][10309] Executing state maasng.fabric_present for [pxe_admin]
2019-05-04 21:20:23,673 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-04 21:20:23,733 [salt.loaded.ext.module.maasng:1008][WARNING ][10309] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-04 21:20:23,733 [salt.loaded.ext.module.maasng:1011][WARNING ][10309] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-04 21:20:23,775 [salt.state       :300 ][INFO    ][10309] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-04 21:20:23,775 [salt.state       :1951][INFO    ][10309] Completed state [pxe_admin] at time 21:20:23.775716 duration_in_ms=143.126
2019-05-04 21:20:23,775 [salt.state       :1780][INFO    ][10309] Running state [vlan 0] at time 21:20:23.775918
2019-05-04 21:20:23,776 [salt.state       :1813][INFO    ][10309] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-04 21:20:23,818 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-04 21:20:23,907 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{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'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-04 21:20:24,110 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'id': 0}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'id': 1}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'wrwawt', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'id': 2}]
2019-05-04 21:20:24,164 [salt.state       :300 ][INFO    ][10309] {'new': 'Vlan untagged was updated'}
2019-05-04 21:20:24,165 [salt.state       :1951][INFO    ][10309] Completed state [vlan 0] at time 21:20:24.165003 duration_in_ms=389.085
2019-05-04 21:20:24,165 [salt.state       :1780][INFO    ][10309] Running state [192.168.11.0/24] at time 21:20:24.165613
2019-05-04 21:20:24,165 [salt.state       :1813][INFO    ][10309] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-04 21:20:24,284 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{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'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-04 21:20:24,285 [salt.loaded.ext.module.maasng:1235][WARNING ][10309] Ignoring parameter vlan:0
2019-05-04 21:20:24,332 [salt.state       :300 ][INFO    ][10309] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-04 21:20:24,332 [salt.state       :1951][INFO    ][10309] Completed state [192.168.11.0/24] at time 21:20:24.332736 duration_in_ms=167.122
2019-05-04 21:20:24,333 [salt.state       :1780][INFO    ][10309] Running state [maas_create_iprange_1] at time 21:20:24.333316
2019-05-04 21:20:24,333 [salt.state       :1813][INFO    ][10309] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-04 21:20:24,368 [salt.state       :300 ][INFO    ][10309] Iprange maas_create_iprange_1 already exist.
2019-05-04 21:20:24,369 [salt.state       :1951][INFO    ][10309] Completed state [maas_create_iprange_1] at time 21:20:24.369046 duration_in_ms=35.731
2019-05-04 21:20:24,369 [salt.state       :1780][INFO    ][10309] Running state [vlan 0] at time 21:20:24.369226
2019-05-04 21:20:24,369 [salt.state       :1813][INFO    ][10309] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-04 21:20:24,410 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:20:24,494 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:20:24,638 [salt.loaded.ext.module.maasng:945 ][INFO    ][10309] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:20:24,692 [salt.state       :300 ][INFO    ][10309] {'new': 'Vlan untagged was updated'}
2019-05-04 21:20:24,693 [salt.state       :1951][INFO    ][10309] Completed state [vlan 0] at time 21:20:24.693178 duration_in_ms=323.95
2019-05-04 21:20:24,693 [salt.state       :1780][INFO    ][10309] Running state [opnfv] at time 21:20:24.693612
2019-05-04 21:20:24,693 [salt.state       :1813][INFO    ][10309] Executing state maasng.sshkey_present for [opnfv]
2019-05-04 21:20:24,716 [salt.loaded.ext.module.maasng:1903][INFO    ][10309] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-04 21:20:24,716 [salt.state       :300 ][INFO    ][10309] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-04 21:20:24,716 [salt.state       :1951][INFO    ][10309] Completed state [opnfv] at time 21:20:24.716559 duration_in_ms=22.945
2019-05-04 21:20:24,718 [salt.minion      :1711][INFO    ][10309] Returning information for job: 20190504211957221081
2019-05-04 21:20:25,136 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504212025125558
2019-05-04 21:20:25,146 [salt.minion      :1432][INFO    ][11374] Starting a new job with PID 11374
2019-05-04 21:20:28,553 [salt.state       :915 ][INFO    ][11374] Loading fresh modules for state activity
2019-05-04 21:20:28,606 [salt.state       :1780][INFO    ][11374] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:28.606609
2019-05-04 21:20:28,606 [salt.state       :1813][INFO    ][11374] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:20:28,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11374] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:20:30,053 [salt.state       :300 ][INFO    ][11374] {'pid': 11453, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:20:30,054 [salt.state       :1951][INFO    ][11374] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:30.054675 duration_in_ms=1448.065
2019-05-04 21:20:30,057 [salt.state       :1780][INFO    ][11374] Running state [maas.process_machines] at time 21:20:30.057031
2019-05-04 21:20:30,057 [salt.state       :1813][INFO    ][11374] Executing state module.run for [maas.process_machines]
2019-05-04 21:20:30,058 [salt.utils.decorators:613 ][WARNING ][11374] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:20:30,613 [salt.loaded.ext.module.maas:412 ][WARNING ][11374] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:20:30,614 [salt.loaded.ext.module.maas:92  ][INFO    ][11374] 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=rh47hp architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:20:31,898 [salt.loaded.ext.module.maas:412 ][WARNING ][11374] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:20:31,899 [salt.loaded.ext.module.maas:92  ][INFO    ][11374] 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=h8xrr4 architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:20:33,233 [salt.loaded.ext.module.maas:412 ][WARNING ][11374] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:20:33,234 [salt.loaded.ext.module.maas:92  ][INFO    ][11374] 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=t3hn3y architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:20:34,540 [salt.loaded.ext.module.maas:412 ][WARNING ][11374] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:20:34,541 [salt.loaded.ext.module.maas:92  ][INFO    ][11374] 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=hyxybc architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:20:35,815 [salt.loaded.ext.module.maas:412 ][WARNING ][11374] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:20:35,816 [salt.loaded.ext.module.maas:92  ][INFO    ][11374] 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=agxeet architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:20:36,767 [salt.state       :300 ][INFO    ][11374] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-04 21:20:36,767 [salt.state       :1951][INFO    ][11374] Completed state [maas.process_machines] at time 21:20:36.767515 duration_in_ms=6710.483
2019-05-04 21:20:36,771 [salt.minion      :1711][INFO    ][11374] Returning information for job: 20190504212025125558
2019-05-04 21:21:07,851 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504212107840525
2019-05-04 21:21:07,873 [salt.minion      :1432][INFO    ][11684] Starting a new job with PID 11684
2019-05-04 21:21:11,557 [salt.state       :915 ][INFO    ][11684] Loading fresh modules for state activity
2019-05-04 21:21:11,642 [salt.state       :1780][INFO    ][11684] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:11.642797
2019-05-04 21:21:11,643 [salt.state       :1813][INFO    ][11684] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:21:11,645 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11684] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:21:13,180 [salt.state       :300 ][INFO    ][11684] {'pid': 11691, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:21:13,181 [salt.state       :1951][INFO    ][11684] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:13.181696 duration_in_ms=1538.899
2019-05-04 21:21:13,185 [salt.state       :1780][INFO    ][11684] Running state [maas.wait_for_machine_status] at time 21:21:13.185095
2019-05-04 21:21:13,185 [salt.state       :1813][INFO    ][11684] Executing state module.run for [maas.wait_for_machine_status]
2019-05-04 21:21:13,186 [salt.utils.decorators:613 ][WARNING ][11684] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:21:16,469 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1496.72747588s left)
2019-05-04 21:21:22,960 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212122946542
2019-05-04 21:21:22,982 [salt.minion      :1432][INFO    ][11810] Starting a new job with PID 11810
2019-05-04 21:21:23,007 [salt.minion      :1711][INFO    ][11810] Returning information for job: 20190504212122946542
2019-05-04 21:21:49,620 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1463.57661295s left)
2019-05-04 21:21:53,049 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212153036521
2019-05-04 21:21:53,071 [salt.minion      :1432][INFO    ][11873] Starting a new job with PID 11873
2019-05-04 21:21:53,094 [salt.minion      :1711][INFO    ][11873] Returning information for job: 20190504212153036521
2019-05-04 21:22:22,181 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1431.01512909s left)
2019-05-04 21:22:23,108 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212223100491
2019-05-04 21:22:23,120 [salt.minion      :1432][INFO    ][12407] Starting a new job with PID 12407
2019-05-04 21:22:23,132 [salt.minion      :1711][INFO    ][12407] Returning information for job: 20190504212223100491
2019-05-04 21:22:53,129 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212253116256
2019-05-04 21:22:53,150 [salt.minion      :1432][INFO    ][12458] Starting a new job with PID 12458
2019-05-04 21:22:53,172 [salt.minion      :1711][INFO    ][12458] Returning information for job: 20190504212253116256
2019-05-04 21:22:55,750 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1397.4463079s left)
2019-05-04 21:23:23,176 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212323163349
2019-05-04 21:23:23,198 [salt.minion      :1432][INFO    ][12707] Starting a new job with PID 12707
2019-05-04 21:23:23,221 [salt.minion      :1711][INFO    ][12707] Returning information for job: 20190504212323163349
2019-05-04 21:23:29,218 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1363.97805309s left)
2019-05-04 21:23:53,227 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212353214096
2019-05-04 21:23:53,250 [salt.minion      :1432][INFO    ][12737] Starting a new job with PID 12737
2019-05-04 21:23:53,275 [salt.minion      :1711][INFO    ][12737] Returning information for job: 20190504212353214096
2019-05-04 21:24:02,680 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1330.51652908s left)
2019-05-04 21:24:23,286 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212423273347
2019-05-04 21:24:23,307 [salt.minion      :1432][INFO    ][12794] Starting a new job with PID 12794
2019-05-04 21:24:23,331 [salt.minion      :1711][INFO    ][12794] Returning information for job: 20190504212423273347
2019-05-04 21:24:35,780 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1297.41649389s left)
2019-05-04 21:24:53,487 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212453474910
2019-05-04 21:24:53,507 [salt.minion      :1432][INFO    ][12882] Starting a new job with PID 12882
2019-05-04 21:24:53,530 [salt.minion      :1711][INFO    ][12882] Returning information for job: 20190504212453474910
2019-05-04 21:25:09,537 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1263.65993905s left)
2019-05-04 21:25:23,552 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212523539245
2019-05-04 21:25:23,574 [salt.minion      :1432][INFO    ][13178] Starting a new job with PID 13178
2019-05-04 21:25:23,599 [salt.minion      :1711][INFO    ][13178] Returning information for job: 20190504212523539245
2019-05-04 21:25:43,044 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1230.15236592s left)
2019-05-04 21:25:53,621 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212553608084
2019-05-04 21:25:53,644 [salt.minion      :1432][INFO    ][13198] Starting a new job with PID 13198
2019-05-04 21:25:53,668 [salt.minion      :1711][INFO    ][13198] Returning information for job: 20190504212553608084
2019-05-04 21:26:16,844 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1196.35285592s left)
2019-05-04 21:26:23,697 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212623684791
2019-05-04 21:26:23,720 [salt.minion      :1432][INFO    ][13250] Starting a new job with PID 13250
2019-05-04 21:26:23,745 [salt.minion      :1711][INFO    ][13250] Returning information for job: 20190504212623684791
2019-05-04 21:26:50,022 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1163.17470002s left)
2019-05-04 21:26:53,777 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212653764587
2019-05-04 21:26:53,800 [salt.minion      :1432][INFO    ][13271] Starting a new job with PID 13271
2019-05-04 21:26:53,824 [salt.minion      :1711][INFO    ][13271] Returning information for job: 20190504212653764587
2019-05-04 21:27:23,702 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1129.49448609s left)
2019-05-04 21:27:23,862 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212723850311
2019-05-04 21:27:23,885 [salt.minion      :1432][INFO    ][13326] Starting a new job with PID 13326
2019-05-04 21:27:23,908 [salt.minion      :1711][INFO    ][13326] Returning information for job: 20190504212723850311
2019-05-04 21:27:53,950 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212753937203
2019-05-04 21:27:53,967 [salt.minion      :1432][INFO    ][13345] Starting a new job with PID 13345
2019-05-04 21:27:53,993 [salt.minion      :1711][INFO    ][13345] Returning information for job: 20190504212753937203
2019-05-04 21:27:57,116 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1096.08059096s left)
2019-05-04 21:28:24,041 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212824029188
2019-05-04 21:28:24,064 [salt.minion      :1432][INFO    ][13400] Starting a new job with PID 13400
2019-05-04 21:28:24,088 [salt.minion      :1711][INFO    ][13400] Returning information for job: 20190504212824029188
2019-05-04 21:28:30,847 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1062.34993505s left)
2019-05-04 21:28:54,145 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212854132315
2019-05-04 21:28:54,168 [salt.minion      :1432][INFO    ][13420] Starting a new job with PID 13420
2019-05-04 21:28:54,193 [salt.minion      :1711][INFO    ][13420] Returning information for job: 20190504212854132315
2019-05-04 21:29:04,476 [salt.loaded.ext.module.maas:1023][INFO    ][11684] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1028.72024298s left)
2019-05-04 21:29:24,257 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504212924243370
2019-05-04 21:29:24,279 [salt.minion      :1432][INFO    ][13476] Starting a new job with PID 13476
2019-05-04 21:29:24,303 [salt.minion      :1711][INFO    ][13476] Returning information for job: 20190504212924243370
2019-05-04 21:29:37,963 [salt.loaded.ext.module.maas:993 ][INFO    ][11684] Machine agxeet mark broken
2019-05-04 21:29:38,740 [salt.loaded.ext.module.maas:996 ][INFO    ][11684] Machine agxeet mark fixed
2019-05-04 21:29:39,988 [salt.loaded.ext.module.maas:684 ][INFO    ][11684] deploymachines hwe_kernel=hwe-16.04 system_id=agxeet distro_series=xenial
2019-05-04 21:29:43,054 [salt.loaded.ext.module.maas:160 ][ERROR   ][11684] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-05-04 21:29:43,056 [salt.state       :302 ][ERROR   ][11684] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-05-04 21:29:43,056 [salt.state       :1951][INFO    ][11684] Completed state [maas.wait_for_machine_status] at time 21:29:43.056485 duration_in_ms=509871.388
2019-05-04 21:29:43,060 [salt.minion      :1711][INFO    ][11684] Returning information for job: 20190504212107840525
2019-05-04 21:29:53,792 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command pillar.get with jid 20190504212953779858
2019-05-04 21:29:53,812 [salt.minion      :1432][INFO    ][13570] Starting a new job with PID 13570
2019-05-04 21:29:53,821 [salt.minion      :1711][INFO    ][13570] Returning information for job: 20190504212953779858
2019-05-04 21:29:54,321 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command service.status with jid 20190504212954308557
2019-05-04 21:29:54,342 [salt.minion      :1432][INFO    ][13575] Starting a new job with PID 13575
2019-05-04 21:29:54,738 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13575] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-04 21:29:54,770 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13575] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-04 21:29:54,785 [salt.minion      :1711][INFO    ][13575] Returning information for job: 20190504212954308557
2019-05-04 21:29:55,327 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504212955315188
2019-05-04 21:29:55,347 [salt.minion      :1432][INFO    ][13586] Starting a new job with PID 13586
2019-05-04 21:29:59,033 [salt.state       :915 ][INFO    ][13586] Loading fresh modules for state activity
2019-05-04 21:29:59,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:29:59,794 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:30:00,665 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:30:00,989 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'salt-minion --version' in directory '/root'
2019-05-04 21:30:02,077 [salt.state       :1780][INFO    ][13586] Running state [salt-minion] at time 21:30:02.077679
2019-05-04 21:30:02,078 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [salt-minion]
2019-05-04 21:30:02,078 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:30:02,149 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,149 [salt.state       :1951][INFO    ][13586] Completed state [salt-minion] at time 21:30:02.149527 duration_in_ms=71.849
2019-05-04 21:30:02,149 [salt.state       :1780][INFO    ][13586] Running state [salt_minion_dependency_packages] at time 21:30:02.149770
2019-05-04 21:30:02,150 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-04 21:30:02,154 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,154 [salt.state       :1951][INFO    ][13586] Completed state [salt_minion_dependency_packages] at time 21:30:02.154680 duration_in_ms=4.909
2019-05-04 21:30:02,156 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/minion.d/minion.conf] at time 21:30:02.156900
2019-05-04 21:30:02,157 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-04 21:30:02,337 [salt.state       :300 ][INFO    ][13586] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-04 21:30:02,337 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/minion.d/minion.conf] at time 21:30:02.337722 duration_in_ms=180.821
2019-05-04 21:30:02,337 [salt.state       :1780][INFO    ][13586] Running state [python-netaddr] at time 21:30:02.337899
2019-05-04 21:30:02,338 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [python-netaddr]
2019-05-04 21:30:02,344 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,344 [salt.state       :1951][INFO    ][13586] Completed state [python-netaddr] at time 21:30:02.344633 duration_in_ms=6.734
2019-05-04 21:30:02,347 [salt.state       :1780][INFO    ][13586] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:30:02.347404
2019-05-04 21:30:02,347 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-04 21:30:02,357 [salt.state       :300 ][INFO    ][13586] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-04 21:30:02,357 [salt.state       :1951][INFO    ][13586] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:30:02.357422 duration_in_ms=10.018
2019-05-04 21:30:02,358 [salt.state       :1780][INFO    ][13586] Running state [salt-minion] at time 21:30:02.358297
2019-05-04 21:30:02,358 [salt.state       :1813][INFO    ][13586] Executing state service.running for [salt-minion]
2019-05-04 21:30:02,359 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:02,396 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-04 21:30:02,412 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-04 21:30:02,429 [salt.state       :300 ][INFO    ][13586] The service salt-minion is already running
2019-05-04 21:30:02,430 [salt.state       :1951][INFO    ][13586] Completed state [salt-minion] at time 21:30:02.430160 duration_in_ms=71.863
2019-05-04 21:30:02,431 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains.d] at time 21:30:02.431293
2019-05-04 21:30:02,431 [salt.state       :1813][INFO    ][13586] Executing state file.directory for [/etc/salt/grains.d]
2019-05-04 21:30:02,432 [salt.state       :300 ][INFO    ][13586] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-04 21:30:02,432 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains.d] at time 21:30:02.432389 duration_in_ms=1.095
2019-05-04 21:30:02,432 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains] at time 21:30:02.432892
2019-05-04 21:30:02,433 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/grains]
2019-05-04 21:30:02,433 [salt.state       :300 ][INFO    ][13586] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-04 21:30:02,433 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains] at time 21:30:02.433644 duration_in_ms=0.752
2019-05-04 21:30:02,434 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains.d/placeholder] at time 21:30:02.433979
2019-05-04 21:30:02,434 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-04 21:30:02,434 [salt.state       :300 ][INFO    ][13586] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-04 21:30:02,434 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains.d/placeholder] at time 21:30:02.434707 duration_in_ms=0.729
2019-05-04 21:30:02,435 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains.d/sphinx] at time 21:30:02.435041
2019-05-04 21:30:02,435 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-04 21:30:02,457 [salt.state       :300 ][INFO    ][13586] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-04 21:30:02,457 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains.d/sphinx] at time 21:30:02.457330 duration_in_ms=22.289
2019-05-04 21:30:02,459 [salt.state       :1780][INFO    ][13586] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.459797
2019-05-04 21:30:02,460 [salt.state       :1813][INFO    ][13586] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:30:02,460 [salt.state       :300 ][INFO    ][13586] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:30:02,460 [salt.state       :1951][INFO    ][13586] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.460836 duration_in_ms=1.038
2019-05-04 21:30:02,461 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains.d/dns_records] at time 21:30:02.461448
2019-05-04 21:30:02,461 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-04 21:30:02,475 [salt.state       :300 ][INFO    ][13586] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-04 21:30:02,475 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains.d/dns_records] at time 21:30:02.475603 duration_in_ms=14.156
2019-05-04 21:30:02,476 [salt.state       :1780][INFO    ][13586] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.476614
2019-05-04 21:30:02,476 [salt.state       :1813][INFO    ][13586] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:30:02,477 [salt.state       :300 ][INFO    ][13586] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:30:02,477 [salt.state       :1951][INFO    ][13586] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.477466 duration_in_ms=0.852
2019-05-04 21:30:02,478 [salt.state       :1780][INFO    ][13586] Running state [/etc/salt/grains.d/salt] at time 21:30:02.477985
2019-05-04 21:30:02,478 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-04 21:30:02,487 [salt.state       :300 ][INFO    ][13586] File /etc/salt/grains.d/salt is in the correct state
2019-05-04 21:30:02,487 [salt.state       :1951][INFO    ][13586] Completed state [/etc/salt/grains.d/salt] at time 21:30:02.487471 duration_in_ms=9.487
2019-05-04 21:30:02,488 [salt.state       :1780][INFO    ][13586] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.488431
2019-05-04 21:30:02,488 [salt.state       :1813][INFO    ][13586] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-04 21:30:02,489 [salt.state       :300 ][INFO    ][13586] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-04 21:30:02,489 [salt.state       :1951][INFO    ][13586] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:30:02.489253 duration_in_ms=0.822
2019-05-04 21:30:02,491 [salt.state       :1780][INFO    ][13586] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:30:02.491269
2019-05-04 21:30:02,491 [salt.state       :1813][INFO    ][13586] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-04 21:30:02,491 [salt.state       :300 ][INFO    ][13586] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-04 21:30:02,492 [salt.state       :1951][INFO    ][13586] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:30:02.492109 duration_in_ms=0.84
2019-05-04 21:30:02,492 [salt.state       :1780][INFO    ][13586] Running state [mine.update] at time 21:30:02.492800
2019-05-04 21:30:02,493 [salt.state       :1813][INFO    ][13586] Executing state module.wait for [mine.update]
2019-05-04 21:30:02,493 [salt.state       :300 ][INFO    ][13586] No changes made for mine.update
2019-05-04 21:30:02,493 [salt.state       :1951][INFO    ][13586] Completed state [mine.update] at time 21:30:02.493564 duration_in_ms=0.763
2019-05-04 21:30:02,493 [salt.state       :1780][INFO    ][13586] Running state [ca-certificates] at time 21:30:02.493792
2019-05-04 21:30:02,494 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [ca-certificates]
2019-05-04 21:30:02,501 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,502 [salt.state       :1951][INFO    ][13586] Completed state [ca-certificates] at time 21:30:02.502007 duration_in_ms=8.214
2019-05-04 21:30:02,502 [salt.state       :1780][INFO    ][13586] Running state [update-ca-certificates] at time 21:30:02.502698
2019-05-04 21:30:02,502 [salt.state       :1813][INFO    ][13586] Executing state cmd.wait for [update-ca-certificates]
2019-05-04 21:30:02,503 [salt.state       :300 ][INFO    ][13586] No changes made for update-ca-certificates
2019-05-04 21:30:02,503 [salt.state       :1951][INFO    ][13586] Completed state [update-ca-certificates] at time 21:30:02.503439 duration_in_ms=0.741
2019-05-04 21:30:02,503 [salt.state       :1780][INFO    ][13586] Running state [iptables] at time 21:30:02.503682
2019-05-04 21:30:02,503 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [iptables]
2019-05-04 21:30:02,511 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,511 [salt.state       :1951][INFO    ][13586] Completed state [iptables] at time 21:30:02.511361 duration_in_ms=7.678
2019-05-04 21:30:02,511 [salt.state       :1780][INFO    ][13586] Running state [iptables-persistent] at time 21:30:02.511596
2019-05-04 21:30:02,511 [salt.state       :1813][INFO    ][13586] Executing state pkg.installed for [iptables-persistent]
2019-05-04 21:30:02,518 [salt.state       :300 ][INFO    ][13586] All specified packages are already installed
2019-05-04 21:30:02,519 [salt.state       :1951][INFO    ][13586] Completed state [iptables-persistent] at time 21:30:02.519015 duration_in_ms=7.419
2019-05-04 21:30:02,520 [salt.state       :1780][INFO    ][13586] Running state [iptables_modules_v4_load] at time 21:30:02.519972
2019-05-04 21:30:02,520 [salt.state       :1813][INFO    ][13586] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-04 21:30:02,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'lsmod' in directory '/root'
2019-05-04 21:30:02,541 [salt.state       :300 ][INFO    ][13586] Kernel modules iptable_filter, ip_tables are already present
2019-05-04 21:30:02,542 [salt.state       :1951][INFO    ][13586] Completed state [iptables_modules_v4_load] at time 21:30:02.542027 duration_in_ms=22.055
2019-05-04 21:30:02,542 [salt.state       :1780][INFO    ][13586] Running state [/etc/iptables/rules.v4] at time 21:30:02.542638
2019-05-04 21:30:02,542 [salt.state       :1813][INFO    ][13586] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-04 21:30:02,631 [salt.state       :300 ][INFO    ][13586] File /etc/iptables/rules.v4 is in the correct state
2019-05-04 21:30:02,631 [salt.state       :1951][INFO    ][13586] Completed state [/etc/iptables/rules.v4] at time 21:30:02.631159 duration_in_ms=88.521
2019-05-04 21:30:02,631 [salt.state       :1780][INFO    ][13586] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:30:02.631795
2019-05-04 21:30:02,631 [salt.state       :1813][INFO    ][13586] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-04 21:30:02,632 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-04 21:30:02,650 [salt.state       :300 ][INFO    ][13586] onlyif execution failed
2019-05-04 21:30:02,650 [salt.state       :1951][INFO    ][13586] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:30:02.650429 duration_in_ms=18.634
2019-05-04 21:30:02,651 [salt.state       :1780][INFO    ][13586] Running state [netfilter-persistent] at time 21:30:02.651075
2019-05-04 21:30:02,651 [salt.state       :1813][INFO    ][13586] Executing state service.running for [netfilter-persistent]
2019-05-04 21:30:02,651 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:02,671 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-04 21:30:02,688 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-04 21:30:02,705 [salt.state       :300 ][INFO    ][13586] The service netfilter-persistent is already running
2019-05-04 21:30:02,706 [salt.state       :1951][INFO    ][13586] Completed state [netfilter-persistent] at time 21:30:02.706110 duration_in_ms=55.035
2019-05-04 21:30:02,706 [salt.state       :1780][INFO    ][13586] Running state [iptables_extra.remove_stale_tables] at time 21:30:02.706631
2019-05-04 21:30:02,706 [salt.state       :1813][INFO    ][13586] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-04 21:30:02,707 [salt.state       :300 ][INFO    ][13586] No changes made for iptables_extra.remove_stale_tables
2019-05-04 21:30:02,707 [salt.state       :1951][INFO    ][13586] Completed state [iptables_extra.remove_stale_tables] at time 21:30:02.707172 duration_in_ms=0.541
2019-05-04 21:30:02,707 [salt.state       :1780][INFO    ][13586] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:30:02.707319
2019-05-04 21:30:02,707 [salt.state       :1813][INFO    ][13586] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-04 21:30:02,707 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13586] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-04 21:30:02,723 [salt.state       :300 ][INFO    ][13586] onlyif execution failed
2019-05-04 21:30:02,723 [salt.state       :1951][INFO    ][13586] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:30:02.723635 duration_in_ms=16.314
2019-05-04 21:30:02,725 [salt.state       :1780][INFO    ][13586] Running state [/etc/iptables/rules.v6] at time 21:30:02.725268
2019-05-04 21:30:02,725 [salt.state       :1813][INFO    ][13586] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-04 21:30:02,726 [salt.state       :300 ][INFO    ][13586] File /etc/iptables/rules.v6 is not present
2019-05-04 21:30:02,727 [salt.state       :1951][INFO    ][13586] Completed state [/etc/iptables/rules.v6] at time 21:30:02.726970 duration_in_ms=1.701
2019-05-04 21:30:02,728 [salt.state       :1780][INFO    ][13586] Running state [iptables_extra.flush_all] at time 21:30:02.728137
2019-05-04 21:30:02,728 [salt.state       :1813][INFO    ][13586] Executing state module.wait for [iptables_extra.flush_all]
2019-05-04 21:30:02,729 [salt.state       :300 ][INFO    ][13586] No changes made for iptables_extra.flush_all
2019-05-04 21:30:02,729 [salt.state       :1951][INFO    ][13586] Completed state [iptables_extra.flush_all] at time 21:30:02.729470 duration_in_ms=1.332
2019-05-04 21:30:02,734 [salt.minion      :1711][INFO    ][13586] Returning information for job: 20190504212955315188
2019-05-04 21:30:03,175 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213003163678
2019-05-04 21:30:03,193 [salt.minion      :1432][INFO    ][13662] Starting a new job with PID 13662
2019-05-04 21:30:03,861 [salt.state       :915 ][INFO    ][13662] Loading fresh modules for state activity
2019-05-04 21:30:04,437 [salt.state       :1780][INFO    ][13662] Running state [maas-rack-controller] at time 21:30:04.437903
2019-05-04 21:30:04,438 [salt.state       :1813][INFO    ][13662] Executing state pkg.installed for [maas-rack-controller]
2019-05-04 21:30:04,438 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13662] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:30:04,515 [salt.state       :300 ][INFO    ][13662] All specified packages are already installed
2019-05-04 21:30:04,515 [salt.state       :1951][INFO    ][13662] Completed state [maas-rack-controller] at time 21:30:04.515578 duration_in_ms=77.675
2019-05-04 21:30:04,515 [salt.state       :1780][INFO    ][13662] Running state [ipmitool] at time 21:30:04.515931
2019-05-04 21:30:04,516 [salt.state       :1813][INFO    ][13662] Executing state pkg.installed for [ipmitool]
2019-05-04 21:30:04,520 [salt.state       :300 ][INFO    ][13662] All specified packages are already installed
2019-05-04 21:30:04,521 [salt.state       :1951][INFO    ][13662] Completed state [ipmitool] at time 21:30:04.521100 duration_in_ms=5.168
2019-05-04 21:30:04,523 [salt.state       :1780][INFO    ][13662] Running state [/etc/maas/rackd.conf] at time 21:30:04.523397
2019-05-04 21:30:04,523 [salt.state       :1813][INFO    ][13662] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-04 21:30:04,524 [salt.state       :300 ][INFO    ][13662] No changes needed to be made
2019-05-04 21:30:04,524 [salt.state       :1951][INFO    ][13662] Completed state [/etc/maas/rackd.conf] at time 21:30:04.524714 duration_in_ms=1.316
2019-05-04 21:30:04,525 [salt.state       :1780][INFO    ][13662] Running state [/etc/maas/rackd.conf] at time 21:30:04.524964
2019-05-04 21:30:04,525 [salt.state       :1813][INFO    ][13662] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-04 21:30:04,525 [salt.loaded.int.states.file:2298][WARNING ][13662] 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-05-04 21:30:04,526 [salt.state       :300 ][INFO    ][13662] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-04 21:30:04,526 [salt.state       :1951][INFO    ][13662] Completed state [/etc/maas/rackd.conf] at time 21:30:04.526172 duration_in_ms=1.208
2019-05-04 21:30:04,527 [salt.state       :1780][INFO    ][13662] Running state [maas-rackd] at time 21:30:04.526968
2019-05-04 21:30:04,527 [salt.state       :1813][INFO    ][13662] Executing state service.running for [maas-rackd]
2019-05-04 21:30:04,527 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13662] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:04,556 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13662] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-04 21:30:04,569 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13662] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-04 21:30:04,582 [salt.state       :300 ][INFO    ][13662] The service maas-rackd is already running
2019-05-04 21:30:04,583 [salt.state       :1951][INFO    ][13662] Completed state [maas-rackd] at time 21:30:04.583227 duration_in_ms=56.259
2019-05-04 21:30:04,584 [salt.minion      :1711][INFO    ][13662] Returning information for job: 20190504213003163678
2019-05-04 21:30:05,049 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213005039117
2019-05-04 21:30:05,063 [salt.minion      :1432][INFO    ][13686] Starting a new job with PID 13686
2019-05-04 21:30:05,777 [salt.state       :915 ][INFO    ][13686] Loading fresh modules for state activity
2019-05-04 21:30:06,542 [salt.state       :1780][INFO    ][13686] Running state [maas-region-controller] at time 21:30:06.542630
2019-05-04 21:30:06,542 [salt.state       :1813][INFO    ][13686] Executing state pkg.installed for [maas-region-controller]
2019-05-04 21:30:06,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-04 21:30:06,626 [salt.state       :300 ][INFO    ][13686] All specified packages are already installed
2019-05-04 21:30:06,627 [salt.state       :1951][INFO    ][13686] Completed state [maas-region-controller] at time 21:30:06.627188 duration_in_ms=84.559
2019-05-04 21:30:06,627 [salt.state       :1780][INFO    ][13686] Running state [python-oauth] at time 21:30:06.627510
2019-05-04 21:30:06,627 [salt.state       :1813][INFO    ][13686] Executing state pkg.installed for [python-oauth]
2019-05-04 21:30:06,634 [salt.state       :300 ][INFO    ][13686] All specified packages are already installed
2019-05-04 21:30:06,634 [salt.state       :1951][INFO    ][13686] Completed state [python-oauth] at time 21:30:06.634185 duration_in_ms=6.675
2019-05-04 21:30:06,637 [salt.state       :1780][INFO    ][13686] Running state [/etc/maas/regiond.conf] at time 21:30:06.637219
2019-05-04 21:30:06,637 [salt.state       :1813][INFO    ][13686] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-04 21:30:06,680 [salt.state       :300 ][INFO    ][13686] No changes needed to be made
2019-05-04 21:30:06,681 [salt.state       :1951][INFO    ][13686] Completed state [/etc/maas/regiond.conf] at time 21:30:06.680916 duration_in_ms=43.696
2019-05-04 21:30:06,681 [salt.state       :1780][INFO    ][13686] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:30:06.681711
2019-05-04 21:30:06,682 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-04 21:30:06,757 [salt.state       :300 ][INFO    ][13686] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-04 21:30:06,757 [salt.state       :1951][INFO    ][13686] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:30:06.757521 duration_in_ms=75.81
2019-05-04 21:30:06,758 [salt.state       :1780][INFO    ][13686] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:30:06.758128
2019-05-04 21:30:06,758 [salt.state       :1813][INFO    ][13686] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-04 21:30:06,771 [salt.state       :300 ][INFO    ][13686] No changes needed to be made
2019-05-04 21:30:06,771 [salt.state       :1951][INFO    ][13686] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:30:06.771886 duration_in_ms=13.758
2019-05-04 21:30:06,772 [salt.state       :1780][INFO    ][13686] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:30:06.772587
2019-05-04 21:30:06,773 [salt.state       :1813][INFO    ][13686] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-04 21:30:06,801 [salt.state       :300 ][INFO    ][13686] No changes needed to be made
2019-05-04 21:30:06,802 [salt.state       :1951][INFO    ][13686] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:30:06.802051 duration_in_ms=29.463
2019-05-04 21:30:06,802 [salt.state       :1780][INFO    ][13686] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:30:06.802814
2019-05-04 21:30:06,803 [salt.state       :1813][INFO    ][13686] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-04 21:30:06,841 [salt.state       :300 ][INFO    ][13686] No changes needed to be made
2019-05-04 21:30:06,843 [salt.state       :1951][INFO    ][13686] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:30:06.843035 duration_in_ms=40.214
2019-05-04 21:30:06,844 [salt.state       :1780][INFO    ][13686] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:30:06.844079
2019-05-04 21:30:06,844 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-04 21:30:06,861 [salt.state       :300 ][INFO    ][13686] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-04 21:30:06,862 [salt.state       :1951][INFO    ][13686] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:30:06.861952 duration_in_ms=17.874
2019-05-04 21:30:06,864 [salt.state       :1780][INFO    ][13686] Running state [a2enmod headers] at time 21:30:06.864633
2019-05-04 21:30:06,865 [salt.state       :1813][INFO    ][13686] Executing state cmd.run for [a2enmod headers]
2019-05-04 21:30:06,865 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command 'a2enmod headers' in directory '/root'
2019-05-04 21:30:06,938 [salt.state       :300 ][INFO    ][13686] {'pid': 13705, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-04 21:30:06,939 [salt.state       :1951][INFO    ][13686] Completed state [a2enmod headers] at time 21:30:06.939051 duration_in_ms=74.417
2019-05-04 21:30:06,939 [salt.state       :1780][INFO    ][13686] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:30:06.939664
2019-05-04 21:30:06,940 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-04 21:30:06,959 [salt.state       :300 ][INFO    ][13686] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-04 21:30:06,960 [salt.state       :1951][INFO    ][13686] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:30:06.959921 duration_in_ms=20.257
2019-05-04 21:30:06,960 [salt.state       :1780][INFO    ][13686] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:30:06.960762
2019-05-04 21:30:06,961 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-04 21:30:07,045 [salt.state       :300 ][INFO    ][13686] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-04 21:30:07,045 [salt.state       :1951][INFO    ][13686] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:30:07.045642 duration_in_ms=84.879
2019-05-04 21:30:07,046 [salt.state       :1780][INFO    ][13686] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:30:07.046365
2019-05-04 21:30:07,046 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-04 21:30:07,116 [salt.state       :300 ][INFO    ][13686] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-04 21:30:07,117 [salt.state       :1951][INFO    ][13686] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:30:07.117229 duration_in_ms=70.864
2019-05-04 21:30:07,117 [salt.state       :1780][INFO    ][13686] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:30:07.117850
2019-05-04 21:30:07,118 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-04 21:30:07,188 [salt.state       :300 ][INFO    ][13686] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-04 21:30:07,188 [salt.state       :1951][INFO    ][13686] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:30:07.188921 duration_in_ms=71.07
2019-05-04 21:30:07,189 [salt.state       :1780][INFO    ][13686] Running state [/root/.pgpass] at time 21:30:07.189232
2019-05-04 21:30:07,189 [salt.state       :1813][INFO    ][13686] Executing state file.managed for [/root/.pgpass]
2019-05-04 21:30:07,242 [salt.state       :300 ][INFO    ][13686] File /root/.pgpass is in the correct state
2019-05-04 21:30:07,242 [salt.state       :1951][INFO    ][13686] Completed state [/root/.pgpass] at time 21:30:07.242754 duration_in_ms=53.523
2019-05-04 21:30:07,248 [salt.state       :1780][INFO    ][13686] Running state [maas-region syncdb --noinput] at time 21:30:07.248000
2019-05-04 21:30:07,248 [salt.state       :1813][INFO    ][13686] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-04 21:30:07,249 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-04 21:30:09,292 [salt.state       :300 ][INFO    ][13686] {'pid': 13718, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sites, auth, maasserver, metadataserver, sessions, contenttypes, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-04 21:30:09,292 [salt.state       :1951][INFO    ][13686] Completed state [maas-region syncdb --noinput] at time 21:30:09.292833 duration_in_ms=2044.831
2019-05-04 21:30:09,293 [salt.state       :2022][WARNING ][13686] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-04 21:30:09,296 [salt.state       :1780][INFO    ][13686] Running state [maas-regiond] at time 21:30:09.296412
2019-05-04 21:30:09,297 [salt.state       :1813][INFO    ][13686] Executing state service.running for [maas-regiond]
2019-05-04 21:30:09,298 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:09,335 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-04 21:30:09,354 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-04 21:30:09,371 [salt.state       :300 ][INFO    ][13686] The service maas-regiond is already running
2019-05-04 21:30:09,372 [salt.state       :1951][INFO    ][13686] Completed state [maas-regiond] at time 21:30:09.372180 duration_in_ms=75.769
2019-05-04 21:30:09,374 [salt.state       :1780][INFO    ][13686] Running state [bind9] at time 21:30:09.374676
2019-05-04 21:30:09,375 [salt.state       :1813][INFO    ][13686] Executing state service.running for [bind9]
2019-05-04 21:30:09,376 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:09,395 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-04 21:30:09,413 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-04 21:30:09,430 [salt.state       :300 ][INFO    ][13686] The service bind9 is already running
2019-05-04 21:30:09,431 [salt.state       :1951][INFO    ][13686] Completed state [bind9] at time 21:30:09.431210 duration_in_ms=56.534
2019-05-04 21:30:09,433 [salt.state       :1780][INFO    ][13686] Running state [apache2] at time 21:30:09.433550
2019-05-04 21:30:09,434 [salt.state       :1813][INFO    ][13686] Executing state service.running for [apache2]
2019-05-04 21:30:09,435 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-04 21:30:09,453 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-04 21:30:09,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-04 21:30:09,490 [salt.state       :300 ][INFO    ][13686] The service apache2 is already running
2019-05-04 21:30:09,491 [salt.state       :1951][INFO    ][13686] Completed state [apache2] at time 21:30:09.491100 duration_in_ms=57.549
2019-05-04 21:30:09,493 [salt.state       :1780][INFO    ][13686] Running state [maasng.wait_for_http_code] at time 21:30:09.493433
2019-05-04 21:30:09,493 [salt.state       :1813][INFO    ][13686] Executing state module.run for [maasng.wait_for_http_code]
2019-05-04 21:30:09,494 [salt.utils.decorators:613 ][WARNING ][13686] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:30:09,505 [salt.state       :300 ][INFO    ][13686] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-04 21:30:09,506 [salt.state       :1951][INFO    ][13686] Completed state [maasng.wait_for_http_code] at time 21:30:09.506194 duration_in_ms=12.761
2019-05-04 21:30:09,507 [salt.state       :1780][INFO    ][13686] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:30:09.507604
2019-05-04 21:30:09,508 [salt.state       :1813][INFO    ][13686] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-04 21:30:09,508 [salt.state       :300 ][INFO    ][13686] /var/lib/maas/.setup_admin exists
2019-05-04 21:30:09,509 [salt.state       :1951][INFO    ][13686] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:30:09.509248 duration_in_ms=1.644
2019-05-04 21:30:09,510 [salt.state       :1780][INFO    ][13686] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:09.510364
2019-05-04 21:30:09,510 [salt.state       :1813][INFO    ][13686] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:30:09,511 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13686] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:30:10,938 [salt.state       :300 ][INFO    ][13686] {'pid': 13737, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:30:10,939 [salt.state       :1951][INFO    ][13686] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:10.939552 duration_in_ms=1429.187
2019-05-04 21:30:10,948 [salt.state       :1780][INFO    ][13686] Running state [maas_region_boot_source_resources_mirror] at time 21:30:10.948213
2019-05-04 21:30:10,948 [salt.state       :1813][INFO    ][13686] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-04 21:30:11,056 [salt.state       :300 ][INFO    ][13686] {'changes': {}}
2019-05-04 21:30:11,056 [salt.state       :1951][INFO    ][13686] Completed state [maas_region_boot_source_resources_mirror] at time 21:30:11.056769 duration_in_ms=108.557
2019-05-04 21:30:11,057 [salt.state       :1780][INFO    ][13686] Running state [maasng.boot_resources_import] at time 21:30:11.057845
2019-05-04 21:30:11,058 [salt.state       :1813][INFO    ][13686] Executing state module.run for [maasng.boot_resources_import]
2019-05-04 21:30:11,058 [salt.utils.decorators:613 ][WARNING ][13686] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:30:11,191 [salt.loaded.ext.module.maasng:1600][INFO    ][13686] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-04 21:30:16,250 [salt.loaded.ext.module.maasng:1600][INFO    ][13686] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-04 21:30:20,160 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213020148043
2019-05-04 21:30:20,183 [salt.minion      :1432][INFO    ][13787] Starting a new job with PID 13787
2019-05-04 21:30:20,205 [salt.minion      :1711][INFO    ][13787] Returning information for job: 20190504213020148043
2019-05-04 21:30:21,389 [salt.loaded.ext.module.maasng:1600][INFO    ][13686] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-04 21:30:26,511 [salt.state       :300 ][INFO    ][13686] {'ret': True}
2019-05-04 21:30:26,512 [salt.state       :1951][INFO    ][13686] Completed state [maasng.boot_resources_import] at time 21:30:26.512046 duration_in_ms=15454.201
2019-05-04 21:30:26,513 [salt.state       :1780][INFO    ][13686] Running state [maas_region_boot_sources_selection_xenial] at time 21:30:26.513230
2019-05-04 21:30:26,513 [salt.state       :1813][INFO    ][13686] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-04 21:30:26,739 [salt.state       :300 ][INFO    ][13686] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-04 21:30:26,739 [salt.state       :1951][INFO    ][13686] Completed state [maas_region_boot_sources_selection_xenial] at time 21:30:26.739821 duration_in_ms=226.59
2019-05-04 21:30:26,741 [salt.state       :1780][INFO    ][13686] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:30:26.741205
2019-05-04 21:30:26,741 [salt.state       :1813][INFO    ][13686] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-04 21:30:26,742 [salt.utils.decorators:613 ][WARNING ][13686] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:30:26,742 [salt.loaded.ext.module.maasng:1771][INFO    ][13686] boot-sources sync initiated for ALL Rack's
2019-05-04 21:30:27,810 [salt.state       :300 ][INFO    ][13686] {'ret': True}
2019-05-04 21:30:27,811 [salt.state       :1951][INFO    ][13686] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:30:27.811337 duration_in_ms=1070.132
2019-05-04 21:30:27,813 [salt.state       :1780][INFO    ][13686] Running state [maas.process_maas_config] at time 21:30:27.813325
2019-05-04 21:30:27,813 [salt.state       :1813][INFO    ][13686] Executing state module.run for [maas.process_maas_config]
2019-05-04 21:30:27,814 [salt.utils.decorators:613 ][WARNING ][13686] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:30:27,815 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=enable_http_proxy value=True
2019-05-04 21:30:27,878 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=upstream_dns value=8.8.8.8
2019-05-04 21:30:27,942 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=commissioning_distro_series value=xenial
2019-05-04 21:30:28,008 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=default_osystem value=ubuntu
2019-05-04 21:30:28,074 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=active_discovery_interval value=600
2019-05-04 21:30:28,134 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=dnssec_validation value=no
2019-05-04 21:30:28,194 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=maas_name value=mas01
2019-05-04 21:30:28,254 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=network_discovery value=enabled
2019-05-04 21:30:28,373 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=enable_third_party_drivers value=True
2019-05-04 21:30:28,421 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=default_storage_layout value=lvm
2019-05-04 21:30:28,481 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=ntp_external_only value=True
2019-05-04 21:30:28,541 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-04 21:30:28,601 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=default_distro_series value=xenial
2019-05-04 21:30:28,673 [salt.loaded.ext.module.maas:92  ][INFO    ][13686] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-04 21:30:28,804 [salt.state       :300 ][INFO    ][13686] {'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-05-04 21:30:28,805 [salt.state       :1951][INFO    ][13686] Completed state [maas.process_maas_config] at time 21:30:28.805202 duration_in_ms=991.876
2019-05-04 21:30:28,806 [salt.state       :1780][INFO    ][13686] Running state [pxe_admin] at time 21:30:28.806275
2019-05-04 21:30:28,806 [salt.state       :1813][INFO    ][13686] Executing state maasng.fabric_present for [pxe_admin]
2019-05-04 21:30:28,876 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:30:28,947 [salt.loaded.ext.module.maasng:1008][WARNING ][13686] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-04 21:30:28,948 [salt.loaded.ext.module.maasng:1011][WARNING ][13686] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-04 21:30:29,020 [salt.state       :300 ][INFO    ][13686] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-04 21:30:29,021 [salt.state       :1951][INFO    ][13686] Completed state [pxe_admin] at time 21:30:29.021037 duration_in_ms=214.761
2019-05-04 21:30:29,021 [salt.state       :1780][INFO    ][13686] Running state [vlan 0] at time 21:30:29.021561
2019-05-04 21:30:29,022 [salt.state       :1813][INFO    ][13686] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-04 21:30:30,797 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{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'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-04 21:30:30,921 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:30:31,187 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-04 21:30:31,271 [salt.state       :300 ][INFO    ][13686] {'new': 'Vlan untagged was updated'}
2019-05-04 21:30:31,272 [salt.state       :1951][INFO    ][13686] Completed state [vlan 0] at time 21:30:31.272003 duration_in_ms=2250.442
2019-05-04 21:30:31,272 [salt.state       :1780][INFO    ][13686] Running state [192.168.11.0/24] at time 21:30:31.272754
2019-05-04 21:30:31,273 [salt.state       :1813][INFO    ][13686] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-04 21:30:31,472 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-04 21:30:31,473 [salt.loaded.ext.module.maasng:1235][WARNING ][13686] Ignoring parameter vlan:0
2019-05-04 21:30:31,570 [salt.state       :300 ][INFO    ][13686] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-04 21:30:31,571 [salt.state       :1951][INFO    ][13686] Completed state [192.168.11.0/24] at time 21:30:31.571142 duration_in_ms=298.385
2019-05-04 21:30:31,573 [salt.state       :1780][INFO    ][13686] Running state [maas_create_iprange_1] at time 21:30:31.573118
2019-05-04 21:30:31,573 [salt.state       :1813][INFO    ][13686] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-04 21:30:31,640 [salt.state       :300 ][INFO    ][13686] Iprange maas_create_iprange_1 already exist.
2019-05-04 21:30:31,641 [salt.state       :1951][INFO    ][13686] Completed state [maas_create_iprange_1] at time 21:30:31.641237 duration_in_ms=68.118
2019-05-04 21:30:31,641 [salt.state       :1780][INFO    ][13686] Running state [vlan 0] at time 21:30:31.641880
2019-05-04 21:30:31,642 [salt.state       :1813][INFO    ][13686] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-04 21:30:31,700 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:30:31,801 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wrwawt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-04 21:30:32,037 [salt.loaded.ext.module.maasng:945 ][INFO    ][13686] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, 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'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, 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'wrwawt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-04 21:30:32,122 [salt.state       :300 ][INFO    ][13686] {'new': 'Vlan untagged was updated'}
2019-05-04 21:30:32,122 [salt.state       :1951][INFO    ][13686] Completed state [vlan 0] at time 21:30:32.122769 duration_in_ms=480.889
2019-05-04 21:30:32,123 [salt.state       :1780][INFO    ][13686] Running state [opnfv] at time 21:30:32.123641
2019-05-04 21:30:32,124 [salt.state       :1813][INFO    ][13686] Executing state maasng.sshkey_present for [opnfv]
2019-05-04 21:30:32,179 [salt.loaded.ext.module.maasng:1903][INFO    ][13686] [{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-05-04 21:30:32,179 [salt.state       :300 ][INFO    ][13686] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-04 21:30:32,179 [salt.state       :1951][INFO    ][13686] Completed state [opnfv] at time 21:30:32.179812 duration_in_ms=56.17
2019-05-04 21:30:32,183 [salt.minion      :1711][INFO    ][13686] Returning information for job: 20190504213005039117
2019-05-04 21:30:32,750 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213032738219
2019-05-04 21:30:32,768 [salt.minion      :1432][INFO    ][14159] Starting a new job with PID 14159
2019-05-04 21:30:36,432 [salt.state       :915 ][INFO    ][14159] Loading fresh modules for state activity
2019-05-04 21:30:36,528 [salt.state       :1780][INFO    ][14159] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:36.528655
2019-05-04 21:30:36,529 [salt.state       :1813][INFO    ][14159] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:30:36,531 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14159] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:30:37,955 [salt.state       :300 ][INFO    ][14159] {'pid': 14185, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:30:37,956 [salt.state       :1951][INFO    ][14159] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:37.956069 duration_in_ms=1427.415
2019-05-04 21:30:37,958 [salt.state       :1780][INFO    ][14159] Running state [maas.process_machines] at time 21:30:37.958531
2019-05-04 21:30:37,959 [salt.state       :1813][INFO    ][14159] Executing state module.run for [maas.process_machines]
2019-05-04 21:30:37,959 [salt.utils.decorators:613 ][WARNING ][14159] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:30:38,702 [salt.loaded.ext.module.maas:412 ][WARNING ][14159] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:30:38,703 [salt.loaded.ext.module.maas:92  ][INFO    ][14159] 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=rh47hp architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:30:39,714 [salt.loaded.ext.module.maas:412 ][WARNING ][14159] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:30:39,715 [salt.loaded.ext.module.maas:92  ][INFO    ][14159] 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=h8xrr4 architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:30:40,708 [salt.loaded.ext.module.maas:412 ][WARNING ][14159] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:30:40,709 [salt.loaded.ext.module.maas:92  ][INFO    ][14159] 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=t3hn3y architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:30:41,996 [salt.loaded.ext.module.maas:412 ][WARNING ][14159] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:30:41,997 [salt.loaded.ext.module.maas:92  ][INFO    ][14159] 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=hyxybc architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:30:43,111 [salt.loaded.ext.module.maas:412 ][WARNING ][14159] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-04 21:30:43,112 [salt.loaded.ext.module.maas:92  ][INFO    ][14159] 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=agxeet architecture=amd64/generic power_parameters_power_user=admin
2019-05-04 21:30:44,335 [salt.state       :300 ][INFO    ][14159] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-04 21:30:44,335 [salt.state       :1951][INFO    ][14159] Completed state [maas.process_machines] at time 21:30:44.335536 duration_in_ms=6377.004
2019-05-04 21:30:44,339 [salt.minion      :1711][INFO    ][14159] Returning information for job: 20190504213032738219
2019-05-04 21:31:17,634 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213117620695
2019-05-04 21:31:17,656 [salt.minion      :1432][INFO    ][14433] Starting a new job with PID 14433
2019-05-04 21:31:21,286 [salt.state       :915 ][INFO    ][14433] Loading fresh modules for state activity
2019-05-04 21:31:21,384 [salt.state       :1780][INFO    ][14433] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:21.384068
2019-05-04 21:31:21,384 [salt.state       :1813][INFO    ][14433] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:31:21,386 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14433] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:31:22,804 [salt.state       :300 ][INFO    ][14433] {'pid': 14467, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:31:22,804 [salt.state       :1951][INFO    ][14433] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:22.804851 duration_in_ms=1420.784
2019-05-04 21:31:22,805 [salt.state       :1780][INFO    ][14433] Running state [maas.wait_for_machine_status] at time 21:31:22.805954
2019-05-04 21:31:22,806 [salt.state       :1813][INFO    ][14433] Executing state module.run for [maas.wait_for_machine_status]
2019-05-04 21:31:22,806 [salt.utils.decorators:613 ][WARNING ][14433] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:31:26,458 [salt.loaded.ext.module.maas:993 ][INFO    ][14433] Machine agxeet mark broken
2019-05-04 21:31:27,112 [salt.loaded.ext.module.maas:996 ][INFO    ][14433] Machine agxeet mark fixed
2019-05-04 21:31:28,411 [salt.loaded.ext.module.maas:684 ][INFO    ][14433] deploymachines hwe_kernel=hwe-16.04 system_id=agxeet distro_series=xenial
2019-05-04 21:31:31,160 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1491.65038109s left)
2019-05-04 21:31:32,686 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213132673694
2019-05-04 21:31:32,708 [salt.minion      :1432][INFO    ][14535] Starting a new job with PID 14535
2019-05-04 21:31:32,734 [salt.minion      :1711][INFO    ][14535] Returning information for job: 20190504213132673694
2019-05-04 21:32:02,743 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213202728667
2019-05-04 21:32:02,764 [salt.minion      :1432][INFO    ][14557] Starting a new job with PID 14557
2019-05-04 21:32:02,790 [salt.minion      :1711][INFO    ][14557] Returning information for job: 20190504213202728667
2019-05-04 21:32:04,912 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1457.89849019s left)
2019-05-04 21:32:32,996 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213232939954
2019-05-04 21:32:33,017 [salt.minion      :1432][INFO    ][14615] Starting a new job with PID 14615
2019-05-04 21:32:33,041 [salt.minion      :1711][INFO    ][14615] Returning information for job: 20190504213232939954
2019-05-04 21:32:38,495 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1424.3150661s left)
2019-05-04 21:33:03,041 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213303028384
2019-05-04 21:33:03,064 [salt.minion      :1432][INFO    ][14635] Starting a new job with PID 14635
2019-05-04 21:33:03,089 [salt.minion      :1711][INFO    ][14635] Returning information for job: 20190504213303028384
2019-05-04 21:33:11,837 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1390.97350502s left)
2019-05-04 21:33:33,094 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213333080805
2019-05-04 21:33:33,114 [salt.minion      :1432][INFO    ][14752] Starting a new job with PID 14752
2019-05-04 21:33:33,140 [salt.minion      :1711][INFO    ][14752] Returning information for job: 20190504213333080805
2019-05-04 21:33:45,418 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1357.39293098s left)
2019-05-04 21:34:03,148 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213403134866
2019-05-04 21:34:03,170 [salt.minion      :1432][INFO    ][14785] Starting a new job with PID 14785
2019-05-04 21:34:03,196 [salt.minion      :1711][INFO    ][14785] Returning information for job: 20190504213403134866
2019-05-04 21:34:18,625 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1324.18534112s left)
2019-05-04 21:34:33,208 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213433194876
2019-05-04 21:34:33,231 [salt.minion      :1432][INFO    ][15002] Starting a new job with PID 15002
2019-05-04 21:34:33,257 [salt.minion      :1711][INFO    ][15002] Returning information for job: 20190504213433194876
2019-05-04 21:34:52,244 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1290.56660199s left)
2019-05-04 21:35:03,280 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213503265958
2019-05-04 21:35:03,302 [salt.minion      :1432][INFO    ][15023] Starting a new job with PID 15023
2019-05-04 21:35:03,328 [salt.minion      :1711][INFO    ][15023] Returning information for job: 20190504213503265958
2019-05-04 21:35:24,804 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1258.00606418s left)
2019-05-04 21:35:33,351 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213533334340
2019-05-04 21:35:33,377 [salt.minion      :1432][INFO    ][15124] Starting a new job with PID 15124
2019-05-04 21:35:33,413 [salt.minion      :1711][INFO    ][15124] Returning information for job: 20190504213533334340
2019-05-04 21:35:58,245 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1224.56510901s left)
2019-05-04 21:36:03,435 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213603422023
2019-05-04 21:36:03,456 [salt.minion      :1432][INFO    ][15146] Starting a new job with PID 15146
2019-05-04 21:36:03,488 [salt.minion      :1711][INFO    ][15146] Returning information for job: 20190504213603422023
2019-05-04 21:36:31,553 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.25793409s left)
2019-05-04 21:36:33,522 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213633509077
2019-05-04 21:36:33,543 [salt.minion      :1432][INFO    ][15298] Starting a new job with PID 15298
2019-05-04 21:36:33,569 [salt.minion      :1711][INFO    ][15298] Returning information for job: 20190504213633509077
2019-05-04 21:37:03,599 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213703586174
2019-05-04 21:37:03,620 [salt.minion      :1432][INFO    ][15317] Starting a new job with PID 15317
2019-05-04 21:37:03,646 [salt.minion      :1711][INFO    ][15317] Returning information for job: 20190504213703586174
2019-05-04 21:37:05,095 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1157.71546412s left)
2019-05-04 21:37:33,682 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213733670201
2019-05-04 21:37:33,702 [salt.minion      :1432][INFO    ][15435] Starting a new job with PID 15435
2019-05-04 21:37:33,727 [salt.minion      :1711][INFO    ][15435] Returning information for job: 20190504213733670201
2019-05-04 21:37:38,763 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.0470922s left)
2019-05-04 21:38:03,767 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213803754767
2019-05-04 21:38:03,789 [salt.minion      :1432][INFO    ][15461] Starting a new job with PID 15461
2019-05-04 21:38:03,816 [salt.minion      :1711][INFO    ][15461] Returning information for job: 20190504213803754767
2019-05-04 21:38:12,436 [salt.loaded.ext.module.maas:1023][INFO    ][14433] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1090.37460804s left)
2019-05-04 21:38:33,862 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command saltutil.find_job with jid 20190504213833849601
2019-05-04 21:38:33,885 [salt.minion      :1432][INFO    ][15543] Starting a new job with PID 15543
2019-05-04 21:38:33,911 [salt.minion      :1711][INFO    ][15543] Returning information for job: 20190504213833849601
2019-05-04 21:38:45,866 [salt.state       :300 ][INFO    ][14433] {'ret': True}
2019-05-04 21:38:45,867 [salt.state       :1951][INFO    ][14433] Completed state [maas.wait_for_machine_status] at time 21:38:45.867193 duration_in_ms=443061.235
2019-05-04 21:38:45,870 [salt.minion      :1711][INFO    ][14433] Returning information for job: 20190504213117620695
2019-05-04 21:38:46,520 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213846507449
2019-05-04 21:38:46,543 [salt.minion      :1432][INFO    ][15569] Starting a new job with PID 15569
2019-05-04 21:38:50,252 [salt.state       :915 ][INFO    ][15569] Loading fresh modules for state activity
2019-05-04 21:38:50,393 [salt.state       :1780][INFO    ][15569] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:50.392930
2019-05-04 21:38:50,393 [salt.state       :1813][INFO    ][15569] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:38:50,395 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15569] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:38:51,837 [salt.state       :300 ][INFO    ][15569] {'pid': 15584, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:38:51,838 [salt.state       :1951][INFO    ][15569] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:51.838241 duration_in_ms=1445.312
2019-05-04 21:38:51,839 [salt.state       :1780][INFO    ][15569] Running state [maas_machines_storage_cmp002_lvm] at time 21:38:51.839710
2019-05-04 21:38:51,839 [salt.state       :1813][INFO    ][15569] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-04 21:38:52,518 [salt.state       :300 ][INFO    ][15569] Machine cmp002 is not in Ready state.
2019-05-04 21:38:52,518 [salt.state       :1951][INFO    ][15569] Completed state [maas_machines_storage_cmp002_lvm] at time 21:38:52.518801 duration_in_ms=679.087
2019-05-04 21:38:52,519 [salt.state       :1780][INFO    ][15569] Running state [maas_machines_storage_cmp001_lvm] at time 21:38:52.519680
2019-05-04 21:38:52,520 [salt.state       :1813][INFO    ][15569] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-04 21:38:53,273 [salt.state       :300 ][INFO    ][15569] Machine cmp001 is not in Ready state.
2019-05-04 21:38:53,274 [salt.state       :1951][INFO    ][15569] Completed state [maas_machines_storage_cmp001_lvm] at time 21:38:53.274329 duration_in_ms=754.648
2019-05-04 21:38:53,278 [salt.minion      :1711][INFO    ][15569] Returning information for job: 20190504213846507449
2019-05-04 21:38:53,911 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213853897737
2019-05-04 21:38:53,934 [salt.minion      :1432][INFO    ][15595] Starting a new job with PID 15595
2019-05-04 21:38:54,712 [salt.state       :915 ][INFO    ][15595] Loading fresh modules for state activity
2019-05-04 21:38:54,799 [salt.state       :1780][INFO    ][15595] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:54.799054
2019-05-04 21:38:54,799 [salt.state       :1813][INFO    ][15595] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:38:54,801 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15595] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:38:56,312 [salt.state       :300 ][INFO    ][15595] {'pid': 15602, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:38:56,313 [salt.state       :1951][INFO    ][15595] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:56.313650 duration_in_ms=1514.595
2019-05-04 21:38:56,316 [salt.state       :1780][INFO    ][15595] Running state [maas.deploy_machines] at time 21:38:56.316214
2019-05-04 21:38:56,316 [salt.state       :1813][INFO    ][15595] Executing state module.run for [maas.deploy_machines]
2019-05-04 21:38:56,318 [salt.utils.decorators:613 ][WARNING ][15595] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:38:57,024 [salt.state       :300 ][INFO    ][15595] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-04 21:38:57,024 [salt.state       :1951][INFO    ][15595] Completed state [maas.deploy_machines] at time 21:38:57.024438 duration_in_ms=708.223
2019-05-04 21:38:57,027 [salt.minion      :1711][INFO    ][15595] Returning information for job: 20190504213853897737
2019-05-04 21:38:57,661 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command state.apply with jid 20190504213857647356
2019-05-04 21:38:57,683 [salt.minion      :1432][INFO    ][15611] Starting a new job with PID 15611
2019-05-04 21:38:58,392 [salt.state       :915 ][INFO    ][15611] Loading fresh modules for state activity
2019-05-04 21:38:58,483 [salt.state       :1780][INFO    ][15611] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:58.482991
2019-05-04 21:38:58,483 [salt.state       :1813][INFO    ][15611] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-04 21:38:58,485 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15611] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-04 21:38:59,915 [salt.state       :300 ][INFO    ][15611] {'pid': 15619, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-04 21:38:59,915 [salt.state       :1951][INFO    ][15611] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:59.915580 duration_in_ms=1432.589
2019-05-04 21:38:59,917 [salt.state       :1780][INFO    ][15611] Running state [maas.wait_for_machine_status] at time 21:38:59.917089
2019-05-04 21:38:59,917 [salt.state       :1813][INFO    ][15611] Executing state module.run for [maas.wait_for_machine_status]
2019-05-04 21:38:59,917 [salt.utils.decorators:613 ][WARNING ][15611] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-04 21:39:03,160 [salt.state       :300 ][INFO    ][15611] {'ret': True}
2019-05-04 21:39:03,161 [salt.state       :1951][INFO    ][15611] Completed state [maas.wait_for_machine_status] at time 21:39:03.161177 duration_in_ms=3244.084
2019-05-04 21:39:03,164 [salt.minion      :1711][INFO    ][15611] Returning information for job: 20190504213857647356
2019-05-04 22:09:13,893 [salt.utils.schedule:1377][INFO    ][6626] Running scheduled job: __mine_interval
2019-05-04 23:01:18,839 [salt.minion      :1308][INFO    ][6626] User sudo_ubuntu Executing command cp.push_dir with jid 20190504230118821544
2019-05-04 23:01:18,861 [salt.minion      :1432][INFO    ][21371] Starting a new job with PID 21371
