2019-12-16 20:03:53,108 [salt.utils.decorators:613 ][WARNING ][2113] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:03:53,671 [salt.utils.decorators:613 ][WARNING ][2113] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:03:55,785 [salt.loaded.int.states.file:2298][WARNING ][2322] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-12-16 20:04:21,416 [salt.state       :2022][WARNING ][2928] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-16 20:04:23,963 [salt.utils.decorators:613 ][WARNING ][2928] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:04:51,604 [salt.utils.decorators:613 ][WARNING ][2928] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:05:59,752 [salt.utils.decorators:613 ][WARNING ][2928] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:06:00,586 [salt.utils.decorators:613 ][WARNING ][2928] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:06:05,900 [salt.loaded.ext.module.maasng:1008][WARNING ][2928] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-12-16 20:06:05,901 [salt.loaded.ext.module.maasng:1011][WARNING ][2928] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-12-16 20:06:06,610 [salt.loaded.ext.module.maasng:1235][WARNING ][2928] Ignoring parameter vlan:0
2019-12-16 20:06:09,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6994] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-16 20:06:09,407 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6994] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-12-16 20:06:09,433 [salt.utils.parsers:1051][WARNING ][317] Minion received a SIGTERM. Exiting.
2019-12-16 20:06:10,403 [salt.cli.daemons :293 ][INFO    ][7064] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-12-16 20:06:10,484 [salt.cli.daemons :82  ][INFO    ][7064] Starting up the Salt Minion
2019-12-16 20:06:10,484 [salt.utils.event :1017][INFO    ][7064] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-12-16 20:06:11,283 [salt.minion      :976 ][INFO    ][7064] Creating minion process manager
2019-12-16 20:06:12,714 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7064] Executing command ['date', '+%z'] in directory '/root'
2019-12-16 20:06:12,731 [salt.utils.schedule:568 ][INFO    ][7064] Updating job settings for scheduled job: __mine_interval
2019-12-16 20:06:12,777 [salt.minion      :1108][INFO    ][7064] Added mine.update to scheduler
2019-12-16 20:06:12,783 [salt.minion      :1975][INFO    ][7064] Minion is starting as user 'root'
2019-12-16 20:06:12,798 [salt.minion      :2336][INFO    ][7064] Minion is ready to receive requests!
2019-12-16 20:06:13,493 [salt.utils.decorators:613 ][WARNING ][7002] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:06:13,568 [salt.loaded.ext.module.maas:412 ][WARNING ][7002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:06:15,044 [salt.loaded.ext.module.maas:412 ][WARNING ][7002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:06:16,467 [salt.loaded.ext.module.maas:412 ][WARNING ][7002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:06:17,869 [salt.loaded.ext.module.maas:412 ][WARNING ][7002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:06:19,173 [salt.loaded.ext.module.maas:412 ][WARNING ][7002] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:06:51,667 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216200651654882
2019-12-16 20:06:51,689 [salt.minion      :1432][INFO    ][7465] Starting a new job with PID 7465
2019-12-16 20:06:55,536 [salt.state       :915 ][INFO    ][7465] Loading fresh modules for state activity
2019-12-16 20:06:55,590 [salt.fileclient  :1219][INFO    ][7465] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-12-16 20:06:55,635 [salt.state       :1780][INFO    ][7465] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:06:55.635361
2019-12-16 20:06:55,635 [salt.state       :1813][INFO    ][7465] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:06:55,637 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7465] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:06:57,090 [salt.state       :300 ][INFO    ][7465] {'pid': 7490, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:06:57,090 [salt.state       :1951][INFO    ][7465] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:06:57.090618 duration_in_ms=1455.258
2019-12-16 20:06:57,092 [salt.state       :1780][INFO    ][7465] Running state [maas.wait_for_machine_status] at time 20:06:57.092143
2019-12-16 20:06:57,092 [salt.state       :1813][INFO    ][7465] Executing state module.run for [maas.wait_for_machine_status]
2019-12-16 20:06:57,092 [salt.utils.decorators:613 ][WARNING ][7465] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:06:58,219 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.87834096s left)
2019-12-16 20:07:06,711 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200706695283
2019-12-16 20:07:06,734 [salt.minion      :1432][INFO    ][7502] Starting a new job with PID 7502
2019-12-16 20:07:06,758 [salt.minion      :1711][INFO    ][7502] Returning information for job: 20191216200706695283
2019-12-16 20:07:29,180 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1467.91653991s left)
2019-12-16 20:07:36,763 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200736748175
2019-12-16 20:07:36,785 [salt.minion      :1432][INFO    ][7540] Starting a new job with PID 7540
2019-12-16 20:07:36,808 [salt.minion      :1711][INFO    ][7540] Returning information for job: 20191216200736748175
2019-12-16 20:08:00,162 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.93467689s left)
2019-12-16 20:08:06,795 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200806788640
2019-12-16 20:08:06,810 [salt.minion      :1432][INFO    ][7682] Starting a new job with PID 7682
2019-12-16 20:08:06,820 [salt.minion      :1711][INFO    ][7682] Returning information for job: 20191216200806788640
2019-12-16 20:08:31,562 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.53467798s left)
2019-12-16 20:08:36,815 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200836802469
2019-12-16 20:08:36,834 [salt.minion      :1432][INFO    ][7872] Starting a new job with PID 7872
2019-12-16 20:08:36,857 [salt.minion      :1711][INFO    ][7872] Returning information for job: 20191216200836802469
2019-12-16 20:09:03,196 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.90059304s left)
2019-12-16 20:09:06,869 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200906861364
2019-12-16 20:09:06,888 [salt.minion      :1432][INFO    ][8168] Starting a new job with PID 8168
2019-12-16 20:09:06,905 [salt.minion      :1711][INFO    ][8168] Returning information for job: 20191216200906861364
2019-12-16 20:09:35,059 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.03764486s left)
2019-12-16 20:09:36,917 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216200936903824
2019-12-16 20:09:36,940 [salt.minion      :1432][INFO    ][8619] Starting a new job with PID 8619
2019-12-16 20:09:36,965 [salt.minion      :1711][INFO    ][8619] Returning information for job: 20191216200936903824
2019-12-16 20:10:06,986 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201006971993
2019-12-16 20:10:07,007 [salt.minion      :1432][INFO    ][8754] Starting a new job with PID 8754
2019-12-16 20:10:07,026 [salt.minion      :1711][INFO    ][8754] Returning information for job: 20191216201006971993
2019-12-16 20:10:07,831 [salt.loaded.ext.module.maas:1023][INFO    ][7465] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1309.26567888s left)
2019-12-16 20:10:37,040 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201037028022
2019-12-16 20:10:37,062 [salt.minion      :1432][INFO    ][8825] Starting a new job with PID 8825
2019-12-16 20:10:37,086 [salt.minion      :1711][INFO    ][8825] Returning information for job: 20191216201037028022
2019-12-16 20:10:41,215 [salt.state       :300 ][INFO    ][7465] {'ret': True}
2019-12-16 20:10:41,215 [salt.state       :1951][INFO    ][7465] Completed state [maas.wait_for_machine_status] at time 20:10:41.215685 duration_in_ms=224123.539
2019-12-16 20:10:41,252 [salt.minion      :1711][INFO    ][7465] Returning information for job: 20191216200651654882
2019-12-16 20:10:41,900 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216201041883376
2019-12-16 20:10:41,922 [salt.minion      :1432][INFO    ][8837] Starting a new job with PID 8837
2019-12-16 20:10:45,732 [salt.state       :915 ][INFO    ][8837] Loading fresh modules for state activity
2019-12-16 20:10:45,783 [salt.fileclient  :1219][INFO    ][8837] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-12-16 20:10:45,874 [salt.state       :1780][INFO    ][8837] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:10:45.874786
2019-12-16 20:10:45,875 [salt.state       :1813][INFO    ][8837] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:10:45,877 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8837] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:10:47,161 [salt.state       :300 ][INFO    ][8837] {'pid': 8848, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:10:47,162 [salt.state       :1951][INFO    ][8837] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:10:47.162314 duration_in_ms=1287.53
2019-12-16 20:10:47,163 [salt.state       :1780][INFO    ][8837] Running state [maas_machines_storage_cmp002_lvm] at time 20:10:47.163709
2019-12-16 20:10:47,163 [salt.state       :1813][INFO    ][8837] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-16 20:10:47,984 [salt.loaded.ext.module.maasng:610 ][INFO    ][8837] btkh6x
2019-12-16 20:10:47,984 [salt.loaded.ext.module.maasng:626 ][INFO    ][8837] sda
2019-12-16 20:10:48,604 [salt.loaded.ext.module.maasng:361 ][INFO    ][8837] btkh6x
2019-12-16 20:10:48,724 [salt.loaded.ext.module.maasng:367 ][INFO    ][8837] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'btkh6x', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 3, u'partitions': [{u'size': 2397992648704, u'uuid': u'2f1664b0-bfde-4ea9-ac24-a3b44d690000', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btkh6x', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'd8afcbdf-84d3-4583-9dd1-28c173996bb2', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/partition/3', u'type': u'partition', u'id': 3, u'device_id': 3}]}, {u'size': 2397988454400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/8/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'd3e7c596-a5b4-4713-98e0-e154fc61a0b4', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'a6f5ef57-d41a-4cfd-9282-ad25fc2eb953', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'btkh6x', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 8, u'partitions': []}]
2019-12-16 20:10:48,725 [salt.loaded.ext.module.maasng:632 ][INFO    ][8837] vgroot
2019-12-16 20:10:48,726 [salt.loaded.ext.module.maasng:635 ][INFO    ][8837] lvroot
2019-12-16 20:10:48,726 [salt.loaded.ext.module.maasng:639 ][INFO    ][8837] 107374182400
2019-12-16 20:10:49,454 [salt.loaded.ext.module.maasng:645 ][INFO    ][8837] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'disable_ipv4': False, u'storage_test_status_name': u'Passed', 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'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'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 27, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'btkh6x', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/interfaces/4/'}, u'min_hwe_kernel': u'ga-18.04', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'partition_table_type': u'GPT', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'db700468-1fef-4c77-9c21-275027dabcdc', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btkh6x', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'03b26888-2c36-42bf-958e-699311f7adfb', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/partition/6', u'type': u'partition', u'id': 6, u'device_id': 3}], u'filesystem': None, u'name': u'sda', u'system_id': u'btkh6x', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/btkh6x/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'btkh6x', u'power_state': u'on', 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"'cloudinit' running modules for final", u'owner_data': {}, u'blockdevice_set': [{u'partition_table_type': u'GPT', u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'filesystem': None, u'partitions': [{u'size': 2397992648704, u'uuid': u'db700468-1fef-4c77-9c21-275027dabcdc', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btkh6x', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'03b26888-2c36-42bf-958e-699311f7adfb', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/partition/6', u'type': u'partition', u'id': 6, u'device_id': 3}], u'name': u'sda', u'system_id': u'btkh6x', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'partition_table_type': None, u'uuid': u'9793a8fe-3ad0-43b5-8db7-bfd88de7fc3f', u'tags': [], u'type': u'virtual', u'id': 11, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'06b14fb6-1334-4c09-8be7-901e800e2f83', u'label': u'root'}, u'partitions': [], u'name': u'vgroot-lvroot', u'system_id': u'btkh6x', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/11/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'partition_table_type': u'GPT', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'db700468-1fef-4c77-9c21-275027dabcdc', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btkh6x', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'03b26888-2c36-42bf-958e-699311f7adfb', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/partition/6', u'type': u'partition', u'id': 6, u'device_id': 3}], u'filesystem': None, u'name': u'sda', u'system_id': u'btkh6x', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/3/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'btkh6x', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 27, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'btkh6x', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 28, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'system_id': u'btkh6x', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/interfaces/15/'}, {u'name': u'enp8s0', u'links': [{u'id': 31, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'system_id': u'btkh6x', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/interfaces/17/'}, {u'name': u'enp7s0', u'links': [{u'id': 34, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'system_id': u'btkh6x', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'partition_table_type': None, u'uuid': u'9793a8fe-3ad0-43b5-8db7-bfd88de7fc3f', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'06b14fb6-1334-4c09-8be7-901e800e2f83', u'label': u'root'}, u'name': u'vgroot-lvroot', u'system_id': u'btkh6x', u'resource_uri': u'/MAAS/api/2.0/nodes/btkh6x/blockdevices/11/', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'serial': None, u'size': 107374182400}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-12-16 20:10:49,457 [salt.state       :300 ][INFO    ][8837] {'new': {'storage_layout': 'lvm'}}
2019-12-16 20:10:49,457 [salt.state       :1951][INFO    ][8837] Completed state [maas_machines_storage_cmp002_lvm] at time 20:10:49.457526 duration_in_ms=2293.814
2019-12-16 20:10:49,458 [salt.state       :1780][INFO    ][8837] Running state [maas_machines_storage_cmp001_lvm] at time 20:10:49.458118
2019-12-16 20:10:49,458 [salt.state       :1813][INFO    ][8837] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-16 20:10:50,770 [salt.loaded.ext.module.maasng:610 ][INFO    ][8837] xy3acp
2019-12-16 20:10:50,771 [salt.loaded.ext.module.maasng:626 ][INFO    ][8837] sda
2019-12-16 20:10:51,282 [salt.loaded.ext.module.maasng:361 ][INFO    ][8837] xy3acp
2019-12-16 20:10:51,397 [salt.loaded.ext.module.maasng:367 ][INFO    ][8837] [{u'partition_table_type': u'GPT', u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'filesystem': None, u'partitions': [{u'size': 2397992648704, u'uuid': u'6cb13e31-812d-4076-bd68-fca29c50da76', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xy3acp', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'52805b84-1c2e-47cb-9edd-a4637e5a1826', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/partition/2', u'type': u'partition', u'id': 2, u'device_id': 2}], u'name': u'sda', u'system_id': u'xy3acp', u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'partition_table_type': None, u'uuid': u'3230c0e2-8709-4538-978c-33eabe409dca', u'tags': [], u'type': u'virtual', u'id': 7, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'28e07bf7-da9c-47f7-8308-157a6bce6a00', u'label': u'root'}, u'partitions': [], u'name': u'vgroot-lvroot', u'system_id': u'xy3acp', u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/7/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'size': 2397988454400}]
2019-12-16 20:10:51,397 [salt.loaded.ext.module.maasng:632 ][INFO    ][8837] vgroot
2019-12-16 20:10:51,398 [salt.loaded.ext.module.maasng:635 ][INFO    ][8837] lvroot
2019-12-16 20:10:51,398 [salt.loaded.ext.module.maasng:639 ][INFO    ][8837] 107374182400
2019-12-16 20:10:52,104 [salt.loaded.ext.module.maasng:645 ][INFO    ][8837] {u'hwe_kernel': u'', u'swap_size': None, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 23, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'xy3acp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/interfaces/5/'}, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'status_action': u'modules-final', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/', u'partitions': [{u'size': 2397992648704, u'uuid': u'e66d51b8-a0ce-4d5f-b031-5b5d94fc85cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xy3acp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'07c5fe47-8c37-43d2-987a-6f0e30aaad0f', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'system_id': u'xy3acp', 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': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'13596ad3-a7e2-4d2b-ac6a-dcdf47eb7f4b', u'tags': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/12/', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'system_id': u'xy3acp', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'd2694722-c8dc-4ebc-b828-d9b08ed8b508', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 107374182400, u'type': u'virtual', u'id': 12, u'serial': None, u'name': u'vgroot-lvroot'}], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'xy3acp', u'power_state': u'on', 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"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/12/', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'13596ad3-a7e2-4d2b-ac6a-dcdf47eb7f4b', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'xy3acp', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'd2694722-c8dc-4ebc-b828-d9b08ed8b508', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'min_hwe_kernel': u'ga-18.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'xy3acp', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'e66d51b8-a0ce-4d5f-b031-5b5d94fc85cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xy3acp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'07c5fe47-8c37-43d2-987a-6f0e30aaad0f', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/partition/7'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'xy3acp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 23, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'xy3acp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 24, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'id': 12, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'xy3acp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/interfaces/12/'}, {u'name': u'enp8s0', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'id': 13, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'xy3acp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/interfaces/13/'}, {u'name': u'enp7s0', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'fabric': u'fabric-0'}, u'enabled': True, u'id': 14, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'xy3acp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/interfaces/14/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'e66d51b8-a0ce-4d5f-b031-5b5d94fc85cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xy3acp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'07c5fe47-8c37-43d2-987a-6f0e30aaad0f', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/xy3acp/blockdevices/2/partition/7'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'xy3acp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'ip_addresses': [u'192.168.11.38'], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/xy3acp/', u'distro_series': u'', u'memory_test_status': -1}
2019-12-16 20:10:52,106 [salt.state       :300 ][INFO    ][8837] {'new': {'storage_layout': 'lvm'}}
2019-12-16 20:10:52,106 [salt.state       :1951][INFO    ][8837] Completed state [maas_machines_storage_cmp001_lvm] at time 20:10:52.106730 duration_in_ms=2648.612
2019-12-16 20:10:52,110 [salt.minion      :1711][INFO    ][8837] Returning information for job: 20191216201041883376
2019-12-16 20:10:52,660 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216201052653879
2019-12-16 20:10:52,672 [salt.minion      :1432][INFO    ][8930] Starting a new job with PID 8930
2019-12-16 20:10:53,273 [salt.state       :915 ][INFO    ][8930] Loading fresh modules for state activity
2019-12-16 20:10:53,327 [salt.fileclient  :1219][INFO    ][8930] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-12-16 20:10:53,372 [salt.state       :1780][INFO    ][8930] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:10:53.372727
2019-12-16 20:10:53,373 [salt.state       :1813][INFO    ][8930] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:10:53,375 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8930] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:10:54,804 [salt.state       :300 ][INFO    ][8930] {'pid': 8948, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:10:54,805 [salt.state       :1951][INFO    ][8930] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:10:54.805406 duration_in_ms=1432.678
2019-12-16 20:10:54,807 [salt.state       :1780][INFO    ][8930] Running state [maas.deploy_machines] at time 20:10:54.807839
2019-12-16 20:10:54,808 [salt.state       :1813][INFO    ][8930] Executing state module.run for [maas.deploy_machines]
2019-12-16 20:10:54,809 [salt.utils.decorators:613 ][WARNING ][8930] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:10:55,482 [salt.loaded.ext.module.maas:684 ][INFO    ][8930] deploymachines hwe_kernel=ga-18.04 system_id=btkh6x distro_series=bionic
2019-12-16 20:10:58,190 [salt.loaded.ext.module.maas:684 ][INFO    ][8930] deploymachines hwe_kernel=ga-18.04 system_id=xy3acp distro_series=bionic
2019-12-16 20:11:00,551 [salt.loaded.ext.module.maas:684 ][INFO    ][8930] deploymachines hwe_kernel=ga-18.04 system_id=mbdewb distro_series=bionic
2019-12-16 20:11:03,018 [salt.loaded.ext.module.maas:684 ][INFO    ][8930] deploymachines hwe_kernel=ga-18.04 system_id=7b8a77 distro_series=bionic
2019-12-16 20:11:05,504 [salt.loaded.ext.module.maas:684 ][INFO    ][8930] deploymachines hwe_kernel=ga-18.04 system_id=fwtg7n distro_series=bionic
2019-12-16 20:11:07,772 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201107759678
2019-12-16 20:11:07,794 [salt.minion      :1432][INFO    ][9210] Starting a new job with PID 9210
2019-12-16 20:11:07,819 [salt.minion      :1711][INFO    ][9210] Returning information for job: 20191216201107759678
2019-12-16 20:11:08,187 [salt.state       :300 ][INFO    ][8930] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-12-16 20:11:08,188 [salt.state       :1951][INFO    ][8930] Completed state [maas.deploy_machines] at time 20:11:08.188491 duration_in_ms=13380.636
2019-12-16 20:11:08,192 [salt.minion      :1711][INFO    ][8930] Returning information for job: 20191216201052653879
2019-12-16 20:11:08,746 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216201108733276
2019-12-16 20:11:08,765 [salt.minion      :1432][INFO    ][9225] Starting a new job with PID 9225
2019-12-16 20:11:12,455 [salt.state       :915 ][INFO    ][9225] Loading fresh modules for state activity
2019-12-16 20:11:12,504 [salt.fileclient  :1219][INFO    ][9225] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-12-16 20:11:12,543 [salt.state       :1780][INFO    ][9225] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:11:12.543551
2019-12-16 20:11:12,544 [salt.state       :1813][INFO    ][9225] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:11:12,546 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9225] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:11:14,161 [salt.state       :300 ][INFO    ][9225] {'pid': 9238, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:11:14,162 [salt.state       :1951][INFO    ][9225] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:11:14.162461 duration_in_ms=1618.909
2019-12-16 20:11:14,165 [salt.state       :1780][INFO    ][9225] Running state [maas.wait_for_machine_status] at time 20:11:14.165673
2019-12-16 20:11:14,166 [salt.state       :1813][INFO    ][9225] Executing state module.run for [maas.wait_for_machine_status]
2019-12-16 20:11:14,166 [salt.utils.decorators:613 ][WARNING ][9225] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:11:17,468 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.70847702s left)
2019-12-16 20:11:23,853 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201123840102
2019-12-16 20:11:23,874 [salt.minion      :1432][INFO    ][9271] Starting a new job with PID 9271
2019-12-16 20:11:23,898 [salt.minion      :1711][INFO    ][9271] Returning information for job: 20191216201123840102
2019-12-16 20:11:50,309 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.86709714s left)
2019-12-16 20:11:53,898 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201153883252
2019-12-16 20:11:53,921 [salt.minion      :1432][INFO    ][9309] Starting a new job with PID 9309
2019-12-16 20:11:53,944 [salt.minion      :1711][INFO    ][9309] Returning information for job: 20191216201153883252
2019-12-16 20:12:23,637 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.53999114s left)
2019-12-16 20:12:23,992 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201223979934
2019-12-16 20:12:24,014 [salt.minion      :1432][INFO    ][9345] Starting a new job with PID 9345
2019-12-16 20:12:24,038 [salt.minion      :1711][INFO    ][9345] Returning information for job: 20191216201223979934
2019-12-16 20:12:54,031 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201254024649
2019-12-16 20:12:54,044 [salt.minion      :1432][INFO    ][9473] Starting a new job with PID 9473
2019-12-16 20:12:54,054 [salt.minion      :1711][INFO    ][9473] Returning information for job: 20191216201254024649
2019-12-16 20:12:56,489 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.68773198s left)
2019-12-16 20:13:24,060 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201324050657
2019-12-16 20:13:24,074 [salt.minion      :1432][INFO    ][9726] Starting a new job with PID 9726
2019-12-16 20:13:24,092 [salt.minion      :1711][INFO    ][9726] Returning information for job: 20191216201324050657
2019-12-16 20:13:29,517 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.65922713s left)
2019-12-16 20:13:54,096 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201354085821
2019-12-16 20:13:54,117 [salt.minion      :1432][INFO    ][10208] Starting a new job with PID 10208
2019-12-16 20:13:54,140 [salt.minion      :1711][INFO    ][10208] Returning information for job: 20191216201354085821
2019-12-16 20:14:03,169 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.00743699s left)
2019-12-16 20:14:24,151 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201424138443
2019-12-16 20:14:24,171 [salt.minion      :1432][INFO    ][10423] Starting a new job with PID 10423
2019-12-16 20:14:24,192 [salt.minion      :1711][INFO    ][10423] Returning information for job: 20191216201424138443
2019-12-16 20:14:36,631 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.54600406s left)
2019-12-16 20:14:54,205 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201454193231
2019-12-16 20:14:54,228 [salt.minion      :1432][INFO    ][10647] Starting a new job with PID 10647
2019-12-16 20:14:54,252 [salt.minion      :1711][INFO    ][10647] Returning information for job: 20191216201454193231
2019-12-16 20:15:10,265 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.91169214s left)
2019-12-16 20:15:24,267 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201524255087
2019-12-16 20:15:24,288 [salt.minion      :1432][INFO    ][10737] Starting a new job with PID 10737
2019-12-16 20:15:24,312 [salt.minion      :1711][INFO    ][10737] Returning information for job: 20191216201524255087
2019-12-16 20:15:43,355 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.82181406s left)
2019-12-16 20:15:54,337 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201554321783
2019-12-16 20:15:54,360 [salt.minion      :1432][INFO    ][10857] Starting a new job with PID 10857
2019-12-16 20:15:54,382 [salt.minion      :1711][INFO    ][10857] Returning information for job: 20191216201554321783
2019-12-16 20:16:16,803 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.37390804s left)
2019-12-16 20:16:24,405 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201624393207
2019-12-16 20:16:24,428 [salt.minion      :1432][INFO    ][10956] Starting a new job with PID 10956
2019-12-16 20:16:24,451 [salt.minion      :1711][INFO    ][10956] Returning information for job: 20191216201624393207
2019-12-16 20:16:50,463 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.71313405s left)
2019-12-16 20:16:54,485 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201654474705
2019-12-16 20:16:54,506 [salt.minion      :1432][INFO    ][11194] Starting a new job with PID 11194
2019-12-16 20:16:54,529 [salt.minion      :1711][INFO    ][11194] Returning information for job: 20191216201654474705
2019-12-16 20:17:23,885 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.29153705s left)
2019-12-16 20:17:24,562 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201724554913
2019-12-16 20:17:24,576 [salt.minion      :1432][INFO    ][11373] Starting a new job with PID 11373
2019-12-16 20:17:24,591 [salt.minion      :1711][INFO    ][11373] Returning information for job: 20191216201724554913
2019-12-16 20:17:54,630 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201754619347
2019-12-16 20:17:54,650 [salt.minion      :1432][INFO    ][11637] Starting a new job with PID 11637
2019-12-16 20:17:54,664 [salt.minion      :1711][INFO    ][11637] Returning information for job: 20191216201754619347
2019-12-16 20:17:57,410 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.76621318s left)
2019-12-16 20:18:24,708 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201824695261
2019-12-16 20:18:24,730 [salt.minion      :1432][INFO    ][11701] Starting a new job with PID 11701
2019-12-16 20:18:24,755 [salt.minion      :1711][INFO    ][11701] Returning information for job: 20191216201824695261
2019-12-16 20:18:30,878 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.29829717s left)
2019-12-16 20:18:54,727 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201854714357
2019-12-16 20:18:54,749 [salt.minion      :1432][INFO    ][11899] Starting a new job with PID 11899
2019-12-16 20:18:54,772 [salt.minion      :1711][INFO    ][11899] Returning information for job: 20191216201854714357
2019-12-16 20:19:04,334 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1779.84215117s left)
2019-12-16 20:19:24,759 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201924751992
2019-12-16 20:19:24,773 [salt.minion      :1432][INFO    ][12099] Starting a new job with PID 12099
2019-12-16 20:19:24,789 [salt.minion      :1711][INFO    ][12099] Returning information for job: 20191216201924751992
2019-12-16 20:19:37,566 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1746.61029005s left)
2019-12-16 20:19:54,851 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216201954838744
2019-12-16 20:19:54,872 [salt.minion      :1432][INFO    ][12397] Starting a new job with PID 12397
2019-12-16 20:19:54,893 [salt.minion      :1711][INFO    ][12397] Returning information for job: 20191216201954838744
2019-12-16 20:20:10,962 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1713.21482515s left)
2019-12-16 20:20:24,962 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202024950381
2019-12-16 20:20:24,984 [salt.minion      :1432][INFO    ][12506] Starting a new job with PID 12506
2019-12-16 20:20:25,006 [salt.minion      :1711][INFO    ][12506] Returning information for job: 20191216202024950381
2019-12-16 20:20:44,525 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1679.65180302s left)
2019-12-16 20:20:55,092 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202055076337
2019-12-16 20:20:55,115 [salt.minion      :1432][INFO    ][12543] Starting a new job with PID 12543
2019-12-16 20:20:55,140 [salt.minion      :1711][INFO    ][12543] Returning information for job: 20191216202055076337
2019-12-16 20:21:17,862 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1646.31494308s left)
2019-12-16 20:21:25,221 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202125207981
2019-12-16 20:21:25,239 [salt.minion      :1432][INFO    ][12583] Starting a new job with PID 12583
2019-12-16 20:21:25,261 [salt.minion      :1711][INFO    ][12583] Returning information for job: 20191216202125207981
2019-12-16 20:21:51,376 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1612.80088496s left)
2019-12-16 20:21:55,348 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202155336054
2019-12-16 20:21:55,370 [salt.minion      :1432][INFO    ][12618] Starting a new job with PID 12618
2019-12-16 20:21:55,393 [salt.minion      :1711][INFO    ][12618] Returning information for job: 20191216202155336054
2019-12-16 20:22:25,233 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.94404817s left)
2019-12-16 20:22:25,497 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202225484171
2019-12-16 20:22:25,520 [salt.minion      :1432][INFO    ][12660] Starting a new job with PID 12660
2019-12-16 20:22:25,545 [salt.minion      :1711][INFO    ][12660] Returning information for job: 20191216202225484171
2019-12-16 20:22:55,663 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202255648234
2019-12-16 20:22:55,683 [salt.minion      :1432][INFO    ][12694] Starting a new job with PID 12694
2019-12-16 20:22:55,707 [salt.minion      :1711][INFO    ][12694] Returning information for job: 20191216202255648234
2019-12-16 20:22:58,903 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1545.27384305s left)
2019-12-16 20:23:25,836 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202325820402
2019-12-16 20:23:25,859 [salt.minion      :1432][INFO    ][12736] Starting a new job with PID 12736
2019-12-16 20:23:25,883 [salt.minion      :1711][INFO    ][12736] Returning information for job: 20191216202325820402
2019-12-16 20:23:32,124 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1512.05212903s left)
2019-12-16 20:23:56,011 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202355998467
2019-12-16 20:23:56,034 [salt.minion      :1432][INFO    ][12779] Starting a new job with PID 12779
2019-12-16 20:23:56,058 [salt.minion      :1711][INFO    ][12779] Returning information for job: 20191216202355998467
2019-12-16 20:24:05,654 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1478.52212811s left)
2019-12-16 20:24:26,196 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202426183812
2019-12-16 20:24:26,218 [salt.minion      :1432][INFO    ][12909] Starting a new job with PID 12909
2019-12-16 20:24:26,242 [salt.minion      :1711][INFO    ][12909] Returning information for job: 20191216202426183812
2019-12-16 20:24:38,509 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1445.66746998s left)
2019-12-16 20:24:56,396 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202456383404
2019-12-16 20:24:56,420 [salt.minion      :1432][INFO    ][12955] Starting a new job with PID 12955
2019-12-16 20:24:56,445 [salt.minion      :1711][INFO    ][12955] Returning information for job: 20191216202456383404
2019-12-16 20:25:12,024 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1412.15248013s left)
2019-12-16 20:25:26,612 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202526599148
2019-12-16 20:25:26,634 [salt.minion      :1432][INFO    ][12999] Starting a new job with PID 12999
2019-12-16 20:25:26,658 [salt.minion      :1711][INFO    ][12999] Returning information for job: 20191216202526599148
2019-12-16 20:25:45,031 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1379.14548397s left)
2019-12-16 20:25:56,830 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202556817253
2019-12-16 20:25:56,853 [salt.minion      :1432][INFO    ][13036] Starting a new job with PID 13036
2019-12-16 20:25:56,878 [salt.minion      :1711][INFO    ][13036] Returning information for job: 20191216202556817253
2019-12-16 20:26:18,690 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1345.48656297s left)
2019-12-16 20:26:26,851 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202626839559
2019-12-16 20:26:26,874 [salt.minion      :1432][INFO    ][13074] Starting a new job with PID 13074
2019-12-16 20:26:26,896 [salt.minion      :1711][INFO    ][13074] Returning information for job: 20191216202626839559
2019-12-16 20:26:52,355 [salt.loaded.ext.module.maas:1023][INFO    ][9225] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1311.82192016s left)
2019-12-16 20:26:56,882 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202656870048
2019-12-16 20:26:56,907 [salt.minion      :1432][INFO    ][13110] Starting a new job with PID 13110
2019-12-16 20:26:56,932 [salt.minion      :1711][INFO    ][13110] Returning information for job: 20191216202656870048
2019-12-16 20:27:25,076 [salt.loaded.ext.module.maas:993 ][INFO    ][9225] Machine 7b8a77 mark broken
2019-12-16 20:27:25,832 [salt.loaded.ext.module.maas:996 ][INFO    ][9225] Machine 7b8a77 mark fixed
2019-12-16 20:27:26,934 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202726922051
2019-12-16 20:27:26,955 [salt.minion      :1432][INFO    ][13168] Starting a new job with PID 13168
2019-12-16 20:27:26,980 [salt.minion      :1711][INFO    ][13168] Returning information for job: 20191216202726922051
2019-12-16 20:27:27,010 [salt.loaded.ext.module.maas:684 ][INFO    ][9225] deploymachines hwe_kernel=ga-18.04 system_id=7b8a77 distro_series=bionic
2019-12-16 20:27:29,675 [salt.loaded.ext.module.maas:160 ][ERROR   ][9225] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-12-16 20:27:29,677 [salt.state       :302 ][ERROR   ][9225] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-12-16 20:27:29,678 [salt.state       :1951][INFO    ][9225] Completed state [maas.wait_for_machine_status] at time 20:27:29.678602 duration_in_ms=975512.921
2019-12-16 20:27:29,689 [salt.minion      :1711][INFO    ][9225] Returning information for job: 20191216201108733276
2019-12-16 20:27:40,436 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command pillar.get with jid 20191216202740425753
2019-12-16 20:27:40,455 [salt.minion      :1432][INFO    ][13230] Starting a new job with PID 13230
2019-12-16 20:27:40,460 [salt.minion      :1711][INFO    ][13230] Returning information for job: 20191216202740425753
2019-12-16 20:27:40,910 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command service.status with jid 20191216202740897006
2019-12-16 20:27:40,931 [salt.minion      :1432][INFO    ][13235] Starting a new job with PID 13235
2019-12-16 20:27:41,326 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13235] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:41,361 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13235] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-12-16 20:27:41,376 [salt.minion      :1711][INFO    ][13235] Returning information for job: 20191216202740897006
2019-12-16 20:27:41,905 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216202741898071
2019-12-16 20:27:41,925 [salt.minion      :1432][INFO    ][13246] Starting a new job with PID 13246
2019-12-16 20:27:45,557 [salt.state       :915 ][INFO    ][13246] Loading fresh modules for state activity
2019-12-16 20:27:45,879 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'salt-minion --version' in directory '/root'
2019-12-16 20:27:46,196 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'salt-minion --version' in directory '/root'
2019-12-16 20:27:47,048 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'salt-minion --version' in directory '/root'
2019-12-16 20:27:47,392 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'salt-minion --version' in directory '/root'
2019-12-16 20:27:48,668 [salt.state       :1780][INFO    ][13246] Running state [salt-minion] at time 20:27:48.668900
2019-12-16 20:27:48,669 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [salt-minion]
2019-12-16 20:27:48,669 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-16 20:27:48,750 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:48,751 [salt.state       :1951][INFO    ][13246] Completed state [salt-minion] at time 20:27:48.750990 duration_in_ms=82.09
2019-12-16 20:27:48,751 [salt.state       :1780][INFO    ][13246] Running state [salt_minion_dependency_packages] at time 20:27:48.751253
2019-12-16 20:27:48,751 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-12-16 20:27:48,756 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:48,756 [salt.state       :1951][INFO    ][13246] Completed state [salt_minion_dependency_packages] at time 20:27:48.756734 duration_in_ms=5.481
2019-12-16 20:27:48,759 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/minion.d/minion.conf] at time 20:27:48.759282
2019-12-16 20:27:48,759 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-12-16 20:27:48,947 [salt.state       :300 ][INFO    ][13246] File /etc/salt/minion.d/minion.conf is in the correct state
2019-12-16 20:27:48,947 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/minion.d/minion.conf] at time 20:27:48.947559 duration_in_ms=188.277
2019-12-16 20:27:48,947 [salt.state       :1780][INFO    ][13246] Running state [python-netaddr] at time 20:27:48.947748
2019-12-16 20:27:48,947 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [python-netaddr]
2019-12-16 20:27:48,954 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:48,954 [salt.state       :1951][INFO    ][13246] Completed state [python-netaddr] at time 20:27:48.954789 duration_in_ms=7.041
2019-12-16 20:27:48,957 [salt.state       :1780][INFO    ][13246] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:27:48.957845
2019-12-16 20:27:48,958 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-12-16 20:27:48,967 [salt.state       :300 ][INFO    ][13246] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-12-16 20:27:48,968 [salt.state       :1951][INFO    ][13246] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:27:48.967974 duration_in_ms=10.129
2019-12-16 20:27:48,968 [salt.state       :1780][INFO    ][13246] Running state [salt-minion] at time 20:27:48.968934
2019-12-16 20:27:48,969 [salt.state       :1813][INFO    ][13246] Executing state service.running for [salt-minion]
2019-12-16 20:27:48,969 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:48,999 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-12-16 20:27:49,013 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-12-16 20:27:49,026 [salt.state       :300 ][INFO    ][13246] The service salt-minion is already running
2019-12-16 20:27:49,026 [salt.state       :1951][INFO    ][13246] Completed state [salt-minion] at time 20:27:49.026789 duration_in_ms=57.855
2019-12-16 20:27:49,027 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains.d] at time 20:27:49.027946
2019-12-16 20:27:49,028 [salt.state       :1813][INFO    ][13246] Executing state file.directory for [/etc/salt/grains.d]
2019-12-16 20:27:49,029 [salt.state       :300 ][INFO    ][13246] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-12-16 20:27:49,029 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains.d] at time 20:27:49.029160 duration_in_ms=1.214
2019-12-16 20:27:49,029 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains] at time 20:27:49.029679
2019-12-16 20:27:49,029 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/grains]
2019-12-16 20:27:49,030 [salt.state       :300 ][INFO    ][13246] File /etc/salt/grains exists with proper permissions. No changes made.
2019-12-16 20:27:49,030 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains] at time 20:27:49.030531 duration_in_ms=0.853
2019-12-16 20:27:49,030 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains.d/placeholder] at time 20:27:49.030880
2019-12-16 20:27:49,031 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-12-16 20:27:49,031 [salt.state       :300 ][INFO    ][13246] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-12-16 20:27:49,031 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains.d/placeholder] at time 20:27:49.031700 duration_in_ms=0.82
2019-12-16 20:27:49,032 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains.d/sphinx] at time 20:27:49.032053
2019-12-16 20:27:49,032 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-12-16 20:27:49,043 [salt.state       :300 ][INFO    ][13246] File /etc/salt/grains.d/sphinx is in the correct state
2019-12-16 20:27:49,043 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains.d/sphinx] at time 20:27:49.043196 duration_in_ms=11.143
2019-12-16 20:27:49,044 [salt.state       :1780][INFO    ][13246] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.044907
2019-12-16 20:27:49,045 [salt.state       :1813][INFO    ][13246] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-12-16 20:27:49,045 [salt.state       :300 ][INFO    ][13246] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-12-16 20:27:49,045 [salt.state       :1951][INFO    ][13246] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.045596 duration_in_ms=0.689
2019-12-16 20:27:49,045 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains.d/dns_records] at time 20:27:49.045951
2019-12-16 20:27:49,046 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-12-16 20:27:49,055 [salt.state       :300 ][INFO    ][13246] File /etc/salt/grains.d/dns_records is in the correct state
2019-12-16 20:27:49,055 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains.d/dns_records] at time 20:27:49.055354 duration_in_ms=9.403
2019-12-16 20:27:49,056 [salt.state       :1780][INFO    ][13246] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.056065
2019-12-16 20:27:49,056 [salt.state       :1813][INFO    ][13246] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-12-16 20:27:49,056 [salt.state       :300 ][INFO    ][13246] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-12-16 20:27:49,056 [salt.state       :1951][INFO    ][13246] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.056739 duration_in_ms=0.673
2019-12-16 20:27:49,057 [salt.state       :1780][INFO    ][13246] Running state [/etc/salt/grains.d/salt] at time 20:27:49.057101
2019-12-16 20:27:49,057 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-12-16 20:27:49,067 [salt.state       :300 ][INFO    ][13246] File /etc/salt/grains.d/salt is in the correct state
2019-12-16 20:27:49,067 [salt.state       :1951][INFO    ][13246] Completed state [/etc/salt/grains.d/salt] at time 20:27:49.067342 duration_in_ms=10.241
2019-12-16 20:27:49,068 [salt.state       :1780][INFO    ][13246] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.068041
2019-12-16 20:27:49,068 [salt.state       :1813][INFO    ][13246] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-12-16 20:27:49,068 [salt.state       :300 ][INFO    ][13246] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-12-16 20:27:49,068 [salt.state       :1951][INFO    ][13246] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:27:49.068728 duration_in_ms=0.687
2019-12-16 20:27:49,070 [salt.state       :1780][INFO    ][13246] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:27:49.070170
2019-12-16 20:27:49,070 [salt.state       :1813][INFO    ][13246] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-12-16 20:27:49,070 [salt.state       :300 ][INFO    ][13246] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-12-16 20:27:49,070 [salt.state       :1951][INFO    ][13246] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:27:49.070872 duration_in_ms=0.703
2019-12-16 20:27:49,071 [salt.state       :1780][INFO    ][13246] Running state [mine.update] at time 20:27:49.071391
2019-12-16 20:27:49,071 [salt.state       :1813][INFO    ][13246] Executing state module.wait for [mine.update]
2019-12-16 20:27:49,071 [salt.state       :300 ][INFO    ][13246] No changes made for mine.update
2019-12-16 20:27:49,072 [salt.state       :1951][INFO    ][13246] Completed state [mine.update] at time 20:27:49.072049 duration_in_ms=0.659
2019-12-16 20:27:49,072 [salt.state       :1780][INFO    ][13246] Running state [ca-certificates] at time 20:27:49.072252
2019-12-16 20:27:49,072 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [ca-certificates]
2019-12-16 20:27:49,078 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:49,078 [salt.state       :1951][INFO    ][13246] Completed state [ca-certificates] at time 20:27:49.078306 duration_in_ms=6.054
2019-12-16 20:27:49,078 [salt.state       :1780][INFO    ][13246] Running state [update-ca-certificates] at time 20:27:49.078854
2019-12-16 20:27:49,079 [salt.state       :1813][INFO    ][13246] Executing state cmd.wait for [update-ca-certificates]
2019-12-16 20:27:49,079 [salt.state       :300 ][INFO    ][13246] No changes made for update-ca-certificates
2019-12-16 20:27:49,079 [salt.state       :1951][INFO    ][13246] Completed state [update-ca-certificates] at time 20:27:49.079516 duration_in_ms=0.662
2019-12-16 20:27:49,079 [salt.state       :1780][INFO    ][13246] Running state [iptables] at time 20:27:49.079720
2019-12-16 20:27:49,079 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [iptables]
2019-12-16 20:27:49,084 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:49,085 [salt.state       :1951][INFO    ][13246] Completed state [iptables] at time 20:27:49.085114 duration_in_ms=5.394
2019-12-16 20:27:49,085 [salt.state       :1780][INFO    ][13246] Running state [iptables-persistent] at time 20:27:49.085311
2019-12-16 20:27:49,085 [salt.state       :1813][INFO    ][13246] Executing state pkg.installed for [iptables-persistent]
2019-12-16 20:27:49,090 [salt.state       :300 ][INFO    ][13246] All specified packages are already installed
2019-12-16 20:27:49,090 [salt.state       :1951][INFO    ][13246] Completed state [iptables-persistent] at time 20:27:49.090717 duration_in_ms=5.406
2019-12-16 20:27:49,091 [salt.state       :1780][INFO    ][13246] Running state [iptables_modules_v4_load] at time 20:27:49.091481
2019-12-16 20:27:49,091 [salt.state       :1813][INFO    ][13246] Executing state kmod.present for [iptables_modules_v4_load]
2019-12-16 20:27:49,092 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'lsmod' in directory '/root'
2019-12-16 20:27:49,110 [salt.state       :300 ][INFO    ][13246] Kernel modules iptable_filter, ip_tables are already present
2019-12-16 20:27:49,110 [salt.state       :1951][INFO    ][13246] Completed state [iptables_modules_v4_load] at time 20:27:49.110863 duration_in_ms=19.381
2019-12-16 20:27:49,111 [salt.state       :1780][INFO    ][13246] Running state [/etc/iptables/rules.v4] at time 20:27:49.111328
2019-12-16 20:27:49,111 [salt.state       :1813][INFO    ][13246] Executing state file.managed for [/etc/iptables/rules.v4]
2019-12-16 20:27:49,181 [salt.state       :300 ][INFO    ][13246] File /etc/iptables/rules.v4 is in the correct state
2019-12-16 20:27:49,181 [salt.state       :1951][INFO    ][13246] Completed state [/etc/iptables/rules.v4] at time 20:27:49.181311 duration_in_ms=69.982
2019-12-16 20:27:49,182 [salt.state       :1780][INFO    ][13246] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:27:49.182078
2019-12-16 20:27:49,182 [salt.state       :1813][INFO    ][13246] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-12-16 20:27:49,182 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-12-16 20:27:49,201 [salt.state       :300 ][INFO    ][13246] onlyif execution failed
2019-12-16 20:27:49,201 [salt.state       :1951][INFO    ][13246] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:27:49.201577 duration_in_ms=19.497
2019-12-16 20:27:49,202 [salt.state       :1780][INFO    ][13246] Running state [netfilter-persistent] at time 20:27:49.202817
2019-12-16 20:27:49,203 [salt.state       :1813][INFO    ][13246] Executing state service.running for [netfilter-persistent]
2019-12-16 20:27:49,203 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:49,221 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-12-16 20:27:49,238 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-12-16 20:27:49,253 [salt.state       :300 ][INFO    ][13246] The service netfilter-persistent is already running
2019-12-16 20:27:49,253 [salt.state       :1951][INFO    ][13246] Completed state [netfilter-persistent] at time 20:27:49.253474 duration_in_ms=50.658
2019-12-16 20:27:49,254 [salt.state       :1780][INFO    ][13246] Running state [iptables_extra.remove_stale_tables] at time 20:27:49.254118
2019-12-16 20:27:49,254 [salt.state       :1813][INFO    ][13246] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-12-16 20:27:49,254 [salt.state       :300 ][INFO    ][13246] No changes made for iptables_extra.remove_stale_tables
2019-12-16 20:27:49,254 [salt.state       :1951][INFO    ][13246] Completed state [iptables_extra.remove_stale_tables] at time 20:27:49.254842 duration_in_ms=0.724
2019-12-16 20:27:49,255 [salt.state       :1780][INFO    ][13246] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:27:49.255041
2019-12-16 20:27:49,255 [salt.state       :1813][INFO    ][13246] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-12-16 20:27:49,255 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13246] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-12-16 20:27:49,266 [salt.state       :300 ][INFO    ][13246] onlyif execution failed
2019-12-16 20:27:49,267 [salt.state       :1951][INFO    ][13246] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:27:49.266990 duration_in_ms=11.949
2019-12-16 20:27:49,267 [salt.state       :1780][INFO    ][13246] Running state [/etc/iptables/rules.v6] at time 20:27:49.267702
2019-12-16 20:27:49,267 [salt.state       :1813][INFO    ][13246] Executing state file.absent for [/etc/iptables/rules.v6]
2019-12-16 20:27:49,268 [salt.state       :300 ][INFO    ][13246] File /etc/iptables/rules.v6 is not present
2019-12-16 20:27:49,268 [salt.state       :1951][INFO    ][13246] Completed state [/etc/iptables/rules.v6] at time 20:27:49.268476 duration_in_ms=0.774
2019-12-16 20:27:49,269 [salt.state       :1780][INFO    ][13246] Running state [iptables_extra.flush_all] at time 20:27:49.268982
2019-12-16 20:27:49,269 [salt.state       :1813][INFO    ][13246] Executing state module.wait for [iptables_extra.flush_all]
2019-12-16 20:27:49,269 [salt.state       :300 ][INFO    ][13246] No changes made for iptables_extra.flush_all
2019-12-16 20:27:49,269 [salt.state       :1951][INFO    ][13246] Completed state [iptables_extra.flush_all] at time 20:27:49.269601 duration_in_ms=0.62
2019-12-16 20:27:49,271 [salt.minion      :1711][INFO    ][13246] Returning information for job: 20191216202741898071
2019-12-16 20:27:49,758 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216202749750419
2019-12-16 20:27:49,776 [salt.minion      :1432][INFO    ][13326] Starting a new job with PID 13326
2019-12-16 20:27:50,529 [salt.state       :915 ][INFO    ][13326] Loading fresh modules for state activity
2019-12-16 20:27:51,106 [salt.state       :1780][INFO    ][13326] Running state [maas-rack-controller] at time 20:27:51.106353
2019-12-16 20:27:51,106 [salt.state       :1813][INFO    ][13326] Executing state pkg.installed for [maas-rack-controller]
2019-12-16 20:27:51,107 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13326] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-16 20:27:51,200 [salt.state       :300 ][INFO    ][13326] All specified packages are already installed
2019-12-16 20:27:51,200 [salt.state       :1951][INFO    ][13326] Completed state [maas-rack-controller] at time 20:27:51.200584 duration_in_ms=94.231
2019-12-16 20:27:51,201 [salt.state       :1780][INFO    ][13326] Running state [ipmitool] at time 20:27:51.200992
2019-12-16 20:27:51,201 [salt.state       :1813][INFO    ][13326] Executing state pkg.installed for [ipmitool]
2019-12-16 20:27:51,209 [salt.state       :300 ][INFO    ][13326] All specified packages are already installed
2019-12-16 20:27:51,210 [salt.state       :1951][INFO    ][13326] Completed state [ipmitool] at time 20:27:51.210096 duration_in_ms=9.103
2019-12-16 20:27:51,213 [salt.state       :1780][INFO    ][13326] Running state [/etc/maas/rackd.conf] at time 20:27:51.213750
2019-12-16 20:27:51,214 [salt.state       :1813][INFO    ][13326] Executing state file.line for [/etc/maas/rackd.conf]
2019-12-16 20:27:51,215 [salt.state       :300 ][INFO    ][13326] No changes needed to be made
2019-12-16 20:27:51,215 [salt.state       :1951][INFO    ][13326] Completed state [/etc/maas/rackd.conf] at time 20:27:51.215682 duration_in_ms=1.933
2019-12-16 20:27:51,216 [salt.state       :1780][INFO    ][13326] Running state [/etc/maas/rackd.conf] at time 20:27:51.215973
2019-12-16 20:27:51,216 [salt.state       :1813][INFO    ][13326] Executing state file.managed for [/etc/maas/rackd.conf]
2019-12-16 20:27:51,216 [salt.loaded.int.states.file:2298][WARNING ][13326] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-12-16 20:27:51,217 [salt.state       :300 ][INFO    ][13326] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-12-16 20:27:51,217 [salt.state       :1951][INFO    ][13326] Completed state [/etc/maas/rackd.conf] at time 20:27:51.217503 duration_in_ms=1.529
2019-12-16 20:27:51,218 [salt.state       :1780][INFO    ][13326] Running state [maas-rackd] at time 20:27:51.218523
2019-12-16 20:27:51,218 [salt.state       :1813][INFO    ][13326] Executing state service.running for [maas-rackd]
2019-12-16 20:27:51,219 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13326] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:51,253 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13326] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-12-16 20:27:51,268 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13326] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-12-16 20:27:51,283 [salt.state       :300 ][INFO    ][13326] The service maas-rackd is already running
2019-12-16 20:27:51,283 [salt.state       :1951][INFO    ][13326] Completed state [maas-rackd] at time 20:27:51.283298 duration_in_ms=64.775
2019-12-16 20:27:51,284 [salt.minion      :1711][INFO    ][13326] Returning information for job: 20191216202749750419
2019-12-16 20:27:51,799 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216202751787775
2019-12-16 20:27:51,813 [salt.minion      :1432][INFO    ][13349] Starting a new job with PID 13349
2019-12-16 20:27:52,426 [salt.state       :915 ][INFO    ][13349] Loading fresh modules for state activity
2019-12-16 20:27:53,097 [salt.state       :1780][INFO    ][13349] Running state [maas-region-controller] at time 20:27:53.097253
2019-12-16 20:27:53,097 [salt.state       :1813][INFO    ][13349] Executing state pkg.installed for [maas-region-controller]
2019-12-16 20:27:53,098 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-16 20:27:53,196 [salt.state       :300 ][INFO    ][13349] All specified packages are already installed
2019-12-16 20:27:53,196 [salt.state       :1951][INFO    ][13349] Completed state [maas-region-controller] at time 20:27:53.196415 duration_in_ms=99.162
2019-12-16 20:27:53,196 [salt.state       :1780][INFO    ][13349] Running state [python-oauth] at time 20:27:53.196871
2019-12-16 20:27:53,197 [salt.state       :1813][INFO    ][13349] Executing state pkg.installed for [python-oauth]
2019-12-16 20:27:53,205 [salt.state       :300 ][INFO    ][13349] All specified packages are already installed
2019-12-16 20:27:53,206 [salt.state       :1951][INFO    ][13349] Completed state [python-oauth] at time 20:27:53.206019 duration_in_ms=9.149
2019-12-16 20:27:53,210 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/regiond.conf] at time 20:27:53.210155
2019-12-16 20:27:53,210 [salt.state       :1813][INFO    ][13349] Executing state file.replace for [/etc/maas/regiond.conf]
2019-12-16 20:27:53,260 [salt.state       :300 ][INFO    ][13349] No changes needed to be made
2019-12-16 20:27:53,260 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/regiond.conf] at time 20:27:53.260817 duration_in_ms=50.662
2019-12-16 20:27:53,261 [salt.state       :1780][INFO    ][13349] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:27:53.261595
2019-12-16 20:27:53,262 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-12-16 20:27:53,337 [salt.state       :300 ][INFO    ][13349] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-12-16 20:27:53,337 [salt.state       :1951][INFO    ][13349] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:27:53.337628 duration_in_ms=76.033
2019-12-16 20:27:53,338 [salt.state       :1780][INFO    ][13349] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:27:53.338273
2019-12-16 20:27:53,338 [salt.state       :1813][INFO    ][13349] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-16 20:27:53,351 [salt.state       :300 ][INFO    ][13349] No changes needed to be made
2019-12-16 20:27:53,351 [salt.state       :1951][INFO    ][13349] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:27:53.351346 duration_in_ms=13.073
2019-12-16 20:27:53,352 [salt.state       :1780][INFO    ][13349] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:27:53.352017
2019-12-16 20:27:53,352 [salt.state       :1813][INFO    ][13349] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-16 20:27:53,375 [salt.state       :300 ][INFO    ][13349] No changes needed to be made
2019-12-16 20:27:53,375 [salt.state       :1951][INFO    ][13349] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:27:53.375468 duration_in_ms=23.45
2019-12-16 20:27:53,376 [salt.state       :1780][INFO    ][13349] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:27:53.376130
2019-12-16 20:27:53,376 [salt.state       :1813][INFO    ][13349] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-12-16 20:27:53,407 [salt.state       :300 ][INFO    ][13349] No changes needed to be made
2019-12-16 20:27:53,407 [salt.state       :1951][INFO    ][13349] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:27:53.407409 duration_in_ms=31.28
2019-12-16 20:27:53,408 [salt.state       :1780][INFO    ][13349] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:27:53.408015
2019-12-16 20:27:53,408 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-12-16 20:27:53,421 [salt.state       :300 ][INFO    ][13349] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-12-16 20:27:53,421 [salt.state       :1951][INFO    ][13349] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:27:53.421397 duration_in_ms=13.382
2019-12-16 20:27:53,422 [salt.state       :1780][INFO    ][13349] Running state [a2enmod headers] at time 20:27:53.422847
2019-12-16 20:27:53,423 [salt.state       :1813][INFO    ][13349] Executing state cmd.run for [a2enmod headers]
2019-12-16 20:27:53,423 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command 'a2enmod headers' in directory '/root'
2019-12-16 20:27:53,501 [salt.state       :300 ][INFO    ][13349] {'pid': 13382, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-12-16 20:27:53,501 [salt.state       :1951][INFO    ][13349] Completed state [a2enmod headers] at time 20:27:53.501805 duration_in_ms=78.957
2019-12-16 20:27:53,502 [salt.state       :1780][INFO    ][13349] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:27:53.502417
2019-12-16 20:27:53,503 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-12-16 20:27:53,522 [salt.state       :300 ][INFO    ][13349] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-12-16 20:27:53,523 [salt.state       :1951][INFO    ][13349] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:27:53.523002 duration_in_ms=20.586
2019-12-16 20:27:53,524 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:27:53.523936
2019-12-16 20:27:53,524 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-12-16 20:27:53,619 [salt.state       :300 ][INFO    ][13349] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-12-16 20:27:53,620 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:27:53.620521 duration_in_ms=96.583
2019-12-16 20:27:53,621 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:27:53.621736
2019-12-16 20:27:53,622 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-12-16 20:27:53,684 [salt.state       :300 ][INFO    ][13349] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-12-16 20:27:53,685 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:27:53.685081 duration_in_ms=63.345
2019-12-16 20:27:53,685 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:27:53.685618
2019-12-16 20:27:53,685 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-12-16 20:27:53,744 [salt.state       :300 ][INFO    ][13349] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-12-16 20:27:53,745 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:27:53.745000 duration_in_ms=59.382
2019-12-16 20:27:53,745 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 20:27:53.745562
2019-12-16 20:27:53,745 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-12-16 20:27:53,804 [salt.state       :300 ][INFO    ][13349] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-12-16 20:27:53,804 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 20:27:53.804815 duration_in_ms=59.253
2019-12-16 20:27:53,805 [salt.state       :1780][INFO    ][13349] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 20:27:53.805333
2019-12-16 20:27:53,805 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-12-16 20:27:53,858 [salt.state       :300 ][INFO    ][13349] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-12-16 20:27:53,858 [salt.state       :1951][INFO    ][13349] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 20:27:53.858666 duration_in_ms=53.333
2019-12-16 20:27:53,859 [salt.state       :1780][INFO    ][13349] Running state [/root/.pgpass] at time 20:27:53.858958
2019-12-16 20:27:53,859 [salt.state       :1813][INFO    ][13349] Executing state file.managed for [/root/.pgpass]
2019-12-16 20:27:53,906 [salt.state       :300 ][INFO    ][13349] File /root/.pgpass is in the correct state
2019-12-16 20:27:53,906 [salt.state       :1951][INFO    ][13349] Completed state [/root/.pgpass] at time 20:27:53.906586 duration_in_ms=47.628
2019-12-16 20:27:53,912 [salt.state       :1780][INFO    ][13349] Running state [maas-region syncdb --noinput] at time 20:27:53.912930
2019-12-16 20:27:53,913 [salt.state       :1813][INFO    ][13349] Executing state cmd.run for [maas-region syncdb --noinput]
2019-12-16 20:27:53,914 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-12-16 20:27:56,005 [salt.state       :300 ][INFO    ][13349] {'pid': 13402, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, maasserver, sites, auth, contenttypes, metadataserver, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-12-16 20:27:56,005 [salt.state       :1951][INFO    ][13349] Completed state [maas-region syncdb --noinput] at time 20:27:56.005742 duration_in_ms=2092.811
2019-12-16 20:27:56,006 [salt.state       :2022][WARNING ][13349] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-16 20:27:56,009 [salt.state       :1780][INFO    ][13349] Running state [maas-regiond] at time 20:27:56.009181
2019-12-16 20:27:56,009 [salt.state       :1813][INFO    ][13349] Executing state service.running for [maas-regiond]
2019-12-16 20:27:56,011 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:56,050 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-12-16 20:27:56,068 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-12-16 20:27:56,086 [salt.state       :300 ][INFO    ][13349] The service maas-regiond is already running
2019-12-16 20:27:56,087 [salt.state       :1951][INFO    ][13349] Completed state [maas-regiond] at time 20:27:56.086956 duration_in_ms=77.775
2019-12-16 20:27:56,089 [salt.state       :1780][INFO    ][13349] Running state [bind9] at time 20:27:56.089743
2019-12-16 20:27:56,090 [salt.state       :1813][INFO    ][13349] Executing state service.running for [bind9]
2019-12-16 20:27:56,091 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:56,111 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-12-16 20:27:56,129 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-12-16 20:27:56,147 [salt.state       :300 ][INFO    ][13349] The service bind9 is already running
2019-12-16 20:27:56,147 [salt.state       :1951][INFO    ][13349] Completed state [bind9] at time 20:27:56.147729 duration_in_ms=57.986
2019-12-16 20:27:56,150 [salt.state       :1780][INFO    ][13349] Running state [apache2] at time 20:27:56.150515
2019-12-16 20:27:56,151 [salt.state       :1813][INFO    ][13349] Executing state service.running for [apache2]
2019-12-16 20:27:56,152 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-12-16 20:27:56,171 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-12-16 20:27:56,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-12-16 20:27:56,211 [salt.state       :300 ][INFO    ][13349] The service apache2 is already running
2019-12-16 20:27:56,211 [salt.state       :1951][INFO    ][13349] Completed state [apache2] at time 20:27:56.211835 duration_in_ms=61.319
2019-12-16 20:27:56,214 [salt.state       :1780][INFO    ][13349] Running state [maasng.wait_for_http_code] at time 20:27:56.214561
2019-12-16 20:27:56,215 [salt.state       :1813][INFO    ][13349] Executing state module.run for [maasng.wait_for_http_code]
2019-12-16 20:27:56,215 [salt.utils.decorators:613 ][WARNING ][13349] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:27:56,354 [salt.state       :300 ][INFO    ][13349] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-12-16 20:27:56,354 [salt.state       :1951][INFO    ][13349] Completed state [maasng.wait_for_http_code] at time 20:27:56.354721 duration_in_ms=140.159
2019-12-16 20:27:56,356 [salt.state       :1780][INFO    ][13349] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:27:56.356128
2019-12-16 20:27:56,356 [salt.state       :1813][INFO    ][13349] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-12-16 20:27:56,357 [salt.state       :300 ][INFO    ][13349] /var/lib/maas/.setup_admin exists
2019-12-16 20:27:56,357 [salt.state       :1951][INFO    ][13349] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:27:56.357738 duration_in_ms=1.611
2019-12-16 20:27:56,358 [salt.state       :1780][INFO    ][13349] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:27:56.358879
2019-12-16 20:27:56,359 [salt.state       :1813][INFO    ][13349] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:27:56,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13349] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:27:57,918 [salt.state       :300 ][INFO    ][13349] {'pid': 13423, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:27:57,919 [salt.state       :1951][INFO    ][13349] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:27:57.919054 duration_in_ms=1560.174
2019-12-16 20:27:57,929 [salt.state       :1780][INFO    ][13349] Running state [maas_region_boot_source_resources_mirror] at time 20:27:57.928940
2019-12-16 20:27:57,929 [salt.state       :1813][INFO    ][13349] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-12-16 20:27:58,039 [salt.state       :300 ][INFO    ][13349] {'changes': {}}
2019-12-16 20:27:58,040 [salt.state       :1951][INFO    ][13349] Completed state [maas_region_boot_source_resources_mirror] at time 20:27:58.040311 duration_in_ms=111.371
2019-12-16 20:27:58,041 [salt.state       :1780][INFO    ][13349] Running state [maasng.boot_resources_import] at time 20:27:58.041462
2019-12-16 20:27:58,041 [salt.state       :1813][INFO    ][13349] Executing state module.run for [maasng.boot_resources_import]
2019-12-16 20:27:58,042 [salt.utils.decorators:613 ][WARNING ][13349] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:27:58,154 [salt.loaded.ext.module.maasng:1600][INFO    ][13349] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-12-16 20:28:03,222 [salt.loaded.ext.module.maasng:1600][INFO    ][13349] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-12-16 20:28:06,821 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202806806935
2019-12-16 20:28:06,845 [salt.minion      :1432][INFO    ][13448] Starting a new job with PID 13448
2019-12-16 20:28:06,870 [salt.minion      :1711][INFO    ][13448] Returning information for job: 20191216202806806935
2019-12-16 20:28:08,288 [salt.loaded.ext.module.maasng:1600][INFO    ][13349] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-12-16 20:28:13,402 [salt.state       :300 ][INFO    ][13349] {'ret': True}
2019-12-16 20:28:13,403 [salt.state       :1951][INFO    ][13349] Completed state [maasng.boot_resources_import] at time 20:28:13.402930 duration_in_ms=15361.468
2019-12-16 20:28:13,404 [salt.state       :1780][INFO    ][13349] Running state [maas_region_boot_sources_selection_bionic] at time 20:28:13.404215
2019-12-16 20:28:13,404 [salt.state       :1813][INFO    ][13349] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-12-16 20:28:13,612 [salt.state       :300 ][INFO    ][13349] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-12-16 20:28:13,612 [salt.state       :1951][INFO    ][13349] Completed state [maas_region_boot_sources_selection_bionic] at time 20:28:13.612414 duration_in_ms=208.199
2019-12-16 20:28:13,614 [salt.state       :1780][INFO    ][13349] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:28:13.613982
2019-12-16 20:28:13,614 [salt.state       :1813][INFO    ][13349] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-12-16 20:28:13,615 [salt.utils.decorators:613 ][WARNING ][13349] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:28:13,615 [salt.loaded.ext.module.maasng:1771][INFO    ][13349] boot-sources sync initiated for ALL Rack's
2019-12-16 20:28:14,518 [salt.state       :300 ][INFO    ][13349] {'ret': True}
2019-12-16 20:28:14,519 [salt.state       :1951][INFO    ][13349] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:28:14.519102 duration_in_ms=905.121
2019-12-16 20:28:14,520 [salt.state       :1780][INFO    ][13349] Running state [maas.process_maas_config] at time 20:28:14.520894
2019-12-16 20:28:14,521 [salt.state       :1813][INFO    ][13349] Executing state module.run for [maas.process_maas_config]
2019-12-16 20:28:14,521 [salt.utils.decorators:613 ][WARNING ][13349] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:28:14,522 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=enable_http_proxy value=True
2019-12-16 20:28:14,573 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=upstream_dns value=8.8.8.8
2019-12-16 20:28:17,553 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=commissioning_distro_series value=bionic
2019-12-16 20:28:17,626 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=default_osystem value=ubuntu
2019-12-16 20:28:17,683 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=active_discovery_interval value=600
2019-12-16 20:28:17,748 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=dnssec_validation value=no
2019-12-16 20:28:17,818 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=maas_name value=mas01
2019-12-16 20:28:17,876 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=network_discovery value=enabled
2019-12-16 20:28:17,978 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=enable_third_party_drivers value=True
2019-12-16 20:28:18,037 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=default_storage_layout value=lvm
2019-12-16 20:28:18,111 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=ntp_external_only value=True
2019-12-16 20:28:18,169 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=disk_erase_with_secure_erase value=False
2019-12-16 20:28:18,219 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=default_distro_series value=bionic
2019-12-16 20:28:18,273 [salt.loaded.ext.module.maas:92  ][INFO    ][13349] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-12-16 20:28:18,375 [salt.state       :300 ][INFO    ][13349] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-12-16 20:28:18,376 [salt.state       :1951][INFO    ][13349] Completed state [maas.process_maas_config] at time 20:28:18.376115 duration_in_ms=3855.218
2019-12-16 20:28:18,377 [salt.state       :1780][INFO    ][13349] Running state [pxe_admin] at time 20:28:18.377283
2019-12-16 20:28:18,377 [salt.state       :1813][INFO    ][13349] Executing state maasng.fabric_present for [pxe_admin]
2019-12-16 20:28:18,434 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'athkxf', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-16 20:28:18,494 [salt.loaded.ext.module.maasng:1008][WARNING ][13349] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-12-16 20:28:18,495 [salt.loaded.ext.module.maasng:1011][WARNING ][13349] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-12-16 20:28:18,561 [salt.state       :300 ][INFO    ][13349] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-12-16 20:28:18,561 [salt.state       :1951][INFO    ][13349] Completed state [pxe_admin] at time 20:28:18.561680 duration_in_ms=184.395
2019-12-16 20:28:18,562 [salt.state       :1780][INFO    ][13349] Running state [vlan 0] at time 20:28:18.562316
2019-12-16 20:28:18,562 [salt.state       :1813][INFO    ][13349] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-16 20:28:18,629 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'athkxf', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-16 20:28:18,750 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'athkxf', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-16 20:28:18,950 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'athkxf', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-16 20:28:19,028 [salt.state       :300 ][INFO    ][13349] {'new': 'Vlan untagged was updated'}
2019-12-16 20:28:19,029 [salt.state       :1951][INFO    ][13349] Completed state [vlan 0] at time 20:28:19.029094 duration_in_ms=466.777
2019-12-16 20:28:19,031 [salt.state       :1780][INFO    ][13349] Running state [192.168.11.0/24] at time 20:28:19.031102
2019-12-16 20:28:19,031 [salt.state       :1813][INFO    ][13349] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-12-16 20:28:19,249 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'athkxf', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-16 20:28:19,250 [salt.loaded.ext.module.maasng:1235][WARNING ][13349] Ignoring parameter vlan:0
2019-12-16 20:28:19,328 [salt.state       :300 ][INFO    ][13349] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-12-16 20:28:19,328 [salt.state       :1951][INFO    ][13349] Completed state [192.168.11.0/24] at time 20:28:19.328469 duration_in_ms=297.367
2019-12-16 20:28:19,329 [salt.state       :1780][INFO    ][13349] Running state [maas_create_iprange_1] at time 20:28:19.329566
2019-12-16 20:28:19,329 [salt.state       :1813][INFO    ][13349] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-12-16 20:28:19,384 [salt.state       :300 ][INFO    ][13349] Iprange maas_create_iprange_1 already exist.
2019-12-16 20:28:19,385 [salt.state       :1951][INFO    ][13349] Completed state [maas_create_iprange_1] at time 20:28:19.385119 duration_in_ms=55.554
2019-12-16 20:28:19,385 [salt.state       :1780][INFO    ][13349] Running state [vlan 0] at time 20:28:19.385442
2019-12-16 20:28:19,385 [salt.state       :1813][INFO    ][13349] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-16 20:28:19,464 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'class_type': None, 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'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'fabric': u'fabric-0'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, 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'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'fabric': u'fabric-1'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-12-16 20:28:19,583 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{u'class_type': None, 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'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'fabric': u'fabric-0'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, 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'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'fabric': u'fabric-1'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-12-16 20:28:19,788 [salt.loaded.ext.module.maasng:945 ][INFO    ][13349] [{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'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'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'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'fabric': u'fabric-1'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'athkxf', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-12-16 20:28:19,872 [salt.state       :300 ][INFO    ][13349] {'new': 'Vlan untagged was updated'}
2019-12-16 20:28:19,873 [salt.state       :1951][INFO    ][13349] Completed state [vlan 0] at time 20:28:19.873337 duration_in_ms=487.893
2019-12-16 20:28:19,874 [salt.state       :1780][INFO    ][13349] Running state [opnfv] at time 20:28:19.874328
2019-12-16 20:28:19,874 [salt.state       :1813][INFO    ][13349] Executing state maasng.sshkey_present for [opnfv]
2019-12-16 20:28:19,927 [salt.loaded.ext.module.maasng:1903][INFO    ][13349] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-12-16 20:28:19,928 [salt.state       :300 ][INFO    ][13349] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-12-16 20:28:19,928 [salt.state       :1951][INFO    ][13349] Completed state [opnfv] at time 20:28:19.928394 duration_in_ms=54.066
2019-12-16 20:28:19,932 [salt.minion      :1711][INFO    ][13349] Returning information for job: 20191216202751787775
2019-12-16 20:28:20,510 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216202820485027
2019-12-16 20:28:20,532 [salt.minion      :1432][INFO    ][13726] Starting a new job with PID 13726
2019-12-16 20:28:24,323 [salt.state       :915 ][INFO    ][13726] Loading fresh modules for state activity
2019-12-16 20:28:24,373 [salt.state       :1780][INFO    ][13726] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:28:24.373261
2019-12-16 20:28:24,373 [salt.state       :1813][INFO    ][13726] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:28:24,374 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13726] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:28:25,924 [salt.state       :300 ][INFO    ][13726] {'pid': 13761, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:28:25,925 [salt.state       :1951][INFO    ][13726] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:28:25.925443 duration_in_ms=1552.181
2019-12-16 20:28:25,928 [salt.state       :1780][INFO    ][13726] Running state [maas.process_machines] at time 20:28:25.928237
2019-12-16 20:28:25,928 [salt.state       :1813][INFO    ][13726] Executing state module.run for [maas.process_machines]
2019-12-16 20:28:25,929 [salt.utils.decorators:613 ][WARNING ][13726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:28:26,643 [salt.loaded.ext.module.maas:412 ][WARNING ][13726] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:28:26,644 [salt.loaded.ext.module.maas:92  ][INFO    ][13726] 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=btkh6x architecture=amd64/generic power_parameters_power_user=admin
2019-12-16 20:28:27,886 [salt.loaded.ext.module.maas:412 ][WARNING ][13726] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:28:27,887 [salt.loaded.ext.module.maas:92  ][INFO    ][13726] 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=xy3acp architecture=amd64/generic power_parameters_power_user=admin
2019-12-16 20:28:29,087 [salt.loaded.ext.module.maas:412 ][WARNING ][13726] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:28:29,088 [salt.loaded.ext.module.maas:92  ][INFO    ][13726] 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=mbdewb architecture=amd64/generic power_parameters_power_user=admin
2019-12-16 20:28:30,332 [salt.loaded.ext.module.maas:412 ][WARNING ][13726] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:28:30,333 [salt.loaded.ext.module.maas:92  ][INFO    ][13726] 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=7b8a77 architecture=amd64/generic power_parameters_power_user=admin
2019-12-16 20:28:31,554 [salt.loaded.ext.module.maas:412 ][WARNING ][13726] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-16 20:28:31,555 [salt.loaded.ext.module.maas:92  ][INFO    ][13726] 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=fwtg7n architecture=amd64/generic power_parameters_power_user=admin
2019-12-16 20:28:32,813 [salt.state       :300 ][INFO    ][13726] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-16 20:28:32,813 [salt.state       :1951][INFO    ][13726] Completed state [maas.process_machines] at time 20:28:32.813552 duration_in_ms=6885.314
2019-12-16 20:28:32,817 [salt.minion      :1711][INFO    ][13726] Returning information for job: 20191216202820485027
2019-12-16 20:29:06,131 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216202906118578
2019-12-16 20:29:06,154 [salt.minion      :1432][INFO    ][14008] Starting a new job with PID 14008
2019-12-16 20:29:09,888 [salt.state       :915 ][INFO    ][14008] Loading fresh modules for state activity
2019-12-16 20:29:09,980 [salt.state       :1780][INFO    ][14008] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:29:09.980116
2019-12-16 20:29:09,980 [salt.state       :1813][INFO    ][14008] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:29:09,982 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14008] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:29:11,480 [salt.state       :300 ][INFO    ][14008] {'pid': 14016, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:29:11,481 [salt.state       :1951][INFO    ][14008] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:29:11.480934 duration_in_ms=1500.819
2019-12-16 20:29:11,483 [salt.state       :1780][INFO    ][14008] Running state [maas.wait_for_machine_status] at time 20:29:11.483656
2019-12-16 20:29:11,484 [salt.state       :1813][INFO    ][14008] Executing state module.run for [maas.wait_for_machine_status]
2019-12-16 20:29:11,484 [salt.utils.decorators:613 ][WARNING ][14008] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:29:14,423 [salt.loaded.ext.module.maas:993 ][INFO    ][14008] Machine 7b8a77 mark broken
2019-12-16 20:29:14,896 [salt.loaded.ext.module.maas:996 ][INFO    ][14008] Machine 7b8a77 mark fixed
2019-12-16 20:29:15,878 [salt.loaded.ext.module.maas:684 ][INFO    ][14008] deploymachines hwe_kernel=ga-18.04 system_id=7b8a77 distro_series=bionic
2019-12-16 20:29:19,176 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.31933713s left)
2019-12-16 20:29:21,175 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202921162194
2019-12-16 20:29:21,199 [salt.minion      :1432][INFO    ][14093] Starting a new job with PID 14093
2019-12-16 20:29:21,225 [salt.minion      :1711][INFO    ][14093] Returning information for job: 20191216202921162194
2019-12-16 20:29:51,232 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216202951220102
2019-12-16 20:29:51,252 [salt.minion      :1432][INFO    ][14129] Starting a new job with PID 14129
2019-12-16 20:29:51,278 [salt.minion      :1711][INFO    ][14129] Returning information for job: 20191216202951220102
2019-12-16 20:29:52,503 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1458.99275708s left)
2019-12-16 20:30:21,338 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203021284864
2019-12-16 20:30:21,359 [salt.minion      :1432][INFO    ][14172] Starting a new job with PID 14172
2019-12-16 20:30:21,384 [salt.minion      :1711][INFO    ][14172] Returning information for job: 20191216203021284864
2019-12-16 20:30:26,138 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1425.35762501s left)
2019-12-16 20:30:51,387 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203051374367
2019-12-16 20:30:51,410 [salt.minion      :1432][INFO    ][14207] Starting a new job with PID 14207
2019-12-16 20:30:51,436 [salt.minion      :1711][INFO    ][14207] Returning information for job: 20191216203051374367
2019-12-16 20:30:59,362 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.13416195s left)
2019-12-16 20:31:21,430 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203121417355
2019-12-16 20:31:21,453 [salt.minion      :1432][INFO    ][14311] Starting a new job with PID 14311
2019-12-16 20:31:21,480 [salt.minion      :1711][INFO    ][14311] Returning information for job: 20191216203121417355
2019-12-16 20:31:32,909 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1358.58648992s left)
2019-12-16 20:31:51,490 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203151477962
2019-12-16 20:31:51,513 [salt.minion      :1432][INFO    ][14395] Starting a new job with PID 14395
2019-12-16 20:31:51,538 [salt.minion      :1711][INFO    ][14395] Returning information for job: 20191216203151477962
2019-12-16 20:32:06,304 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.19145799s left)
2019-12-16 20:32:21,542 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203221529402
2019-12-16 20:32:21,566 [salt.minion      :1432][INFO    ][14466] Starting a new job with PID 14466
2019-12-16 20:32:21,593 [salt.minion      :1711][INFO    ][14466] Returning information for job: 20191216203221529402
2019-12-16 20:32:40,069 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1291.42686605s left)
2019-12-16 20:32:51,615 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203251602205
2019-12-16 20:32:51,638 [salt.minion      :1432][INFO    ][14592] Starting a new job with PID 14592
2019-12-16 20:32:51,662 [salt.minion      :1711][INFO    ][14592] Returning information for job: 20191216203251602205
2019-12-16 20:33:13,148 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1258.34809804s left)
2019-12-16 20:33:21,679 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203321667147
2019-12-16 20:33:21,702 [salt.minion      :1432][INFO    ][14634] Starting a new job with PID 14634
2019-12-16 20:33:21,727 [salt.minion      :1711][INFO    ][14634] Returning information for job: 20191216203321667147
2019-12-16 20:33:46,496 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1224.9992981s left)
2019-12-16 20:33:51,754 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203351741450
2019-12-16 20:33:51,777 [salt.minion      :1432][INFO    ][14668] Starting a new job with PID 14668
2019-12-16 20:33:51,803 [salt.minion      :1711][INFO    ][14668] Returning information for job: 20191216203351741450
2019-12-16 20:34:19,528 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1191.96728206s left)
2019-12-16 20:34:21,831 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203421818626
2019-12-16 20:34:21,854 [salt.minion      :1432][INFO    ][14728] Starting a new job with PID 14728
2019-12-16 20:34:21,882 [salt.minion      :1711][INFO    ][14728] Returning information for job: 20191216203421818626
2019-12-16 20:34:51,915 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203451903232
2019-12-16 20:34:51,935 [salt.minion      :1432][INFO    ][14815] Starting a new job with PID 14815
2019-12-16 20:34:51,962 [salt.minion      :1711][INFO    ][14815] Returning information for job: 20191216203451903232
2019-12-16 20:34:53,014 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1158.48128891s left)
2019-12-16 20:35:21,994 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203521984805
2019-12-16 20:35:22,015 [salt.minion      :1432][INFO    ][14893] Starting a new job with PID 14893
2019-12-16 20:35:22,039 [salt.minion      :1711][INFO    ][14893] Returning information for job: 20191216203521984805
2019-12-16 20:35:26,827 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1124.66847801s left)
2019-12-16 20:35:52,088 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203552075681
2019-12-16 20:35:52,111 [salt.minion      :1432][INFO    ][14995] Starting a new job with PID 14995
2019-12-16 20:35:52,137 [salt.minion      :1711][INFO    ][14995] Returning information for job: 20191216203552075681
2019-12-16 20:36:00,485 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1091.01108313s left)
2019-12-16 20:36:22,188 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203622174278
2019-12-16 20:36:22,210 [salt.minion      :1432][INFO    ][15039] Starting a new job with PID 15039
2019-12-16 20:36:22,235 [salt.minion      :1711][INFO    ][15039] Returning information for job: 20191216203622174278
2019-12-16 20:36:33,543 [salt.loaded.ext.module.maas:1023][INFO    ][14008] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1057.9530549s left)
2019-12-16 20:36:52,293 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command saltutil.find_job with jid 20191216203652280262
2019-12-16 20:36:52,315 [salt.minion      :1432][INFO    ][15102] Starting a new job with PID 15102
2019-12-16 20:36:52,340 [salt.minion      :1711][INFO    ][15102] Returning information for job: 20191216203652280262
2019-12-16 20:37:06,948 [salt.state       :300 ][INFO    ][14008] {'ret': True}
2019-12-16 20:37:06,948 [salt.state       :1951][INFO    ][14008] Completed state [maas.wait_for_machine_status] at time 20:37:06.948673 duration_in_ms=475465.016
2019-12-16 20:37:06,957 [salt.minion      :1711][INFO    ][14008] Returning information for job: 20191216202906118578
2019-12-16 20:37:07,627 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216203707613315
2019-12-16 20:37:07,650 [salt.minion      :1432][INFO    ][15149] Starting a new job with PID 15149
2019-12-16 20:37:11,472 [salt.state       :915 ][INFO    ][15149] Loading fresh modules for state activity
2019-12-16 20:37:11,612 [salt.state       :1780][INFO    ][15149] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:11.612737
2019-12-16 20:37:11,613 [salt.state       :1813][INFO    ][15149] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:37:11,614 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15149] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:37:13,176 [salt.state       :300 ][INFO    ][15149] {'pid': 15157, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:37:13,177 [salt.state       :1951][INFO    ][15149] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:13.177794 duration_in_ms=1565.056
2019-12-16 20:37:13,181 [salt.state       :1780][INFO    ][15149] Running state [maas_machines_storage_cmp002_lvm] at time 20:37:13.181139
2019-12-16 20:37:13,181 [salt.state       :1813][INFO    ][15149] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-16 20:37:13,855 [salt.state       :300 ][INFO    ][15149] Machine cmp002 is not in Ready state.
2019-12-16 20:37:13,855 [salt.state       :1951][INFO    ][15149] Completed state [maas_machines_storage_cmp002_lvm] at time 20:37:13.855725 duration_in_ms=674.586
2019-12-16 20:37:13,856 [salt.state       :1780][INFO    ][15149] Running state [maas_machines_storage_cmp001_lvm] at time 20:37:13.856262
2019-12-16 20:37:13,856 [salt.state       :1813][INFO    ][15149] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-16 20:37:14,499 [salt.state       :300 ][INFO    ][15149] Machine cmp001 is not in Ready state.
2019-12-16 20:37:14,499 [salt.state       :1951][INFO    ][15149] Completed state [maas_machines_storage_cmp001_lvm] at time 20:37:14.499880 duration_in_ms=643.618
2019-12-16 20:37:14,504 [salt.minion      :1711][INFO    ][15149] Returning information for job: 20191216203707613315
2019-12-16 20:37:15,143 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216203715129988
2019-12-16 20:37:15,166 [salt.minion      :1432][INFO    ][15187] Starting a new job with PID 15187
2019-12-16 20:37:15,899 [salt.state       :915 ][INFO    ][15187] Loading fresh modules for state activity
2019-12-16 20:37:15,944 [salt.state       :1780][INFO    ][15187] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:15.944623
2019-12-16 20:37:15,944 [salt.state       :1813][INFO    ][15187] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:37:15,946 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15187] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:37:17,481 [salt.state       :300 ][INFO    ][15187] {'pid': 15196, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:37:17,482 [salt.state       :1951][INFO    ][15187] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:17.482782 duration_in_ms=1538.158
2019-12-16 20:37:17,485 [salt.state       :1780][INFO    ][15187] Running state [maas.deploy_machines] at time 20:37:17.485576
2019-12-16 20:37:17,486 [salt.state       :1813][INFO    ][15187] Executing state module.run for [maas.deploy_machines]
2019-12-16 20:37:17,487 [salt.utils.decorators:613 ][WARNING ][15187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:37:18,293 [salt.state       :300 ][INFO    ][15187] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-16 20:37:18,294 [salt.state       :1951][INFO    ][15187] Completed state [maas.deploy_machines] at time 20:37:18.294166 duration_in_ms=808.589
2019-12-16 20:37:18,297 [salt.minion      :1711][INFO    ][15187] Returning information for job: 20191216203715129988
2019-12-16 20:37:18,945 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command state.apply with jid 20191216203718932007
2019-12-16 20:37:18,967 [salt.minion      :1432][INFO    ][15205] Starting a new job with PID 15205
2019-12-16 20:37:19,700 [salt.state       :915 ][INFO    ][15205] Loading fresh modules for state activity
2019-12-16 20:37:19,790 [salt.state       :1780][INFO    ][15205] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:19.790216
2019-12-16 20:37:19,790 [salt.state       :1813][INFO    ][15205] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-16 20:37:19,792 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15205] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-16 20:37:21,310 [salt.state       :300 ][INFO    ][15205] {'pid': 15212, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-16 20:37:21,310 [salt.state       :1951][INFO    ][15205] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:21.310825 duration_in_ms=1520.609
2019-12-16 20:37:21,314 [salt.state       :1780][INFO    ][15205] Running state [maas.wait_for_machine_status] at time 20:37:21.314052
2019-12-16 20:37:21,314 [salt.state       :1813][INFO    ][15205] Executing state module.run for [maas.wait_for_machine_status]
2019-12-16 20:37:21,315 [salt.utils.decorators:613 ][WARNING ][15205] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-16 20:37:24,686 [salt.state       :300 ][INFO    ][15205] {'ret': True}
2019-12-16 20:37:24,687 [salt.state       :1951][INFO    ][15205] Completed state [maas.wait_for_machine_status] at time 20:37:24.686964 duration_in_ms=3372.91
2019-12-16 20:37:24,690 [salt.minion      :1711][INFO    ][15205] Returning information for job: 20191216203718932007
2019-12-16 21:06:13,801 [salt.utils.schedule:1377][INFO    ][7064] Running scheduled job: __mine_interval
2019-12-16 22:06:13,801 [salt.utils.schedule:1377][INFO    ][7064] Running scheduled job: __mine_interval
2019-12-16 22:09:46,942 [salt.minion      :1308][INFO    ][7064] User sudo_ubuntu Executing command cp.push_dir with jid 20191216220946930718
2019-12-16 22:09:46,964 [salt.minion      :1432][INFO    ][21845] Starting a new job with PID 21845
