2019-12-14 20:08:41,650 [salt.utils.decorators:613 ][WARNING ][2019] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:08:42,100 [salt.utils.decorators:613 ][WARNING ][2019] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:08:44,114 [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-14 20:09:11,705 [salt.state       :2022][WARNING ][2947] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-14 20:09:14,176 [salt.utils.decorators:613 ][WARNING ][2947] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:10:24,952 [salt.utils.decorators:613 ][WARNING ][2947] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:11:49,078 [salt.utils.decorators:613 ][WARNING ][2947] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:12:05,804 [salt.utils.decorators:613 ][WARNING ][2947] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:12:09,791 [salt.loaded.ext.module.maasng:1008][WARNING ][2947] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-12-14 20:12:09,791 [salt.loaded.ext.module.maasng:1011][WARNING ][2947] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-12-14 20:12:10,708 [salt.loaded.ext.module.maasng:1235][WARNING ][2947] Ignoring parameter vlan:0
2019-12-14 20:12:17,910 [salt.utils.decorators:613 ][WARNING ][9014] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:12:17,980 [salt.loaded.ext.module.maas:412 ][WARNING ][9014] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:12:19,346 [salt.loaded.ext.module.maas:412 ][WARNING ][9014] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:12:21,130 [salt.loaded.ext.module.maas:412 ][WARNING ][9014] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:12:22,269 [salt.loaded.ext.module.maas:412 ][WARNING ][9014] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:12:23,473 [salt.loaded.ext.module.maas:412 ][WARNING ][9014] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:12:26,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9643] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-14 20:12:26,403 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9643] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-12-14 20:12:26,425 [salt.utils.parsers:1051][WARNING ][324] Minion received a SIGTERM. Exiting.
2019-12-14 20:12:27,488 [salt.cli.daemons :293 ][INFO    ][9697] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-12-14 20:12:27,587 [salt.cli.daemons :82  ][INFO    ][9697] Starting up the Salt Minion
2019-12-14 20:12:27,588 [salt.utils.event :1017][INFO    ][9697] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-12-14 20:12:28,509 [salt.minion      :976 ][INFO    ][9697] Creating minion process manager
2019-12-14 20:12:29,949 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9697] Executing command ['date', '+%z'] in directory '/root'
2019-12-14 20:12:29,968 [salt.utils.schedule:568 ][INFO    ][9697] Updating job settings for scheduled job: __mine_interval
2019-12-14 20:12:29,969 [salt.minion      :1108][INFO    ][9697] Added mine.update to scheduler
2019-12-14 20:12:29,973 [salt.minion      :1975][INFO    ][9697] Minion is starting as user 'root'
2019-12-14 20:12:29,986 [salt.minion      :2336][INFO    ][9697] Minion is ready to receive requests!
2019-12-14 20:12:55,722 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214201255708413
2019-12-14 20:12:55,743 [salt.minion      :1432][INFO    ][9808] Starting a new job with PID 9808
2019-12-14 20:12:59,367 [salt.state       :915 ][INFO    ][9808] Loading fresh modules for state activity
2019-12-14 20:12:59,421 [salt.fileclient  :1219][INFO    ][9808] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-12-14 20:12:59,467 [salt.state       :1780][INFO    ][9808] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:12:59.467032
2019-12-14 20:12:59,467 [salt.state       :1813][INFO    ][9808] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:12:59,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9808] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:13:00,899 [salt.state       :300 ][INFO    ][9808] {'pid': 9817, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:13:00,899 [salt.state       :1951][INFO    ][9808] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:13:00.899683 duration_in_ms=1432.653
2019-12-14 20:13:00,901 [salt.state       :1780][INFO    ][9808] Running state [maas.wait_for_machine_status] at time 20:13:00.901227
2019-12-14 20:13:00,901 [salt.state       :1813][INFO    ][9808] Executing state module.run for [maas.wait_for_machine_status]
2019-12-14 20:13:00,901 [salt.utils.decorators:613 ][WARNING ][9808] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:13:01,843 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.06326699s left)
2019-12-14 20:13:10,766 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201310750732
2019-12-14 20:13:10,789 [salt.minion      :1432][INFO    ][9841] Starting a new job with PID 9841
2019-12-14 20:13:10,812 [salt.minion      :1711][INFO    ][9841] Returning information for job: 20191214201310750732
2019-12-14 20:13:32,924 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1467.98233795s left)
2019-12-14 20:13:40,822 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201340806993
2019-12-14 20:13:40,844 [salt.minion      :1432][INFO    ][9873] Starting a new job with PID 9873
2019-12-14 20:13:40,869 [salt.minion      :1711][INFO    ][9873] Returning information for job: 20191214201340806993
2019-12-14 20:14:04,133 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.77347493s left)
2019-12-14 20:14:10,895 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201410884090
2019-12-14 20:14:10,913 [salt.minion      :1432][INFO    ][10033] Starting a new job with PID 10033
2019-12-14 20:14:10,934 [salt.minion      :1711][INFO    ][10033] Returning information for job: 20191214201410884090
2019-12-14 20:14:35,457 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.44858098s left)
2019-12-14 20:14:40,931 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201440918079
2019-12-14 20:14:40,953 [salt.minion      :1432][INFO    ][10192] Starting a new job with PID 10192
2019-12-14 20:14:40,976 [salt.minion      :1711][INFO    ][10192] Returning information for job: 20191214201440918079
2019-12-14 20:15:06,832 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.07406807s left)
2019-12-14 20:15:10,987 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201510974334
2019-12-14 20:15:11,010 [salt.minion      :1432][INFO    ][10478] Starting a new job with PID 10478
2019-12-14 20:15:11,033 [salt.minion      :1711][INFO    ][10478] Returning information for job: 20191214201510974334
2019-12-14 20:15:38,284 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.62162399s left)
2019-12-14 20:15:41,052 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201541034346
2019-12-14 20:15:41,076 [salt.minion      :1432][INFO    ][10953] Starting a new job with PID 10953
2019-12-14 20:15:41,100 [salt.minion      :1711][INFO    ][10953] Returning information for job: 20191214201541034346
2019-12-14 20:16:11,111 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201611099233
2019-12-14 20:16:11,136 [salt.minion      :1432][INFO    ][11094] Starting a new job with PID 11094
2019-12-14 20:16:11,162 [salt.minion      :1711][INFO    ][11094] Returning information for job: 20191214201611099233
2019-12-14 20:16:11,296 [salt.loaded.ext.module.maas:1023][INFO    ][9808] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1309.61011195s left)
2019-12-14 20:16:41,173 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201641165908
2019-12-14 20:16:41,193 [salt.minion      :1432][INFO    ][11158] Starting a new job with PID 11158
2019-12-14 20:16:41,215 [salt.minion      :1711][INFO    ][11158] Returning information for job: 20191214201641165908
2019-12-14 20:16:44,723 [salt.state       :300 ][INFO    ][9808] {'ret': True}
2019-12-14 20:16:44,723 [salt.state       :1951][INFO    ][9808] Completed state [maas.wait_for_machine_status] at time 20:16:44.723847 duration_in_ms=223822.618
2019-12-14 20:16:44,728 [salt.minion      :1711][INFO    ][9808] Returning information for job: 20191214201255708413
2019-12-14 20:16:45,320 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214201645306598
2019-12-14 20:16:45,342 [salt.minion      :1432][INFO    ][11173] Starting a new job with PID 11173
2019-12-14 20:16:49,189 [salt.state       :915 ][INFO    ][11173] Loading fresh modules for state activity
2019-12-14 20:16:49,242 [salt.fileclient  :1219][INFO    ][11173] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-12-14 20:16:49,331 [salt.state       :1780][INFO    ][11173] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:49.331617
2019-12-14 20:16:49,331 [salt.state       :1813][INFO    ][11173] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:16:49,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11173] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:16:50,754 [salt.state       :300 ][INFO    ][11173] {'pid': 11180, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:16:50,755 [salt.state       :1951][INFO    ][11173] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:50.755678 duration_in_ms=1424.059
2019-12-14 20:16:50,759 [salt.state       :1780][INFO    ][11173] Running state [maas_machines_storage_cmp002_lvm] at time 20:16:50.758984
2019-12-14 20:16:50,759 [salt.state       :1813][INFO    ][11173] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-14 20:16:52,081 [salt.loaded.ext.module.maasng:610 ][INFO    ][11173] fcqg7t
2019-12-14 20:16:52,082 [salt.loaded.ext.module.maasng:626 ][INFO    ][11173] sda
2019-12-14 20:16:52,695 [salt.loaded.ext.module.maasng:361 ][INFO    ][11173] fcqg7t
2019-12-14 20:16:52,818 [salt.loaded.ext.module.maasng:367 ][INFO    ][11173] [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 4, u'filesystem': None, u'name': u'sda', u'system_id': u'fcqg7t', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'd45a6382-a1b9-48c9-a251-44bccf3982a5', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/partition/4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fcqg7t', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b297c44c-a63e-4453-a609-e2c0a076ba70', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 4, u'size': 2397992648704}], u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/'}, {u'size': 2397988454400, u'block_size': 4096, u'uuid': u'b8972173-14fb-4dfb-8f7c-e1a6449217b0', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 9, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'be95db65-3e54-4aa6-b64f-bef59256917a', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'fcqg7t', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'used_size': 2397988454400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/9/'}]
2019-12-14 20:16:52,819 [salt.loaded.ext.module.maasng:632 ][INFO    ][11173] vgroot
2019-12-14 20:16:52,819 [salt.loaded.ext.module.maasng:635 ][INFO    ][11173] lvroot
2019-12-14 20:16:52,820 [salt.loaded.ext.module.maasng:639 ][INFO    ][11173] 107374182400
2019-12-14 20:16:53,511 [salt.loaded.ext.module.maasng:645 ][INFO    ][11173] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 31, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'fcqg7t', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/interfaces/4/'}, u'min_hwe_kernel': u'ga-18.04', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 4, u'filesystem': None, u'name': u'sda', u'system_id': u'fcqg7t', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'e52ea617-6d6c-41f4-9164-51db076ba281', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fcqg7t', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7cc5ce43-c1fb-48df-9ac1-56426782a2af', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/'}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'status_action': u'modules-final', u'system_id': u'fcqg7t', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'uuid': u'215c63a5-ca36-49d0-85e8-60eb9756f782', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 11, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6fd98dbc-79af-4215-87ba-c08b75cb6253', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'fcqg7t', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/11/'}], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 4, u'filesystem': None, u'name': u'sda', u'system_id': u'fcqg7t', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'e52ea617-6d6c-41f4-9164-51db076ba281', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fcqg7t', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7cc5ce43-c1fb-48df-9ac1-56426782a2af', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/'}, {u'size': 107374182400, u'block_size': 4096, u'uuid': u'215c63a5-ca36-49d0-85e8-60eb9756f782', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 11, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6fd98dbc-79af-4215-87ba-c08b75cb6253', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'fcqg7t', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/11/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'on', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 4, u'filesystem': None, u'name': u'sda', u'system_id': u'fcqg7t', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'e52ea617-6d6c-41f4-9164-51db076ba281', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fcqg7t', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7cc5ce43-c1fb-48df-9ac1-56426782a2af', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/blockdevices/4/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'fcqg7t', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 31, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'fcqg7t', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'fcqg7t', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/interfaces/17/'}, {u'name': u'enp8s0', u'links': [{u'id': 33, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'fcqg7t', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/interfaces/18/'}, {u'name': u'enp7s0', u'links': [{u'id': 35, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'fcqg7t', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/fcqg7t/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'ip_addresses': [u'192.168.11.42'], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/fcqg7t/'}
2019-12-14 20:16:53,513 [salt.state       :300 ][INFO    ][11173] {'new': {'storage_layout': 'lvm'}}
2019-12-14 20:16:53,514 [salt.state       :1951][INFO    ][11173] Completed state [maas_machines_storage_cmp002_lvm] at time 20:16:53.514008 duration_in_ms=2755.024
2019-12-14 20:16:53,514 [salt.state       :1780][INFO    ][11173] Running state [maas_machines_storage_cmp001_lvm] at time 20:16:53.514475
2019-12-14 20:16:53,514 [salt.state       :1813][INFO    ][11173] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-14 20:16:55,035 [salt.loaded.ext.module.maasng:610 ][INFO    ][11173] eg3grw
2019-12-14 20:16:55,035 [salt.loaded.ext.module.maasng:626 ][INFO    ][11173] sda
2019-12-14 20:16:55,747 [salt.loaded.ext.module.maasng:361 ][INFO    ][11173] eg3grw
2019-12-14 20:16:55,888 [salt.loaded.ext.module.maasng:367 ][INFO    ][11173] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/2/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'filesystem': None, u'name': u'sda', u'system_id': u'eg3grw', u'partition_table_type': u'GPT', 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'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'7325630b-ee71-4835-a569-09f0c3a1c90c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eg3grw', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'6123ec0a-d31f-403d-8f4e-ead8a5272ce4', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/2/partition/2', u'type': u'partition', u'id': 2, u'device_id': 2}]}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/7/', u'uuid': u'b9373b26-9d5e-45bf-af4f-821f2888ddad', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'b29eb49a-15c8-45ce-827b-bdb8d9e28bc4', u'label': u'root'}, u'name': u'vgroot-lvroot', u'system_id': u'eg3grw', u'partition_table_type': None, 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'id': 7, u'serial': None, u'partitions': []}]
2019-12-14 20:16:55,888 [salt.loaded.ext.module.maasng:632 ][INFO    ][11173] vgroot
2019-12-14 20:16:55,889 [salt.loaded.ext.module.maasng:635 ][INFO    ][11173] lvroot
2019-12-14 20:16:55,889 [salt.loaded.ext.module.maasng:639 ][INFO    ][11173] 107374182400
2019-12-14 20:16:56,608 [salt.loaded.ext.module.maasng:645 ][INFO    ][11173] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'owner_data': {}, u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 23, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'eg3grw', u'effective_mtu': 1500, u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/interfaces/5/'}, u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'modules-final', u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'eg3grw', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'partition_table_type': None, u'available_size': 0, u'uuid': u'77771f9b-e3fb-4992-8eab-9324036bddce', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'eg3grw', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/12/', u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'31ad6c39-39bb-47c0-bce4-443d1a779292', u'fstype': u'ext4', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'name': u'vgroot-lvroot'}], u'blockdevice_set': [{u'size': 2397998940160, u'partition_table_type': u'GPT', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'd37538a7-f135-4721-8408-2f77beb9b86f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eg3grw', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'354d17c5-8c25-4d1a-8822-92920bc19ad2', u'fstype': u'lvm-pv', u'mount_options': None}, 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/eg3grw/blockdevices/2/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eg3grw', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/2/', 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'used_size': 2397998940160, u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, {u'size': 107374182400, u'partition_table_type': None, u'available_size': 0, u'uuid': u'77771f9b-e3fb-4992-8eab-9324036bddce', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'eg3grw', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/12/', u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'31ad6c39-39bb-47c0-bce4-443d1a779292', u'fstype': u'ext4', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'name': u'vgroot-lvroot'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'on', u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'size': 2397998940160, u'partition_table_type': u'GPT', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'd37538a7-f135-4721-8408-2f77beb9b86f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eg3grw', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'354d17c5-8c25-4d1a-8822-92920bc19ad2', u'fstype': u'lvm-pv', u'mount_options': None}, 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/eg3grw/blockdevices/2/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eg3grw', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/2/', 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'used_size': 2397998940160, u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'eg3grw', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'memory_test_status_name': u'Unknown', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 23, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'eg3grw', u'effective_mtu': 1500, u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/interfaces/5/'}, {u'name': u'enp7s0', 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'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'eg3grw', u'effective_mtu': 1500, u'id': 12, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/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'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'eg3grw', u'effective_mtu': 1500, u'id': 13, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/interfaces/13/'}, {u'name': u'enp9s0', 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'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'eg3grw', u'effective_mtu': 1500, u'id': 14, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/interfaces/14/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.04', u'commissioning_status_name': u'Passed', u'boot_disk': {u'size': 2397998940160, u'partition_table_type': u'GPT', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'd37538a7-f135-4721-8408-2f77beb9b86f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eg3grw', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'354d17c5-8c25-4d1a-8822-92920bc19ad2', u'fstype': u'lvm-pv', u'mount_options': None}, 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/eg3grw/blockdevices/2/partition/7'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eg3grw', u'resource_uri': u'/MAAS/api/2.0/nodes/eg3grw/blockdevices/2/', 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'used_size': 2397998940160, u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, u'ip_addresses': [u'192.168.11.38'], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/eg3grw/'}
2019-12-14 20:16:56,610 [salt.state       :300 ][INFO    ][11173] {'new': {'storage_layout': 'lvm'}}
2019-12-14 20:16:56,611 [salt.state       :1951][INFO    ][11173] Completed state [maas_machines_storage_cmp001_lvm] at time 20:16:56.610920 duration_in_ms=3096.444
2019-12-14 20:16:56,614 [salt.minion      :1711][INFO    ][11173] Returning information for job: 20191214201645306598
2019-12-14 20:16:57,215 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214201657198953
2019-12-14 20:16:57,235 [salt.minion      :1432][INFO    ][11234] Starting a new job with PID 11234
2019-12-14 20:16:57,917 [salt.state       :915 ][INFO    ][11234] Loading fresh modules for state activity
2019-12-14 20:16:57,947 [salt.fileclient  :1219][INFO    ][11234] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-12-14 20:16:57,973 [salt.state       :1780][INFO    ][11234] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:57.973214
2019-12-14 20:16:57,973 [salt.state       :1813][INFO    ][11234] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:16:57,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11234] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:16:59,328 [salt.state       :300 ][INFO    ][11234] {'pid': 11284, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:16:59,329 [salt.state       :1951][INFO    ][11234] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:59.329120 duration_in_ms=1355.905
2019-12-14 20:16:59,331 [salt.state       :1780][INFO    ][11234] Running state [maas.deploy_machines] at time 20:16:59.331585
2019-12-14 20:16:59,332 [salt.state       :1813][INFO    ][11234] Executing state module.run for [maas.deploy_machines]
2019-12-14 20:16:59,333 [salt.utils.decorators:613 ][WARNING ][11234] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:17:00,049 [salt.loaded.ext.module.maas:684 ][INFO    ][11234] deploymachines hwe_kernel=ga-18.04 system_id=fcqg7t distro_series=bionic
2019-12-14 20:17:02,757 [salt.loaded.ext.module.maas:684 ][INFO    ][11234] deploymachines hwe_kernel=ga-18.04 system_id=eg3grw distro_series=bionic
2019-12-14 20:17:05,392 [salt.loaded.ext.module.maas:684 ][INFO    ][11234] deploymachines hwe_kernel=ga-18.04 system_id=eds3wg distro_series=bionic
2019-12-14 20:17:07,539 [salt.loaded.ext.module.maas:684 ][INFO    ][11234] deploymachines hwe_kernel=ga-18.04 system_id=xyetex distro_series=bionic
2019-12-14 20:17:09,831 [salt.loaded.ext.module.maas:684 ][INFO    ][11234] deploymachines hwe_kernel=ga-18.04 system_id=s8msmd distro_series=bionic
2019-12-14 20:17:12,311 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201712298357
2019-12-14 20:17:12,333 [salt.minion      :1432][INFO    ][11556] Starting a new job with PID 11556
2019-12-14 20:17:12,357 [salt.minion      :1711][INFO    ][11556] Returning information for job: 20191214201712298357
2019-12-14 20:17:12,569 [salt.state       :300 ][INFO    ][11234] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-12-14 20:17:12,570 [salt.state       :1951][INFO    ][11234] Completed state [maas.deploy_machines] at time 20:17:12.569988 duration_in_ms=13238.402
2019-12-14 20:17:12,573 [salt.minion      :1711][INFO    ][11234] Returning information for job: 20191214201657198953
2019-12-14 20:17:13,167 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214201713155628
2019-12-14 20:17:13,186 [salt.minion      :1432][INFO    ][11571] Starting a new job with PID 11571
2019-12-14 20:17:16,967 [salt.state       :915 ][INFO    ][11571] Loading fresh modules for state activity
2019-12-14 20:17:17,016 [salt.fileclient  :1219][INFO    ][11571] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-12-14 20:17:17,067 [salt.state       :1780][INFO    ][11571] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:17:17.067467
2019-12-14 20:17:17,067 [salt.state       :1813][INFO    ][11571] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:17:17,070 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11571] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:17:18,494 [salt.state       :300 ][INFO    ][11571] {'pid': 11600, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:17:18,494 [salt.state       :1951][INFO    ][11571] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:17:18.494642 duration_in_ms=1427.177
2019-12-14 20:17:18,496 [salt.state       :1780][INFO    ][11571] Running state [maas.wait_for_machine_status] at time 20:17:18.496254
2019-12-14 20:17:18,496 [salt.state       :1813][INFO    ][11571] Executing state module.run for [maas.wait_for_machine_status]
2019-12-14 20:17:18,496 [salt.utils.decorators:613 ][WARNING ][11571] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:17:21,815 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.68591809s left)
2019-12-14 20:17:28,254 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201728240026
2019-12-14 20:17:28,277 [salt.minion      :1432][INFO    ][11614] Starting a new job with PID 11614
2019-12-14 20:17:28,301 [salt.minion      :1711][INFO    ][11614] Returning information for job: 20191214201728240026
2019-12-14 20:17:54,691 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.81033611s left)
2019-12-14 20:17:58,301 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201758288299
2019-12-14 20:17:58,324 [salt.minion      :1432][INFO    ][11650] Starting a new job with PID 11650
2019-12-14 20:17:58,346 [salt.minion      :1711][INFO    ][11650] Returning information for job: 20191214201758288299
2019-12-14 20:18:28,129 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.37228417s left)
2019-12-14 20:18:28,353 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201828340729
2019-12-14 20:18:28,376 [salt.minion      :1432][INFO    ][11689] Starting a new job with PID 11689
2019-12-14 20:18:28,399 [salt.minion      :1711][INFO    ][11689] Returning information for job: 20191214201828340729
2019-12-14 20:18:58,397 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201858385183
2019-12-14 20:18:58,417 [salt.minion      :1432][INFO    ][11808] Starting a new job with PID 11808
2019-12-14 20:18:58,439 [salt.minion      :1711][INFO    ][11808] Returning information for job: 20191214201858385183
2019-12-14 20:19:01,381 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.11985803s left)
2019-12-14 20:19:28,449 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201928436825
2019-12-14 20:19:28,471 [salt.minion      :1432][INFO    ][12223] Starting a new job with PID 12223
2019-12-14 20:19:28,494 [salt.minion      :1711][INFO    ][12223] Returning information for job: 20191214201928436825
2019-12-14 20:19:35,214 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.28683019s left)
2019-12-14 20:19:58,503 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214201958489595
2019-12-14 20:19:58,524 [salt.minion      :1432][INFO    ][12346] Starting a new job with PID 12346
2019-12-14 20:19:58,545 [salt.minion      :1711][INFO    ][12346] Returning information for job: 20191214201958489595
2019-12-14 20:20:08,439 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.06219101s left)
2019-12-14 20:20:28,569 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202028556282
2019-12-14 20:20:28,591 [salt.minion      :1432][INFO    ][12885] Starting a new job with PID 12885
2019-12-14 20:20:28,614 [salt.minion      :1711][INFO    ][12885] Returning information for job: 20191214202028556282
2019-12-14 20:20:42,115 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.38668418s left)
2019-12-14 20:20:58,620 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202058611572
2019-12-14 20:20:58,639 [salt.minion      :1432][INFO    ][12937] Starting a new job with PID 12937
2019-12-14 20:20:58,661 [salt.minion      :1711][INFO    ][12937] Returning information for job: 20191214202058611572
2019-12-14 20:21:15,511 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.98979402s left)
2019-12-14 20:21:28,680 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202128667642
2019-12-14 20:21:28,703 [salt.minion      :1432][INFO    ][12986] Starting a new job with PID 12986
2019-12-14 20:21:28,728 [salt.minion      :1711][INFO    ][12986] Returning information for job: 20191214202128667642
2019-12-14 20:21:48,877 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.623914s left)
2019-12-14 20:21:58,754 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202158740201
2019-12-14 20:21:58,777 [salt.minion      :1432][INFO    ][13078] Starting a new job with PID 13078
2019-12-14 20:21:58,800 [salt.minion      :1711][INFO    ][13078] Returning information for job: 20191214202158740201
2019-12-14 20:22:22,340 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.16161203s left)
2019-12-14 20:22:28,826 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202228813636
2019-12-14 20:22:28,849 [salt.minion      :1432][INFO    ][13315] Starting a new job with PID 13315
2019-12-14 20:22:28,874 [salt.minion      :1711][INFO    ][13315] Returning information for job: 20191214202228813636
2019-12-14 20:22:55,815 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.6862011s left)
2019-12-14 20:22:58,911 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202258899212
2019-12-14 20:22:58,933 [salt.minion      :1432][INFO    ][13476] Starting a new job with PID 13476
2019-12-14 20:22:58,958 [salt.minion      :1711][INFO    ][13476] Returning information for job: 20191214202258899212
2019-12-14 20:23:28,999 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202328986791
2019-12-14 20:23:29,020 [salt.minion      :1432][INFO    ][13874] Starting a new job with PID 13874
2019-12-14 20:23:29,043 [salt.minion      :1711][INFO    ][13874] Returning information for job: 20191214202328986791
2019-12-14 20:23:29,325 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.17595816s left)
2019-12-14 20:23:59,081 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202359068740
2019-12-14 20:23:59,104 [salt.minion      :1432][INFO    ][13906] Starting a new job with PID 13906
2019-12-14 20:23:59,128 [salt.minion      :1711][INFO    ][13906] Returning information for job: 20191214202359068740
2019-12-14 20:24:02,984 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.51732206s left)
2019-12-14 20:24:29,174 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202429161710
2019-12-14 20:24:29,197 [salt.minion      :1432][INFO    ][13995] Starting a new job with PID 13995
2019-12-14 20:24:29,221 [salt.minion      :1711][INFO    ][13995] Returning information for job: 20191214202429161710
2019-12-14 20:24:36,284 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.21721816s left)
2019-12-14 20:24:59,259 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202459246263
2019-12-14 20:24:59,283 [salt.minion      :1432][INFO    ][14172] Starting a new job with PID 14172
2019-12-14 20:24:59,305 [salt.minion      :1711][INFO    ][14172] Returning information for job: 20191214202459246263
2019-12-14 20:25:09,895 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1778.60633922s left)
2019-12-14 20:25:29,315 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202529302801
2019-12-14 20:25:29,338 [salt.minion      :1432][INFO    ][14459] Starting a new job with PID 14459
2019-12-14 20:25:29,361 [salt.minion      :1711][INFO    ][14459] Returning information for job: 20191214202529302801
2019-12-14 20:25:43,597 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1744.90444112s left)
2019-12-14 20:25:59,427 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202559414822
2019-12-14 20:25:59,450 [salt.minion      :1432][INFO    ][14548] Starting a new job with PID 14548
2019-12-14 20:25:59,473 [salt.minion      :1711][INFO    ][14548] Returning information for job: 20191214202559414822
2019-12-14 20:26:16,187 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1712.31391811s left)
2019-12-14 20:26:29,552 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202629537731
2019-12-14 20:26:29,575 [salt.minion      :1432][INFO    ][14668] Starting a new job with PID 14668
2019-12-14 20:26:29,599 [salt.minion      :1711][INFO    ][14668] Returning information for job: 20191214202629537731
2019-12-14 20:26:49,848 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1678.65286207s left)
2019-12-14 20:26:59,680 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202659667610
2019-12-14 20:26:59,704 [salt.minion      :1432][INFO    ][14702] Starting a new job with PID 14702
2019-12-14 20:26:59,728 [salt.minion      :1711][INFO    ][14702] Returning information for job: 20191214202659667610
2019-12-14 20:27:23,058 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1645.44350815s left)
2019-12-14 20:27:29,816 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202729803333
2019-12-14 20:27:29,838 [salt.minion      :1432][INFO    ][14741] Starting a new job with PID 14741
2019-12-14 20:27:29,862 [salt.minion      :1711][INFO    ][14741] Returning information for job: 20191214202729803333
2019-12-14 20:27:56,483 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1612.018327s left)
2019-12-14 20:27:59,960 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202759947360
2019-12-14 20:27:59,983 [salt.minion      :1432][INFO    ][14777] Starting a new job with PID 14777
2019-12-14 20:28:00,007 [salt.minion      :1711][INFO    ][14777] Returning information for job: 20191214202759947360
2019-12-14 20:28:29,646 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1578.85568714s left)
2019-12-14 20:28:30,107 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202830093529
2019-12-14 20:28:30,131 [salt.minion      :1432][INFO    ][14817] Starting a new job with PID 14817
2019-12-14 20:28:30,153 [salt.minion      :1711][INFO    ][14817] Returning information for job: 20191214202830093529
2019-12-14 20:29:00,265 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202900252150
2019-12-14 20:29:00,287 [salt.minion      :1432][INFO    ][14847] Starting a new job with PID 14847
2019-12-14 20:29:00,309 [salt.minion      :1711][INFO    ][14847] Returning information for job: 20191214202900252150
2019-12-14 20:29:03,064 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1545.4370842s left)
2019-12-14 20:29:30,428 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214202930416265
2019-12-14 20:29:30,448 [salt.minion      :1432][INFO    ][14996] Starting a new job with PID 14996
2019-12-14 20:29:30,470 [salt.minion      :1711][INFO    ][14996] Returning information for job: 20191214202930416265
2019-12-14 20:29:36,460 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1512.04091907s left)
2019-12-14 20:30:00,600 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203000587904
2019-12-14 20:30:00,622 [salt.minion      :1432][INFO    ][15036] Starting a new job with PID 15036
2019-12-14 20:30:00,644 [salt.minion      :1711][INFO    ][15036] Returning information for job: 20191214203000587904
2019-12-14 20:30:10,041 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1478.45994616s left)
2019-12-14 20:30:30,790 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203030777686
2019-12-14 20:30:30,812 [salt.minion      :1432][INFO    ][15081] Starting a new job with PID 15081
2019-12-14 20:30:30,837 [salt.minion      :1711][INFO    ][15081] Returning information for job: 20191214203030777686
2019-12-14 20:30:43,514 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1444.98757315s left)
2019-12-14 20:31:00,987 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203100974595
2019-12-14 20:31:01,010 [salt.minion      :1432][INFO    ][15117] Starting a new job with PID 15117
2019-12-14 20:31:01,034 [salt.minion      :1711][INFO    ][15117] Returning information for job: 20191214203100974595
2019-12-14 20:31:17,000 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1411.50094199s left)
2019-12-14 20:31:31,196 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203131184019
2019-12-14 20:31:31,220 [salt.minion      :1432][INFO    ][15156] Starting a new job with PID 15156
2019-12-14 20:31:31,245 [salt.minion      :1711][INFO    ][15156] Returning information for job: 20191214203131184019
2019-12-14 20:31:50,142 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1378.35897422s left)
2019-12-14 20:32:01,419 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203201405782
2019-12-14 20:32:01,441 [salt.minion      :1432][INFO    ][15190] Starting a new job with PID 15190
2019-12-14 20:32:01,465 [salt.minion      :1711][INFO    ][15190] Returning information for job: 20191214203201405782
2019-12-14 20:32:23,476 [salt.loaded.ext.module.maas:1023][INFO    ][11571] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1345.02558112s left)
2019-12-14 20:32:31,441 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203231428919
2019-12-14 20:32:31,463 [salt.minion      :1432][INFO    ][15231] Starting a new job with PID 15231
2019-12-14 20:32:31,487 [salt.minion      :1711][INFO    ][15231] Returning information for job: 20191214203231428919
2019-12-14 20:32:57,210 [salt.loaded.ext.module.maas:993 ][INFO    ][11571] Machine s8msmd mark broken
2019-12-14 20:32:57,979 [salt.loaded.ext.module.maas:996 ][INFO    ][11571] Machine s8msmd mark fixed
2019-12-14 20:32:59,229 [salt.loaded.ext.module.maas:684 ][INFO    ][11571] deploymachines hwe_kernel=ga-18.04 system_id=s8msmd distro_series=bionic
2019-12-14 20:33:01,479 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203301466664
2019-12-14 20:33:01,499 [salt.minion      :1432][INFO    ][15320] Starting a new job with PID 15320
2019-12-14 20:33:01,522 [salt.minion      :1711][INFO    ][15320] Returning information for job: 20191214203301466664
2019-12-14 20:33:01,923 [salt.loaded.ext.module.maas:160 ][ERROR   ][11571] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-12-14 20:33:01,924 [salt.state       :302 ][ERROR   ][11571] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-12-14 20:33:01,925 [salt.state       :1951][INFO    ][11571] Completed state [maas.wait_for_machine_status] at time 20:33:01.925250 duration_in_ms=943428.989
2019-12-14 20:33:01,931 [salt.minion      :1711][INFO    ][11571] Returning information for job: 20191214201713155628
2019-12-14 20:33:12,735 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command pillar.get with jid 20191214203312722154
2019-12-14 20:33:12,757 [salt.minion      :1432][INFO    ][15349] Starting a new job with PID 15349
2019-12-14 20:33:12,765 [salt.minion      :1711][INFO    ][15349] Returning information for job: 20191214203312722154
2019-12-14 20:33:13,281 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command service.status with jid 20191214203313268569
2019-12-14 20:33:13,302 [salt.minion      :1432][INFO    ][15354] Starting a new job with PID 15354
2019-12-14 20:33:13,696 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15354] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:13,736 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15354] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-12-14 20:33:13,753 [salt.minion      :1711][INFO    ][15354] Returning information for job: 20191214203313268569
2019-12-14 20:33:14,226 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214203314215249
2019-12-14 20:33:14,245 [salt.minion      :1432][INFO    ][15378] Starting a new job with PID 15378
2019-12-14 20:33:18,234 [salt.state       :915 ][INFO    ][15378] Loading fresh modules for state activity
2019-12-14 20:33:18,662 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'salt-minion --version' in directory '/root'
2019-12-14 20:33:18,981 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'salt-minion --version' in directory '/root'
2019-12-14 20:33:19,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'salt-minion --version' in directory '/root'
2019-12-14 20:33:20,193 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'salt-minion --version' in directory '/root'
2019-12-14 20:33:21,575 [salt.state       :1780][INFO    ][15378] Running state [salt-minion] at time 20:33:21.575441
2019-12-14 20:33:21,575 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [salt-minion]
2019-12-14 20:33:21,576 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-14 20:33:21,652 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:21,652 [salt.state       :1951][INFO    ][15378] Completed state [salt-minion] at time 20:33:21.652570 duration_in_ms=77.129
2019-12-14 20:33:21,652 [salt.state       :1780][INFO    ][15378] Running state [salt_minion_dependency_packages] at time 20:33:21.652820
2019-12-14 20:33:21,653 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-12-14 20:33:21,657 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:21,657 [salt.state       :1951][INFO    ][15378] Completed state [salt_minion_dependency_packages] at time 20:33:21.657931 duration_in_ms=5.111
2019-12-14 20:33:21,660 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/minion.d/minion.conf] at time 20:33:21.660391
2019-12-14 20:33:21,660 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-12-14 20:33:21,865 [salt.state       :300 ][INFO    ][15378] File /etc/salt/minion.d/minion.conf is in the correct state
2019-12-14 20:33:21,865 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/minion.d/minion.conf] at time 20:33:21.865562 duration_in_ms=205.171
2019-12-14 20:33:21,865 [salt.state       :1780][INFO    ][15378] Running state [python-netaddr] at time 20:33:21.865758
2019-12-14 20:33:21,865 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [python-netaddr]
2019-12-14 20:33:21,873 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:21,873 [salt.state       :1951][INFO    ][15378] Completed state [python-netaddr] at time 20:33:21.873514 duration_in_ms=7.755
2019-12-14 20:33:21,876 [salt.state       :1780][INFO    ][15378] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:33:21.876822
2019-12-14 20:33:21,877 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-12-14 20:33:21,888 [salt.state       :300 ][INFO    ][15378] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-12-14 20:33:21,888 [salt.state       :1951][INFO    ][15378] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:33:21.888542 duration_in_ms=11.72
2019-12-14 20:33:21,889 [salt.state       :1780][INFO    ][15378] Running state [salt-minion] at time 20:33:21.889380
2019-12-14 20:33:21,889 [salt.state       :1813][INFO    ][15378] Executing state service.running for [salt-minion]
2019-12-14 20:33:21,890 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:21,927 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-12-14 20:33:21,944 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-12-14 20:33:21,961 [salt.state       :300 ][INFO    ][15378] The service salt-minion is already running
2019-12-14 20:33:21,962 [salt.state       :1951][INFO    ][15378] Completed state [salt-minion] at time 20:33:21.962099 duration_in_ms=72.718
2019-12-14 20:33:21,963 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains.d] at time 20:33:21.963601
2019-12-14 20:33:21,963 [salt.state       :1813][INFO    ][15378] Executing state file.directory for [/etc/salt/grains.d]
2019-12-14 20:33:21,964 [salt.state       :300 ][INFO    ][15378] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-12-14 20:33:21,965 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains.d] at time 20:33:21.965118 duration_in_ms=1.517
2019-12-14 20:33:21,965 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains] at time 20:33:21.965795
2019-12-14 20:33:21,966 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/grains]
2019-12-14 20:33:21,966 [salt.state       :300 ][INFO    ][15378] File /etc/salt/grains exists with proper permissions. No changes made.
2019-12-14 20:33:21,966 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains] at time 20:33:21.966888 duration_in_ms=1.093
2019-12-14 20:33:21,967 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains.d/placeholder] at time 20:33:21.967343
2019-12-14 20:33:21,967 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-12-14 20:33:21,968 [salt.state       :300 ][INFO    ][15378] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-12-14 20:33:21,968 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains.d/placeholder] at time 20:33:21.968388 duration_in_ms=1.045
2019-12-14 20:33:21,968 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains.d/sphinx] at time 20:33:21.968867
2019-12-14 20:33:21,969 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-12-14 20:33:21,979 [salt.state       :300 ][INFO    ][15378] File /etc/salt/grains.d/sphinx is in the correct state
2019-12-14 20:33:21,979 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains.d/sphinx] at time 20:33:21.979270 duration_in_ms=10.402
2019-12-14 20:33:21,981 [salt.state       :1780][INFO    ][15378] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:33:21.981455
2019-12-14 20:33:21,981 [salt.state       :1813][INFO    ][15378] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-12-14 20:33:21,982 [salt.state       :300 ][INFO    ][15378] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-12-14 20:33:21,982 [salt.state       :1951][INFO    ][15378] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:33:21.982339 duration_in_ms=0.883
2019-12-14 20:33:21,982 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains.d/dns_records] at time 20:33:21.982822
2019-12-14 20:33:21,983 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-12-14 20:33:21,990 [salt.state       :300 ][INFO    ][15378] File /etc/salt/grains.d/dns_records is in the correct state
2019-12-14 20:33:21,991 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains.d/dns_records] at time 20:33:21.991158 duration_in_ms=8.336
2019-12-14 20:33:21,992 [salt.state       :1780][INFO    ][15378] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:33:21.992052
2019-12-14 20:33:21,992 [salt.state       :1813][INFO    ][15378] 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-14 20:33:21,992 [salt.state       :300 ][INFO    ][15378] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-12-14 20:33:21,992 [salt.state       :1951][INFO    ][15378] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:33:21.992935 duration_in_ms=0.884
2019-12-14 20:33:21,993 [salt.state       :1780][INFO    ][15378] Running state [/etc/salt/grains.d/salt] at time 20:33:21.993403
2019-12-14 20:33:21,993 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-12-14 20:33:22,003 [salt.state       :300 ][INFO    ][15378] File /etc/salt/grains.d/salt is in the correct state
2019-12-14 20:33:22,003 [salt.state       :1951][INFO    ][15378] Completed state [/etc/salt/grains.d/salt] at time 20:33:22.003301 duration_in_ms=9.898
2019-12-14 20:33:22,004 [salt.state       :1780][INFO    ][15378] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:33:22.004174
2019-12-14 20:33:22,004 [salt.state       :1813][INFO    ][15378] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-12-14 20:33:22,004 [salt.state       :300 ][INFO    ][15378] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-12-14 20:33:22,005 [salt.state       :1951][INFO    ][15378] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:33:22.005035 duration_in_ms=0.861
2019-12-14 20:33:22,006 [salt.state       :1780][INFO    ][15378] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:33:22.006843
2019-12-14 20:33:22,007 [salt.state       :1813][INFO    ][15378] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-12-14 20:33:22,007 [salt.state       :300 ][INFO    ][15378] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-12-14 20:33:22,007 [salt.state       :1951][INFO    ][15378] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:33:22.007735 duration_in_ms=0.891
2019-12-14 20:33:22,008 [salt.state       :1780][INFO    ][15378] Running state [mine.update] at time 20:33:22.008391
2019-12-14 20:33:22,008 [salt.state       :1813][INFO    ][15378] Executing state module.wait for [mine.update]
2019-12-14 20:33:22,009 [salt.state       :300 ][INFO    ][15378] No changes made for mine.update
2019-12-14 20:33:22,009 [salt.state       :1951][INFO    ][15378] Completed state [mine.update] at time 20:33:22.009207 duration_in_ms=0.816
2019-12-14 20:33:22,009 [salt.state       :1780][INFO    ][15378] Running state [ca-certificates] at time 20:33:22.009455
2019-12-14 20:33:22,009 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [ca-certificates]
2019-12-14 20:33:22,016 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:22,017 [salt.state       :1951][INFO    ][15378] Completed state [ca-certificates] at time 20:33:22.017033 duration_in_ms=7.578
2019-12-14 20:33:22,017 [salt.state       :1780][INFO    ][15378] Running state [update-ca-certificates] at time 20:33:22.017716
2019-12-14 20:33:22,018 [salt.state       :1813][INFO    ][15378] Executing state cmd.wait for [update-ca-certificates]
2019-12-14 20:33:22,018 [salt.state       :300 ][INFO    ][15378] No changes made for update-ca-certificates
2019-12-14 20:33:22,018 [salt.state       :1951][INFO    ][15378] Completed state [update-ca-certificates] at time 20:33:22.018525 duration_in_ms=0.808
2019-12-14 20:33:22,018 [salt.state       :1780][INFO    ][15378] Running state [iptables] at time 20:33:22.018773
2019-12-14 20:33:22,019 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [iptables]
2019-12-14 20:33:22,025 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:22,025 [salt.state       :1951][INFO    ][15378] Completed state [iptables] at time 20:33:22.025864 duration_in_ms=7.091
2019-12-14 20:33:22,026 [salt.state       :1780][INFO    ][15378] Running state [iptables-persistent] at time 20:33:22.026099
2019-12-14 20:33:22,026 [salt.state       :1813][INFO    ][15378] Executing state pkg.installed for [iptables-persistent]
2019-12-14 20:33:22,032 [salt.state       :300 ][INFO    ][15378] All specified packages are already installed
2019-12-14 20:33:22,032 [salt.state       :1951][INFO    ][15378] Completed state [iptables-persistent] at time 20:33:22.032879 duration_in_ms=6.78
2019-12-14 20:33:22,033 [salt.state       :1780][INFO    ][15378] Running state [iptables_modules_v4_load] at time 20:33:22.033826
2019-12-14 20:33:22,034 [salt.state       :1813][INFO    ][15378] Executing state kmod.present for [iptables_modules_v4_load]
2019-12-14 20:33:22,034 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'lsmod' in directory '/root'
2019-12-14 20:33:22,058 [salt.state       :300 ][INFO    ][15378] Kernel modules iptable_filter, ip_tables are already present
2019-12-14 20:33:22,058 [salt.state       :1951][INFO    ][15378] Completed state [iptables_modules_v4_load] at time 20:33:22.058632 duration_in_ms=24.806
2019-12-14 20:33:22,059 [salt.state       :1780][INFO    ][15378] Running state [/etc/iptables/rules.v4] at time 20:33:22.059286
2019-12-14 20:33:22,059 [salt.state       :1813][INFO    ][15378] Executing state file.managed for [/etc/iptables/rules.v4]
2019-12-14 20:33:22,146 [salt.state       :300 ][INFO    ][15378] File /etc/iptables/rules.v4 is in the correct state
2019-12-14 20:33:22,147 [salt.state       :1951][INFO    ][15378] Completed state [/etc/iptables/rules.v4] at time 20:33:22.147045 duration_in_ms=87.758
2019-12-14 20:33:22,147 [salt.state       :1780][INFO    ][15378] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:33:22.147948
2019-12-14 20:33:22,148 [salt.state       :1813][INFO    ][15378] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-12-14 20:33:22,148 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-12-14 20:33:22,169 [salt.state       :300 ][INFO    ][15378] onlyif execution failed
2019-12-14 20:33:22,169 [salt.state       :1951][INFO    ][15378] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:33:22.169896 duration_in_ms=21.947
2019-12-14 20:33:22,170 [salt.state       :1780][INFO    ][15378] Running state [netfilter-persistent] at time 20:33:22.170731
2019-12-14 20:33:22,171 [salt.state       :1813][INFO    ][15378] Executing state service.running for [netfilter-persistent]
2019-12-14 20:33:22,171 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:22,192 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-12-14 20:33:22,210 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-12-14 20:33:22,228 [salt.state       :300 ][INFO    ][15378] The service netfilter-persistent is already running
2019-12-14 20:33:22,228 [salt.state       :1951][INFO    ][15378] Completed state [netfilter-persistent] at time 20:33:22.228721 duration_in_ms=57.99
2019-12-14 20:33:22,229 [salt.state       :1780][INFO    ][15378] Running state [iptables_extra.remove_stale_tables] at time 20:33:22.229604
2019-12-14 20:33:22,229 [salt.state       :1813][INFO    ][15378] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-12-14 20:33:22,230 [salt.state       :300 ][INFO    ][15378] No changes made for iptables_extra.remove_stale_tables
2019-12-14 20:33:22,230 [salt.state       :1951][INFO    ][15378] Completed state [iptables_extra.remove_stale_tables] at time 20:33:22.230570 duration_in_ms=0.965
2019-12-14 20:33:22,230 [salt.state       :1780][INFO    ][15378] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:33:22.230835
2019-12-14 20:33:22,231 [salt.state       :1813][INFO    ][15378] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-12-14 20:33:22,231 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15378] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-12-14 20:33:22,247 [salt.state       :300 ][INFO    ][15378] onlyif execution failed
2019-12-14 20:33:22,247 [salt.state       :1951][INFO    ][15378] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:33:22.247761 duration_in_ms=16.926
2019-12-14 20:33:22,248 [salt.state       :1780][INFO    ][15378] Running state [/etc/iptables/rules.v6] at time 20:33:22.248774
2019-12-14 20:33:22,249 [salt.state       :1813][INFO    ][15378] Executing state file.absent for [/etc/iptables/rules.v6]
2019-12-14 20:33:22,249 [salt.state       :300 ][INFO    ][15378] File /etc/iptables/rules.v6 is not present
2019-12-14 20:33:22,249 [salt.state       :1951][INFO    ][15378] Completed state [/etc/iptables/rules.v6] at time 20:33:22.249869 duration_in_ms=1.096
2019-12-14 20:33:22,250 [salt.state       :1780][INFO    ][15378] Running state [iptables_extra.flush_all] at time 20:33:22.250601
2019-12-14 20:33:22,250 [salt.state       :1813][INFO    ][15378] Executing state module.wait for [iptables_extra.flush_all]
2019-12-14 20:33:22,251 [salt.state       :300 ][INFO    ][15378] No changes made for iptables_extra.flush_all
2019-12-14 20:33:22,251 [salt.state       :1951][INFO    ][15378] Completed state [iptables_extra.flush_all] at time 20:33:22.251456 duration_in_ms=0.855
2019-12-14 20:33:22,254 [salt.minion      :1711][INFO    ][15378] Returning information for job: 20191214203314215249
2019-12-14 20:33:22,853 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214203322839875
2019-12-14 20:33:22,875 [salt.minion      :1432][INFO    ][15466] Starting a new job with PID 15466
2019-12-14 20:33:23,648 [salt.state       :915 ][INFO    ][15466] Loading fresh modules for state activity
2019-12-14 20:33:24,267 [salt.state       :1780][INFO    ][15466] Running state [maas-rack-controller] at time 20:33:24.267605
2019-12-14 20:33:24,267 [salt.state       :1813][INFO    ][15466] Executing state pkg.installed for [maas-rack-controller]
2019-12-14 20:33:24,268 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15466] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-14 20:33:24,360 [salt.state       :300 ][INFO    ][15466] All specified packages are already installed
2019-12-14 20:33:24,360 [salt.state       :1951][INFO    ][15466] Completed state [maas-rack-controller] at time 20:33:24.360727 duration_in_ms=93.123
2019-12-14 20:33:24,361 [salt.state       :1780][INFO    ][15466] Running state [ipmitool] at time 20:33:24.361084
2019-12-14 20:33:24,361 [salt.state       :1813][INFO    ][15466] Executing state pkg.installed for [ipmitool]
2019-12-14 20:33:24,368 [salt.state       :300 ][INFO    ][15466] All specified packages are already installed
2019-12-14 20:33:24,368 [salt.state       :1951][INFO    ][15466] Completed state [ipmitool] at time 20:33:24.368267 duration_in_ms=7.182
2019-12-14 20:33:24,371 [salt.state       :1780][INFO    ][15466] Running state [/etc/maas/rackd.conf] at time 20:33:24.371313
2019-12-14 20:33:24,371 [salt.state       :1813][INFO    ][15466] Executing state file.line for [/etc/maas/rackd.conf]
2019-12-14 20:33:24,372 [salt.state       :300 ][INFO    ][15466] No changes needed to be made
2019-12-14 20:33:24,372 [salt.state       :1951][INFO    ][15466] Completed state [/etc/maas/rackd.conf] at time 20:33:24.372793 duration_in_ms=1.48
2019-12-14 20:33:24,373 [salt.state       :1780][INFO    ][15466] Running state [/etc/maas/rackd.conf] at time 20:33:24.373001
2019-12-14 20:33:24,373 [salt.state       :1813][INFO    ][15466] Executing state file.managed for [/etc/maas/rackd.conf]
2019-12-14 20:33:24,373 [salt.loaded.int.states.file:2298][WARNING ][15466] 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-14 20:33:24,373 [salt.state       :300 ][INFO    ][15466] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-12-14 20:33:24,374 [salt.state       :1951][INFO    ][15466] Completed state [/etc/maas/rackd.conf] at time 20:33:24.374135 duration_in_ms=1.134
2019-12-14 20:33:24,374 [salt.state       :1780][INFO    ][15466] Running state [maas-rackd] at time 20:33:24.374953
2019-12-14 20:33:24,375 [salt.state       :1813][INFO    ][15466] Executing state service.running for [maas-rackd]
2019-12-14 20:33:24,375 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15466] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:24,409 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15466] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-12-14 20:33:24,426 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15466] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-12-14 20:33:24,442 [salt.state       :300 ][INFO    ][15466] The service maas-rackd is already running
2019-12-14 20:33:24,443 [salt.state       :1951][INFO    ][15466] Completed state [maas-rackd] at time 20:33:24.443051 duration_in_ms=68.097
2019-12-14 20:33:24,444 [salt.minion      :1711][INFO    ][15466] Returning information for job: 20191214203322839875
2019-12-14 20:33:24,982 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214203324970641
2019-12-14 20:33:25,002 [salt.minion      :1432][INFO    ][15489] Starting a new job with PID 15489
2019-12-14 20:33:25,765 [salt.state       :915 ][INFO    ][15489] Loading fresh modules for state activity
2019-12-14 20:33:26,465 [salt.state       :1780][INFO    ][15489] Running state [maas-region-controller] at time 20:33:26.465020
2019-12-14 20:33:26,465 [salt.state       :1813][INFO    ][15489] Executing state pkg.installed for [maas-region-controller]
2019-12-14 20:33:26,465 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-14 20:33:26,552 [salt.state       :300 ][INFO    ][15489] All specified packages are already installed
2019-12-14 20:33:26,553 [salt.state       :1951][INFO    ][15489] Completed state [maas-region-controller] at time 20:33:26.553249 duration_in_ms=88.229
2019-12-14 20:33:26,553 [salt.state       :1780][INFO    ][15489] Running state [python-oauth] at time 20:33:26.553529
2019-12-14 20:33:26,553 [salt.state       :1813][INFO    ][15489] Executing state pkg.installed for [python-oauth]
2019-12-14 20:33:26,560 [salt.state       :300 ][INFO    ][15489] All specified packages are already installed
2019-12-14 20:33:26,560 [salt.state       :1951][INFO    ][15489] Completed state [python-oauth] at time 20:33:26.560228 duration_in_ms=6.698
2019-12-14 20:33:26,563 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/regiond.conf] at time 20:33:26.563240
2019-12-14 20:33:26,563 [salt.state       :1813][INFO    ][15489] Executing state file.replace for [/etc/maas/regiond.conf]
2019-12-14 20:33:26,608 [salt.state       :300 ][INFO    ][15489] No changes needed to be made
2019-12-14 20:33:26,609 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/regiond.conf] at time 20:33:26.609153 duration_in_ms=45.912
2019-12-14 20:33:26,609 [salt.state       :1780][INFO    ][15489] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:33:26.609730
2019-12-14 20:33:26,610 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-12-14 20:33:26,680 [salt.state       :300 ][INFO    ][15489] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-12-14 20:33:26,680 [salt.state       :1951][INFO    ][15489] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:33:26.680355 duration_in_ms=70.624
2019-12-14 20:33:26,680 [salt.state       :1780][INFO    ][15489] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:33:26.680932
2019-12-14 20:33:26,681 [salt.state       :1813][INFO    ][15489] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-14 20:33:26,699 [salt.state       :300 ][INFO    ][15489] No changes needed to be made
2019-12-14 20:33:26,699 [salt.state       :1951][INFO    ][15489] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:33:26.699652 duration_in_ms=18.719
2019-12-14 20:33:26,700 [salt.state       :1780][INFO    ][15489] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:33:26.700185
2019-12-14 20:33:26,700 [salt.state       :1813][INFO    ][15489] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-14 20:33:26,723 [salt.state       :300 ][INFO    ][15489] No changes needed to be made
2019-12-14 20:33:26,723 [salt.state       :1951][INFO    ][15489] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:33:26.723527 duration_in_ms=23.341
2019-12-14 20:33:26,724 [salt.state       :1780][INFO    ][15489] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:33:26.724078
2019-12-14 20:33:26,724 [salt.state       :1813][INFO    ][15489] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-12-14 20:33:26,747 [salt.state       :300 ][INFO    ][15489] No changes needed to be made
2019-12-14 20:33:26,747 [salt.state       :1951][INFO    ][15489] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:33:26.747892 duration_in_ms=23.814
2019-12-14 20:33:26,748 [salt.state       :1780][INFO    ][15489] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:33:26.748369
2019-12-14 20:33:26,748 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-12-14 20:33:26,760 [salt.state       :300 ][INFO    ][15489] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-12-14 20:33:26,760 [salt.state       :1951][INFO    ][15489] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:33:26.760306 duration_in_ms=11.937
2019-12-14 20:33:26,761 [salt.state       :1780][INFO    ][15489] Running state [a2enmod headers] at time 20:33:26.761463
2019-12-14 20:33:26,761 [salt.state       :1813][INFO    ][15489] Executing state cmd.run for [a2enmod headers]
2019-12-14 20:33:26,762 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command 'a2enmod headers' in directory '/root'
2019-12-14 20:33:26,826 [salt.state       :300 ][INFO    ][15489] {'pid': 15508, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-12-14 20:33:26,826 [salt.state       :1951][INFO    ][15489] Completed state [a2enmod headers] at time 20:33:26.826604 duration_in_ms=65.141
2019-12-14 20:33:26,827 [salt.state       :1780][INFO    ][15489] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:33:26.827027
2019-12-14 20:33:26,827 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-12-14 20:33:26,847 [salt.state       :300 ][INFO    ][15489] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-12-14 20:33:26,848 [salt.state       :1951][INFO    ][15489] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:33:26.847965 duration_in_ms=20.937
2019-12-14 20:33:26,848 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:33:26.848871
2019-12-14 20:33:26,849 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-12-14 20:33:26,919 [salt.state       :300 ][INFO    ][15489] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-12-14 20:33:26,920 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:33:26.920336 duration_in_ms=71.464
2019-12-14 20:33:26,921 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:33:26.921263
2019-12-14 20:33:26,921 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-12-14 20:33:26,991 [salt.state       :300 ][INFO    ][15489] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-12-14 20:33:26,992 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:33:26.992039 duration_in_ms=70.776
2019-12-14 20:33:26,992 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:33:26.992698
2019-12-14 20:33:26,993 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-12-14 20:33:27,051 [salt.state       :300 ][INFO    ][15489] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-12-14 20:33:27,051 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:33:27.051776 duration_in_ms=59.077
2019-12-14 20:33:27,052 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 20:33:27.052316
2019-12-14 20:33:27,052 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-12-14 20:33:27,105 [salt.state       :300 ][INFO    ][15489] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-12-14 20:33:27,105 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 20:33:27.105523 duration_in_ms=53.207
2019-12-14 20:33:27,106 [salt.state       :1780][INFO    ][15489] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 20:33:27.106029
2019-12-14 20:33:27,106 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-12-14 20:33:27,153 [salt.state       :300 ][INFO    ][15489] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-12-14 20:33:27,153 [salt.state       :1951][INFO    ][15489] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 20:33:27.153498 duration_in_ms=47.469
2019-12-14 20:33:27,153 [salt.state       :1780][INFO    ][15489] Running state [/root/.pgpass] at time 20:33:27.153761
2019-12-14 20:33:27,154 [salt.state       :1813][INFO    ][15489] Executing state file.managed for [/root/.pgpass]
2019-12-14 20:33:27,195 [salt.state       :300 ][INFO    ][15489] File /root/.pgpass is in the correct state
2019-12-14 20:33:27,195 [salt.state       :1951][INFO    ][15489] Completed state [/root/.pgpass] at time 20:33:27.195360 duration_in_ms=41.598
2019-12-14 20:33:27,199 [salt.state       :1780][INFO    ][15489] Running state [maas-region syncdb --noinput] at time 20:33:27.199837
2019-12-14 20:33:27,200 [salt.state       :1813][INFO    ][15489] Executing state cmd.run for [maas-region syncdb --noinput]
2019-12-14 20:33:27,200 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-12-14 20:33:29,228 [salt.state       :300 ][INFO    ][15489] {'pid': 15525, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: metadataserver, sessions, auth, piston3, sites, contenttypes, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-12-14 20:33:29,229 [salt.state       :1951][INFO    ][15489] Completed state [maas-region syncdb --noinput] at time 20:33:29.229194 duration_in_ms=2029.357
2019-12-14 20:33:29,229 [salt.state       :2022][WARNING ][15489] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-14 20:33:29,230 [salt.state       :1780][INFO    ][15489] Running state [maas-regiond] at time 20:33:29.230535
2019-12-14 20:33:29,230 [salt.state       :1813][INFO    ][15489] Executing state service.running for [maas-regiond]
2019-12-14 20:33:29,231 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:29,266 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-12-14 20:33:29,283 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-12-14 20:33:29,300 [salt.state       :300 ][INFO    ][15489] The service maas-regiond is already running
2019-12-14 20:33:29,300 [salt.state       :1951][INFO    ][15489] Completed state [maas-regiond] at time 20:33:29.300433 duration_in_ms=69.898
2019-12-14 20:33:29,301 [salt.state       :1780][INFO    ][15489] Running state [bind9] at time 20:33:29.301786
2019-12-14 20:33:29,302 [salt.state       :1813][INFO    ][15489] Executing state service.running for [bind9]
2019-12-14 20:33:29,302 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:29,320 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-12-14 20:33:29,336 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-12-14 20:33:29,353 [salt.state       :300 ][INFO    ][15489] The service bind9 is already running
2019-12-14 20:33:29,353 [salt.state       :1951][INFO    ][15489] Completed state [bind9] at time 20:33:29.353538 duration_in_ms=51.752
2019-12-14 20:33:29,355 [salt.state       :1780][INFO    ][15489] Running state [apache2] at time 20:33:29.355087
2019-12-14 20:33:29,355 [salt.state       :1813][INFO    ][15489] Executing state service.running for [apache2]
2019-12-14 20:33:29,356 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-12-14 20:33:29,374 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-12-14 20:33:29,390 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-12-14 20:33:29,411 [salt.state       :300 ][INFO    ][15489] The service apache2 is already running
2019-12-14 20:33:29,412 [salt.state       :1951][INFO    ][15489] Completed state [apache2] at time 20:33:29.412054 duration_in_ms=56.966
2019-12-14 20:33:29,413 [salt.state       :1780][INFO    ][15489] Running state [maasng.wait_for_http_code] at time 20:33:29.413568
2019-12-14 20:33:29,413 [salt.state       :1813][INFO    ][15489] Executing state module.run for [maasng.wait_for_http_code]
2019-12-14 20:33:29,414 [salt.utils.decorators:613 ][WARNING ][15489] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:33:29,537 [salt.state       :300 ][INFO    ][15489] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-12-14 20:33:29,537 [salt.state       :1951][INFO    ][15489] Completed state [maasng.wait_for_http_code] at time 20:33:29.537881 duration_in_ms=124.311
2019-12-14 20:33:29,539 [salt.state       :1780][INFO    ][15489] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:33:29.539307
2019-12-14 20:33:29,539 [salt.state       :1813][INFO    ][15489] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-12-14 20:33:29,540 [salt.state       :300 ][INFO    ][15489] /var/lib/maas/.setup_admin exists
2019-12-14 20:33:29,541 [salt.state       :1951][INFO    ][15489] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:33:29.540919 duration_in_ms=1.613
2019-12-14 20:33:29,542 [salt.state       :1780][INFO    ][15489] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:29.542029
2019-12-14 20:33:29,542 [salt.state       :1813][INFO    ][15489] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:33:29,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15489] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:33:31,119 [salt.state       :300 ][INFO    ][15489] {'pid': 15546, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:33:31,120 [salt.state       :1951][INFO    ][15489] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:31.119912 duration_in_ms=1577.881
2019-12-14 20:33:31,132 [salt.state       :1780][INFO    ][15489] Running state [maas_region_boot_source_resources_mirror] at time 20:33:31.132242
2019-12-14 20:33:31,132 [salt.state       :1813][INFO    ][15489] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-12-14 20:33:31,258 [salt.state       :300 ][INFO    ][15489] {'changes': {}}
2019-12-14 20:33:31,258 [salt.state       :1951][INFO    ][15489] Completed state [maas_region_boot_source_resources_mirror] at time 20:33:31.258529 duration_in_ms=126.288
2019-12-14 20:33:31,259 [salt.state       :1780][INFO    ][15489] Running state [maasng.boot_resources_import] at time 20:33:31.259590
2019-12-14 20:33:31,260 [salt.state       :1813][INFO    ][15489] Executing state module.run for [maasng.boot_resources_import]
2019-12-14 20:33:31,260 [salt.utils.decorators:613 ][WARNING ][15489] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:33:31,385 [salt.loaded.ext.module.maasng:1600][INFO    ][15489] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-12-14 20:33:36,441 [salt.loaded.ext.module.maasng:1600][INFO    ][15489] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-12-14 20:33:40,040 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203340028336
2019-12-14 20:33:40,064 [salt.minion      :1432][INFO    ][15574] Starting a new job with PID 15574
2019-12-14 20:33:40,089 [salt.minion      :1711][INFO    ][15574] Returning information for job: 20191214203340028336
2019-12-14 20:33:41,506 [salt.loaded.ext.module.maasng:1600][INFO    ][15489] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-12-14 20:33:46,621 [salt.state       :300 ][INFO    ][15489] {'ret': True}
2019-12-14 20:33:46,622 [salt.state       :1951][INFO    ][15489] Completed state [maasng.boot_resources_import] at time 20:33:46.622139 duration_in_ms=15362.549
2019-12-14 20:33:46,623 [salt.state       :1780][INFO    ][15489] Running state [maas_region_boot_sources_selection_bionic] at time 20:33:46.623181
2019-12-14 20:33:46,623 [salt.state       :1813][INFO    ][15489] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-12-14 20:33:46,812 [salt.state       :300 ][INFO    ][15489] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-12-14 20:33:46,813 [salt.state       :1951][INFO    ][15489] Completed state [maas_region_boot_sources_selection_bionic] at time 20:33:46.812951 duration_in_ms=189.77
2019-12-14 20:33:46,814 [salt.state       :1780][INFO    ][15489] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:33:46.814185
2019-12-14 20:33:46,814 [salt.state       :1813][INFO    ][15489] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-12-14 20:33:46,815 [salt.utils.decorators:613 ][WARNING ][15489] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:33:46,815 [salt.loaded.ext.module.maasng:1771][INFO    ][15489] boot-sources sync initiated for ALL Rack's
2019-12-14 20:33:47,782 [salt.state       :300 ][INFO    ][15489] {'ret': True}
2019-12-14 20:33:47,783 [salt.state       :1951][INFO    ][15489] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:33:47.783401 duration_in_ms=969.215
2019-12-14 20:33:47,785 [salt.state       :1780][INFO    ][15489] Running state [maas.process_maas_config] at time 20:33:47.785641
2019-12-14 20:33:47,786 [salt.state       :1813][INFO    ][15489] Executing state module.run for [maas.process_maas_config]
2019-12-14 20:33:47,786 [salt.utils.decorators:613 ][WARNING ][15489] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:33:47,787 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=enable_http_proxy value=True
2019-12-14 20:33:47,856 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=upstream_dns value=8.8.8.8
2019-12-14 20:33:47,914 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=commissioning_distro_series value=bionic
2019-12-14 20:33:50,938 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=default_osystem value=ubuntu
2019-12-14 20:33:51,009 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=active_discovery_interval value=600
2019-12-14 20:33:51,057 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=dnssec_validation value=no
2019-12-14 20:33:51,106 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=maas_name value=mas01
2019-12-14 20:33:51,159 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=network_discovery value=enabled
2019-12-14 20:33:51,261 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=enable_third_party_drivers value=True
2019-12-14 20:33:51,316 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=default_storage_layout value=lvm
2019-12-14 20:33:51,384 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=ntp_external_only value=True
2019-12-14 20:33:51,443 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=disk_erase_with_secure_erase value=False
2019-12-14 20:33:51,510 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=default_distro_series value=bionic
2019-12-14 20:33:51,574 [salt.loaded.ext.module.maas:92  ][INFO    ][15489] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-12-14 20:33:51,658 [salt.state       :300 ][INFO    ][15489] {'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-14 20:33:51,658 [salt.state       :1951][INFO    ][15489] Completed state [maas.process_maas_config] at time 20:33:51.658866 duration_in_ms=3873.225
2019-12-14 20:33:51,659 [salt.state       :1780][INFO    ][15489] Running state [pxe_admin] at time 20:33:51.659579
2019-12-14 20:33:51,659 [salt.state       :1813][INFO    ][15489] Executing state maasng.fabric_present for [pxe_admin]
2019-12-14 20:33:51,736 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-12-14 20:33:51,812 [salt.loaded.ext.module.maasng:1008][WARNING ][15489] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-12-14 20:33:51,812 [salt.loaded.ext.module.maasng:1011][WARNING ][15489] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-12-14 20:33:52,070 [salt.state       :300 ][INFO    ][15489] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-12-14 20:33:52,070 [salt.state       :1951][INFO    ][15489] Completed state [pxe_admin] at time 20:33:52.070776 duration_in_ms=411.196
2019-12-14 20:33:52,071 [salt.state       :1780][INFO    ][15489] Running state [vlan 0] at time 20:33:52.071221
2019-12-14 20:33:52,071 [salt.state       :1813][INFO    ][15489] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-14 20:33:52,141 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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-14 20:33:52,268 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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-14 20:33:52,568 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', 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-14 20:33:52,665 [salt.state       :300 ][INFO    ][15489] {'new': 'Vlan untagged was updated'}
2019-12-14 20:33:52,665 [salt.state       :1951][INFO    ][15489] Completed state [vlan 0] at time 20:33:52.665740 duration_in_ms=594.517
2019-12-14 20:33:52,667 [salt.state       :1780][INFO    ][15489] Running state [192.168.11.0/24] at time 20:33:52.667447
2019-12-14 20:33:52,668 [salt.state       :1813][INFO    ][15489] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-12-14 20:33:52,885 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', 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-14 20:33:52,886 [salt.loaded.ext.module.maasng:1235][WARNING ][15489] Ignoring parameter vlan:0
2019-12-14 20:33:52,957 [salt.state       :300 ][INFO    ][15489] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-12-14 20:33:52,958 [salt.state       :1951][INFO    ][15489] Completed state [192.168.11.0/24] at time 20:33:52.958125 duration_in_ms=290.679
2019-12-14 20:33:52,959 [salt.state       :1780][INFO    ][15489] Running state [maas_create_iprange_1] at time 20:33:52.958996
2019-12-14 20:33:52,959 [salt.state       :1813][INFO    ][15489] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-12-14 20:33:53,017 [salt.state       :300 ][INFO    ][15489] Iprange maas_create_iprange_1 already exist.
2019-12-14 20:33:53,017 [salt.state       :1951][INFO    ][15489] Completed state [maas_create_iprange_1] at time 20:33:53.017655 duration_in_ms=58.658
2019-12-14 20:33:53,017 [salt.state       :1780][INFO    ][15489] Running state [vlan 0] at time 20:33:53.017929
2019-12-14 20:33:53,018 [salt.state       :1813][INFO    ][15489] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-14 20:33:53,106 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-12-14 20:33:53,231 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4wtfcq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-12-14 20:33:53,496 [salt.loaded.ext.module.maasng:945 ][INFO    ][15489] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4wtfcq', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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-14 20:33:53,606 [salt.state       :300 ][INFO    ][15489] {'new': 'Vlan untagged was updated'}
2019-12-14 20:33:53,606 [salt.state       :1951][INFO    ][15489] Completed state [vlan 0] at time 20:33:53.606768 duration_in_ms=588.838
2019-12-14 20:33:53,607 [salt.state       :1780][INFO    ][15489] Running state [opnfv] at time 20:33:53.607739
2019-12-14 20:33:53,608 [salt.state       :1813][INFO    ][15489] Executing state maasng.sshkey_present for [opnfv]
2019-12-14 20:33:53,665 [salt.loaded.ext.module.maasng:1903][INFO    ][15489] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-12-14 20:33:53,665 [salt.state       :300 ][INFO    ][15489] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-12-14 20:33:53,666 [salt.state       :1951][INFO    ][15489] Completed state [opnfv] at time 20:33:53.666255 duration_in_ms=58.516
2019-12-14 20:33:53,670 [salt.minion      :1711][INFO    ][15489] Returning information for job: 20191214203324970641
2019-12-14 20:33:54,223 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214203354211872
2019-12-14 20:33:54,241 [salt.minion      :1432][INFO    ][15838] Starting a new job with PID 15838
2019-12-14 20:33:57,975 [salt.state       :915 ][INFO    ][15838] Loading fresh modules for state activity
2019-12-14 20:33:58,071 [salt.state       :1780][INFO    ][15838] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:58.071304
2019-12-14 20:33:58,071 [salt.state       :1813][INFO    ][15838] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:33:58,074 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15838] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:33:59,512 [salt.state       :300 ][INFO    ][15838] {'pid': 15883, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:33:59,513 [salt.state       :1951][INFO    ][15838] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:59.513289 duration_in_ms=1441.987
2019-12-14 20:33:59,514 [salt.state       :1780][INFO    ][15838] Running state [maas.process_machines] at time 20:33:59.514499
2019-12-14 20:33:59,514 [salt.state       :1813][INFO    ][15838] Executing state module.run for [maas.process_machines]
2019-12-14 20:33:59,515 [salt.utils.decorators:613 ][WARNING ][15838] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:34:00,213 [salt.loaded.ext.module.maas:412 ][WARNING ][15838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:34:00,214 [salt.loaded.ext.module.maas:92  ][INFO    ][15838] 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=fcqg7t architecture=amd64/generic power_parameters_power_user=admin
2019-12-14 20:34:01,418 [salt.loaded.ext.module.maas:412 ][WARNING ][15838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:34:01,419 [salt.loaded.ext.module.maas:92  ][INFO    ][15838] 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=eg3grw architecture=amd64/generic power_parameters_power_user=admin
2019-12-14 20:34:02,646 [salt.loaded.ext.module.maas:412 ][WARNING ][15838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:34:02,647 [salt.loaded.ext.module.maas:92  ][INFO    ][15838] 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=eds3wg architecture=amd64/generic power_parameters_power_user=admin
2019-12-14 20:34:03,813 [salt.loaded.ext.module.maas:412 ][WARNING ][15838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:34:03,814 [salt.loaded.ext.module.maas:92  ][INFO    ][15838] 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=xyetex architecture=amd64/generic power_parameters_power_user=admin
2019-12-14 20:34:05,029 [salt.loaded.ext.module.maas:412 ][WARNING ][15838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-14 20:34:05,029 [salt.loaded.ext.module.maas:92  ][INFO    ][15838] 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=s8msmd architecture=amd64/generic power_parameters_power_user=admin
2019-12-14 20:34:06,059 [salt.state       :300 ][INFO    ][15838] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-14 20:34:06,060 [salt.state       :1951][INFO    ][15838] Completed state [maas.process_machines] at time 20:34:06.060308 duration_in_ms=6545.805
2019-12-14 20:34:06,063 [salt.minion      :1711][INFO    ][15838] Returning information for job: 20191214203354211872
2019-12-14 20:34:39,274 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214203439261587
2019-12-14 20:34:39,294 [salt.minion      :1432][INFO    ][16135] Starting a new job with PID 16135
2019-12-14 20:34:43,003 [salt.state       :915 ][INFO    ][16135] Loading fresh modules for state activity
2019-12-14 20:34:43,074 [salt.state       :1780][INFO    ][16135] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:34:43.074542
2019-12-14 20:34:43,074 [salt.state       :1813][INFO    ][16135] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:34:43,076 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16135] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:34:44,644 [salt.state       :300 ][INFO    ][16135] {'pid': 16142, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:34:44,645 [salt.state       :1951][INFO    ][16135] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:34:44.645380 duration_in_ms=1570.839
2019-12-14 20:34:44,646 [salt.state       :1780][INFO    ][16135] Running state [maas.wait_for_machine_status] at time 20:34:44.646920
2019-12-14 20:34:44,647 [salt.state       :1813][INFO    ][16135] Executing state module.run for [maas.wait_for_machine_status]
2019-12-14 20:34:44,647 [salt.utils.decorators:613 ][WARNING ][16135] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:34:48,263 [salt.loaded.ext.module.maas:993 ][INFO    ][16135] Machine s8msmd mark broken
2019-12-14 20:34:48,880 [salt.loaded.ext.module.maas:996 ][INFO    ][16135] Machine s8msmd mark fixed
2019-12-14 20:34:50,106 [salt.loaded.ext.module.maas:684 ][INFO    ][16135] deploymachines hwe_kernel=ga-18.04 system_id=s8msmd distro_series=bionic
2019-12-14 20:34:52,295 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1492.356529s left)
2019-12-14 20:34:54,356 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203454310804
2019-12-14 20:34:54,376 [salt.minion      :1432][INFO    ][16212] Starting a new job with PID 16212
2019-12-14 20:34:54,393 [salt.minion      :1711][INFO    ][16212] Returning information for job: 20191214203454310804
2019-12-14 20:35:24,401 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203524388343
2019-12-14 20:35:24,420 [salt.minion      :1432][INFO    ][16277] Starting a new job with PID 16277
2019-12-14 20:35:24,445 [salt.minion      :1711][INFO    ][16277] Returning information for job: 20191214203524388343
2019-12-14 20:35:25,795 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1458.85676599s left)
2019-12-14 20:35:54,488 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203554477985
2019-12-14 20:35:54,506 [salt.minion      :1432][INFO    ][16293] Starting a new job with PID 16293
2019-12-14 20:35:54,526 [salt.minion      :1711][INFO    ][16293] Returning information for job: 20191214203554477985
2019-12-14 20:35:58,731 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1425.92075896s left)
2019-12-14 20:36:24,528 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203624513447
2019-12-14 20:36:24,550 [salt.minion      :1432][INFO    ][16349] Starting a new job with PID 16349
2019-12-14 20:36:24,576 [salt.minion      :1711][INFO    ][16349] Returning information for job: 20191214203624513447
2019-12-14 20:36:31,526 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1393.12553501s left)
2019-12-14 20:36:54,581 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203654568205
2019-12-14 20:36:54,603 [salt.minion      :1432][INFO    ][16428] Starting a new job with PID 16428
2019-12-14 20:36:54,629 [salt.minion      :1711][INFO    ][16428] Returning information for job: 20191214203654568205
2019-12-14 20:37:05,061 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.59072781s left)
2019-12-14 20:37:24,634 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203724621653
2019-12-14 20:37:24,657 [salt.minion      :1432][INFO    ][16611] Starting a new job with PID 16611
2019-12-14 20:37:24,682 [salt.minion      :1711][INFO    ][16611] Returning information for job: 20191214203724621653
2019-12-14 20:37:38,628 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1326.02362299s left)
2019-12-14 20:37:54,689 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203754676891
2019-12-14 20:37:54,713 [salt.minion      :1432][INFO    ][16630] Starting a new job with PID 16630
2019-12-14 20:37:54,739 [salt.minion      :1711][INFO    ][16630] Returning information for job: 20191214203754676891
2019-12-14 20:38:12,371 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1292.28079295s left)
2019-12-14 20:38:24,759 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203824745431
2019-12-14 20:38:24,781 [salt.minion      :1432][INFO    ][16727] Starting a new job with PID 16727
2019-12-14 20:38:24,807 [salt.minion      :1711][INFO    ][16727] Returning information for job: 20191214203824745431
2019-12-14 20:38:46,228 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1258.42376995s left)
2019-12-14 20:38:54,824 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203854811208
2019-12-14 20:38:54,847 [salt.minion      :1432][INFO    ][16751] Starting a new job with PID 16751
2019-12-14 20:38:54,872 [salt.minion      :1711][INFO    ][16751] Returning information for job: 20191214203854811208
2019-12-14 20:39:19,919 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1224.7321918s left)
2019-12-14 20:39:24,893 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203924880772
2019-12-14 20:39:24,916 [salt.minion      :1432][INFO    ][16843] Starting a new job with PID 16843
2019-12-14 20:39:24,943 [salt.minion      :1711][INFO    ][16843] Returning information for job: 20191214203924880772
2019-12-14 20:39:53,363 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.28837395s left)
2019-12-14 20:39:54,968 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214203954955398
2019-12-14 20:39:54,991 [salt.minion      :1432][INFO    ][16870] Starting a new job with PID 16870
2019-12-14 20:39:55,017 [salt.minion      :1711][INFO    ][16870] Returning information for job: 20191214203954955398
2019-12-14 20:40:25,041 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214204025029671
2019-12-14 20:40:25,064 [salt.minion      :1432][INFO    ][17028] Starting a new job with PID 17028
2019-12-14 20:40:25,087 [salt.minion      :1711][INFO    ][17028] Returning information for job: 20191214204025029671
2019-12-14 20:40:26,698 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1157.95334482s left)
2019-12-14 20:40:55,123 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214204055110295
2019-12-14 20:40:55,147 [salt.minion      :1432][INFO    ][17047] Starting a new job with PID 17047
2019-12-14 20:40:55,173 [salt.minion      :1711][INFO    ][17047] Returning information for job: 20191214204055110295
2019-12-14 20:41:00,315 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.33611488s left)
2019-12-14 20:41:25,215 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214204125202235
2019-12-14 20:41:25,238 [salt.minion      :1432][INFO    ][17129] Starting a new job with PID 17129
2019-12-14 20:41:25,265 [salt.minion      :1711][INFO    ][17129] Returning information for job: 20191214204125202235
2019-12-14 20:41:34,147 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1090.50434589s left)
2019-12-14 20:41:55,311 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214204155299051
2019-12-14 20:41:55,334 [salt.minion      :1432][INFO    ][17150] Starting a new job with PID 17150
2019-12-14 20:41:55,359 [salt.minion      :1711][INFO    ][17150] Returning information for job: 20191214204155299051
2019-12-14 20:42:07,463 [salt.loaded.ext.module.maas:1023][INFO    ][16135] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1057.18879795s left)
2019-12-14 20:42:25,418 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command saltutil.find_job with jid 20191214204225403957
2019-12-14 20:42:25,442 [salt.minion      :1432][INFO    ][17240] Starting a new job with PID 17240
2019-12-14 20:42:25,470 [salt.minion      :1711][INFO    ][17240] Returning information for job: 20191214204225403957
2019-12-14 20:42:41,061 [salt.state       :300 ][INFO    ][16135] {'ret': True}
2019-12-14 20:42:41,062 [salt.state       :1951][INFO    ][16135] Completed state [maas.wait_for_machine_status] at time 20:42:41.062211 duration_in_ms=476415.289
2019-12-14 20:42:41,066 [salt.minion      :1711][INFO    ][16135] Returning information for job: 20191214203439261587
2019-12-14 20:42:41,727 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214204241714151
2019-12-14 20:42:41,749 [salt.minion      :1432][INFO    ][17267] Starting a new job with PID 17267
2019-12-14 20:42:45,517 [salt.state       :915 ][INFO    ][17267] Loading fresh modules for state activity
2019-12-14 20:42:45,596 [salt.state       :1780][INFO    ][17267] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:45.596692
2019-12-14 20:42:45,596 [salt.state       :1813][INFO    ][17267] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:42:45,598 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17267] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:42:47,163 [salt.state       :300 ][INFO    ][17267] {'pid': 17277, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:42:47,164 [salt.state       :1951][INFO    ][17267] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:47.164622 duration_in_ms=1567.927
2019-12-14 20:42:47,167 [salt.state       :1780][INFO    ][17267] Running state [maas_machines_storage_cmp002_lvm] at time 20:42:47.167842
2019-12-14 20:42:47,168 [salt.state       :1813][INFO    ][17267] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-14 20:42:47,895 [salt.state       :300 ][INFO    ][17267] Machine cmp002 is not in Ready state.
2019-12-14 20:42:47,896 [salt.state       :1951][INFO    ][17267] Completed state [maas_machines_storage_cmp002_lvm] at time 20:42:47.896165 duration_in_ms=728.322
2019-12-14 20:42:47,896 [salt.state       :1780][INFO    ][17267] Running state [maas_machines_storage_cmp001_lvm] at time 20:42:47.896751
2019-12-14 20:42:47,897 [salt.state       :1813][INFO    ][17267] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-14 20:42:48,642 [salt.state       :300 ][INFO    ][17267] Machine cmp001 is not in Ready state.
2019-12-14 20:42:48,642 [salt.state       :1951][INFO    ][17267] Completed state [maas_machines_storage_cmp001_lvm] at time 20:42:48.642466 duration_in_ms=745.713
2019-12-14 20:42:48,646 [salt.minion      :1711][INFO    ][17267] Returning information for job: 20191214204241714151
2019-12-14 20:42:49,262 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214204249248641
2019-12-14 20:42:49,285 [salt.minion      :1432][INFO    ][17287] Starting a new job with PID 17287
2019-12-14 20:42:50,039 [salt.state       :915 ][INFO    ][17287] Loading fresh modules for state activity
2019-12-14 20:42:50,128 [salt.state       :1780][INFO    ][17287] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:50.128039
2019-12-14 20:42:50,128 [salt.state       :1813][INFO    ][17287] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:42:50,131 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17287] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:42:51,738 [salt.state       :300 ][INFO    ][17287] {'pid': 17294, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:42:51,739 [salt.state       :1951][INFO    ][17287] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:51.738894 duration_in_ms=1610.853
2019-12-14 20:42:51,741 [salt.state       :1780][INFO    ][17287] Running state [maas.deploy_machines] at time 20:42:51.741762
2019-12-14 20:42:51,742 [salt.state       :1813][INFO    ][17287] Executing state module.run for [maas.deploy_machines]
2019-12-14 20:42:51,743 [salt.utils.decorators:613 ][WARNING ][17287] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:42:52,447 [salt.state       :300 ][INFO    ][17287] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-14 20:42:52,447 [salt.state       :1951][INFO    ][17287] Completed state [maas.deploy_machines] at time 20:42:52.447655 duration_in_ms=705.892
2019-12-14 20:42:52,451 [salt.minion      :1711][INFO    ][17287] Returning information for job: 20191214204249248641
2019-12-14 20:42:53,082 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command state.apply with jid 20191214204253073014
2019-12-14 20:42:53,103 [salt.minion      :1432][INFO    ][17310] Starting a new job with PID 17310
2019-12-14 20:42:53,981 [salt.state       :915 ][INFO    ][17310] Loading fresh modules for state activity
2019-12-14 20:42:54,066 [salt.state       :1780][INFO    ][17310] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:54.066837
2019-12-14 20:42:54,067 [salt.state       :1813][INFO    ][17310] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-14 20:42:54,069 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17310] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-14 20:42:55,413 [salt.state       :300 ][INFO    ][17310] {'pid': 17317, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-14 20:42:55,414 [salt.state       :1951][INFO    ][17310] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:42:55.414408 duration_in_ms=1347.571
2019-12-14 20:42:55,417 [salt.state       :1780][INFO    ][17310] Running state [maas.wait_for_machine_status] at time 20:42:55.417796
2019-12-14 20:42:55,418 [salt.state       :1813][INFO    ][17310] Executing state module.run for [maas.wait_for_machine_status]
2019-12-14 20:42:55,419 [salt.utils.decorators:613 ][WARNING ][17310] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-14 20:42:58,466 [salt.state       :300 ][INFO    ][17310] {'ret': True}
2019-12-14 20:42:58,466 [salt.state       :1951][INFO    ][17310] Completed state [maas.wait_for_machine_status] at time 20:42:58.466693 duration_in_ms=3048.895
2019-12-14 20:42:58,470 [salt.minion      :1711][INFO    ][17310] Returning information for job: 20191214204253073014
2019-12-14 21:12:30,988 [salt.utils.schedule:1377][INFO    ][9697] Running scheduled job: __mine_interval
2019-12-14 22:11:18,547 [salt.minion      :1308][INFO    ][9697] User sudo_ubuntu Executing command cp.push_dir with jid 20191214221118540902
2019-12-14 22:11:18,571 [salt.minion      :1432][INFO    ][23625] Starting a new job with PID 23625
