2019-11-16 05:11:45,267 [salt.utils.decorators:613 ][WARNING ][2036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:11:45,855 [salt.utils.decorators:613 ][WARNING ][2036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:11:47,980 [salt.loaded.int.states.file:2298][WARNING ][2429] 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-11-16 05:12:15,389 [salt.state       :2022][WARNING ][3070] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-16 05:12:17,802 [salt.utils.decorators:613 ][WARNING ][3070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:13:16,764 [salt.utils.decorators:613 ][WARNING ][3070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:14:31,296 [salt.utils.decorators:613 ][WARNING ][3070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:14:47,862 [salt.utils.decorators:613 ][WARNING ][3070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:14:51,502 [salt.loaded.ext.module.maasng:1008][WARNING ][3070] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-11-16 05:14:51,503 [salt.loaded.ext.module.maasng:1011][WARNING ][3070] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-11-16 05:14:52,216 [salt.loaded.ext.module.maasng:1235][WARNING ][3070] Ignoring parameter vlan:0
2019-11-16 05:14:53,235 [salt.utils.decorators:613 ][WARNING ][3070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:14:55,182 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8584] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-16 05:14:55,212 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8584] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-16 05:14:55,232 [salt.utils.parsers:1051][WARNING ][322] Minion received a SIGTERM. Exiting.
2019-11-16 05:14:56,200 [salt.cli.daemons :293 ][INFO    ][8652] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-11-16 05:14:56,285 [salt.cli.daemons :82  ][INFO    ][8652] Starting up the Salt Minion
2019-11-16 05:14:56,285 [salt.utils.event :1017][INFO    ][8652] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-11-16 05:14:57,207 [salt.minion      :976 ][INFO    ][8652] Creating minion process manager
2019-11-16 05:14:58,500 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][8652] Executing command ['date', '+%z'] in directory '/root'
2019-11-16 05:14:58,517 [salt.utils.schedule:568 ][INFO    ][8652] Updating job settings for scheduled job: __mine_interval
2019-11-16 05:14:58,518 [salt.minion      :1108][INFO    ][8652] Added mine.update to scheduler
2019-11-16 05:14:58,522 [salt.minion      :1975][INFO    ][8652] Minion is starting as user 'root'
2019-11-16 05:14:58,531 [salt.minion      :2336][INFO    ][8652] Minion is ready to receive requests!
2019-11-16 05:14:58,938 [salt.utils.decorators:613 ][WARNING ][8599] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:14:59,012 [salt.loaded.ext.module.maas:412 ][WARNING ][8599] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:15:00,506 [salt.loaded.ext.module.maas:412 ][WARNING ][8599] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:15:02,992 [salt.loaded.ext.module.maas:412 ][WARNING ][8599] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:15:04,513 [salt.loaded.ext.module.maas:412 ][WARNING ][8599] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:15:05,830 [salt.loaded.ext.module.maas:412 ][WARNING ][8599] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:15:38,343 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116051538329606
2019-11-16 05:15:38,365 [salt.minion      :1432][INFO    ][9043] Starting a new job with PID 9043
2019-11-16 05:15:42,176 [salt.state       :915 ][INFO    ][9043] Loading fresh modules for state activity
2019-11-16 05:15:42,228 [salt.fileclient  :1219][INFO    ][9043] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-16 05:15:42,270 [salt.state       :1780][INFO    ][9043] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:42.270564
2019-11-16 05:15:42,270 [salt.state       :1813][INFO    ][9043] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:15:42,272 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9043] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:15:43,793 [salt.state       :300 ][INFO    ][9043] {'pid': 9054, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:15:43,794 [salt.state       :1951][INFO    ][9043] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:43.794322 duration_in_ms=1523.758
2019-11-16 05:15:43,797 [salt.state       :1780][INFO    ][9043] Running state [maas.wait_for_machine_status] at time 05:15:43.797540
2019-11-16 05:15:43,798 [salt.state       :1813][INFO    ][9043] Executing state module.run for [maas.wait_for_machine_status]
2019-11-16 05:15:43,798 [salt.utils.decorators:613 ][WARNING ][9043] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:15:44,862 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.9469161s left)
2019-11-16 05:15:53,457 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051553444404
2019-11-16 05:15:53,479 [salt.minion      :1432][INFO    ][9088] Starting a new job with PID 9088
2019-11-16 05:15:53,503 [salt.minion      :1711][INFO    ][9088] Returning information for job: 20191116051553444404
2019-11-16 05:16:15,803 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.00531507s left)
2019-11-16 05:16:23,511 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051623498388
2019-11-16 05:16:23,534 [salt.minion      :1432][INFO    ][9122] Starting a new job with PID 9122
2019-11-16 05:16:23,557 [salt.minion      :1711][INFO    ][9122] Returning information for job: 20191116051623498388
2019-11-16 05:16:46,756 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.05222106s left)
2019-11-16 05:16:53,551 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051653544929
2019-11-16 05:16:53,569 [salt.minion      :1432][INFO    ][9262] Starting a new job with PID 9262
2019-11-16 05:16:53,581 [salt.minion      :1711][INFO    ][9262] Returning information for job: 20191116051653544929
2019-11-16 05:17:18,074 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.73412395s left)
2019-11-16 05:17:23,588 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051723575330
2019-11-16 05:17:23,610 [salt.minion      :1432][INFO    ][9708] Starting a new job with PID 9708
2019-11-16 05:17:23,631 [salt.minion      :1711][INFO    ][9708] Returning information for job: 20191116051723575330
2019-11-16 05:17:49,606 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.20224309s left)
2019-11-16 05:17:53,638 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051753625981
2019-11-16 05:17:53,659 [salt.minion      :1432][INFO    ][10150] Starting a new job with PID 10150
2019-11-16 05:17:53,682 [salt.minion      :1711][INFO    ][10150] Returning information for job: 20191116051753625981
2019-11-16 05:18:21,470 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.33844709s left)
2019-11-16 05:18:23,696 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051823678830
2019-11-16 05:18:23,719 [salt.minion      :1432][INFO    ][10188] Starting a new job with PID 10188
2019-11-16 05:18:23,743 [salt.minion      :1711][INFO    ][10188] Returning information for job: 20191116051823678830
2019-11-16 05:18:53,758 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051853742092
2019-11-16 05:18:53,777 [salt.minion      :1432][INFO    ][10331] Starting a new job with PID 10331
2019-11-16 05:18:53,800 [salt.minion      :1711][INFO    ][10331] Returning information for job: 20191116051853742092
2019-11-16 05:18:55,050 [salt.loaded.ext.module.maas:1023][INFO    ][9043] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1308.75849605s left)
2019-11-16 05:19:23,824 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116051923808824
2019-11-16 05:19:23,847 [salt.minion      :1432][INFO    ][10432] Starting a new job with PID 10432
2019-11-16 05:19:23,872 [salt.minion      :1711][INFO    ][10432] Returning information for job: 20191116051923808824
2019-11-16 05:19:28,366 [salt.state       :300 ][INFO    ][9043] {'ret': True}
2019-11-16 05:19:28,366 [salt.state       :1951][INFO    ][9043] Completed state [maas.wait_for_machine_status] at time 05:19:28.366627 duration_in_ms=224569.085
2019-11-16 05:19:28,370 [salt.minion      :1711][INFO    ][9043] Returning information for job: 20191116051538329606
2019-11-16 05:19:29,037 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116051929021265
2019-11-16 05:19:29,059 [salt.minion      :1432][INFO    ][10445] Starting a new job with PID 10445
2019-11-16 05:19:32,844 [salt.state       :915 ][INFO    ][10445] Loading fresh modules for state activity
2019-11-16 05:19:32,895 [salt.fileclient  :1219][INFO    ][10445] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-16 05:19:32,984 [salt.state       :1780][INFO    ][10445] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:32.984851
2019-11-16 05:19:32,985 [salt.state       :1813][INFO    ][10445] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:19:32,986 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10445] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:19:34,359 [salt.state       :300 ][INFO    ][10445] {'pid': 10452, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:19:34,360 [salt.state       :1951][INFO    ][10445] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:34.360129 duration_in_ms=1375.276
2019-11-16 05:19:34,363 [salt.state       :1780][INFO    ][10445] Running state [maas_machines_storage_cmp002_lvm] at time 05:19:34.363228
2019-11-16 05:19:34,363 [salt.state       :1813][INFO    ][10445] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-16 05:19:35,818 [salt.loaded.ext.module.maasng:610 ][INFO    ][10445] 86aayb
2019-11-16 05:19:35,818 [salt.loaded.ext.module.maasng:626 ][INFO    ][10445] sda
2019-11-16 05:19:36,535 [salt.loaded.ext.module.maasng:361 ][INFO    ][10445] 86aayb
2019-11-16 05:19:36,664 [salt.loaded.ext.module.maasng:367 ][INFO    ][10445] [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 4, u'partitions': [{u'uuid': u'db8362b2-8e35-4cc0-b241-6abfeb2f116e', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86aayb', u'filesystem': {u'mount_options': None, u'uuid': u'ee58fcbd-7fc3-4d47-a60e-870cfc58bb62', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86aayb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/', u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'30aac549-c95d-4898-b518-0fe14e3ab3f3', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 13, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86aayb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'f83fd759-e2ca-483a-b92c-d695499c7eb8', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/13/', u'used_size': 2397988454400, u'serial': None, u'size': 2397988454400}]
2019-11-16 05:19:36,665 [salt.loaded.ext.module.maasng:632 ][INFO    ][10445] vgroot
2019-11-16 05:19:36,665 [salt.loaded.ext.module.maasng:635 ][INFO    ][10445] lvroot
2019-11-16 05:19:36,665 [salt.loaded.ext.module.maasng:639 ][INFO    ][10445] 107374182400
2019-11-16 05:19:37,369 [salt.loaded.ext.module.maasng:645 ][INFO    ][10445] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'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'mode': u'dhcp', u'id': 47}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'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'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'86aayb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/interfaces/4/'}, u'fqdn': u'cmp002.maas', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86aayb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'c4359594-1f71-4809-a581-8691acbba565', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86aayb', u'filesystem': {u'mount_options': None, u'uuid': u'00016cc9-761c-489a-8514-d304e115c9e8', u'fstype': u'lvm-pv', u'mount_point': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/86aayb/', u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'86aayb', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86aayb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'size': 2397992648704, u'uuid': u'c4359594-1f71-4809-a581-8691acbba565', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86aayb', u'filesystem': {u'mount_options': None, u'uuid': u'00016cc9-761c-489a-8514-d304e115c9e8', u'fstype': u'lvm-pv', u'mount_point': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}]}, {u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'09c6e983-d812-43fa-8c74-39c0ad567c6a', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86aayb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'b0917450-131a-4b0b-b210-f7d938af9069', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/15/', u'used_size': 107374182400, u'id': 15, u'serial': None, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'86aayb', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'c4359594-1f71-4809-a581-8691acbba565', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'86aayb', u'filesystem': {u'mount_options': None, u'uuid': u'00016cc9-761c-489a-8514-d304e115c9e8', u'fstype': u'lvm-pv', u'mount_point': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}]}], u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'86aayb', u'id': 10}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'09c6e983-d812-43fa-8c74-39c0ad567c6a', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'86aayb', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'b0917450-131a-4b0b-b210-f7d938af9069', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/blockdevices/15/', u'used_size': 107374182400, u'id': 15, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'min_hwe_kernel': u'ga-18.04', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'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'mode': u'dhcp', u'id': 47}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'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'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'86aayb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 48}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 22, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'86aayb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/interfaces/22/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 50}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 23, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'86aayb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/interfaces/23/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 52}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 18, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'86aayb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/86aayb/interfaces/18/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-16 05:19:37,371 [salt.state       :300 ][INFO    ][10445] {'new': {'storage_layout': 'lvm'}}
2019-11-16 05:19:37,372 [salt.state       :1951][INFO    ][10445] Completed state [maas_machines_storage_cmp002_lvm] at time 05:19:37.372106 duration_in_ms=3008.877
2019-11-16 05:19:37,372 [salt.state       :1780][INFO    ][10445] Running state [maas_machines_storage_cmp001_lvm] at time 05:19:37.372680
2019-11-16 05:19:37,373 [salt.state       :1813][INFO    ][10445] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-16 05:19:38,762 [salt.loaded.ext.module.maasng:610 ][INFO    ][10445] edeecw
2019-11-16 05:19:38,763 [salt.loaded.ext.module.maasng:626 ][INFO    ][10445] sda
2019-11-16 05:19:39,439 [salt.loaded.ext.module.maasng:361 ][INFO    ][10445] edeecw
2019-11-16 05:19:39,565 [salt.loaded.ext.module.maasng:367 ][INFO    ][10445] [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'edeecw', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/', u'used_size': 2397998940160, u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'bf7027a4-dd8d-473f-8156-2776fce1cb59', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'edeecw', u'filesystem': {u'mount_options': None, u'uuid': u'85af824e-9449-413f-b5ec-85acb2363488', u'fstype': u'lvm-pv', u'mount_point': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/partition/1', u'type': u'partition', u'id': 1, u'device_id': 2}]}, {u'size': 2397988454400, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'88558837-8664-4098-a0cf-9a298b019264', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'edeecw', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'd4e5523e-8239-4d62-b832-0fb741936453', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/6/', u'used_size': 2397988454400, u'id': 6, u'serial': None, u'partitions': []}]
2019-11-16 05:19:39,566 [salt.loaded.ext.module.maasng:632 ][INFO    ][10445] vgroot
2019-11-16 05:19:39,566 [salt.loaded.ext.module.maasng:635 ][INFO    ][10445] lvroot
2019-11-16 05:19:39,566 [salt.loaded.ext.module.maasng:639 ][INFO    ][10445] 107374182400
2019-11-16 05:19:40,253 [salt.loaded.ext.module.maasng:645 ][INFO    ][10445] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 19}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'edeecw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/interfaces/5/'}, u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'0dc78d91-1180-4a7a-8111-8d62816da306', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/partition/11', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'edeecw', u'filesystem': {u'label': None, u'uuid': u'3d8e80da-8d08-4e98-8fb8-eea3717be293', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 11, u'size': 2397992648704}], u'path': u'/dev/disk/by-dname/sda', u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'edeecw', u'partition_table_type': u'GPT', u'filesystem': None, u'id': 2, u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/'}, u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'0dc78d91-1180-4a7a-8111-8d62816da306', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/partition/11', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'edeecw', u'filesystem': {u'label': None, u'uuid': u'3d8e80da-8d08-4e98-8fb8-eea3717be293', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 11, u'size': 2397992648704}], u'path': u'/dev/disk/by-dname/sda', u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'edeecw', u'partition_table_type': u'GPT', u'filesystem': None, u'id': 2, u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/'}, {u'size': 107374182400, u'uuid': u'18fb0abf-9c9d-40c6-b4e1-ab31c38497f1', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'path': u'/dev/disk/by-dname/lvroot', u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'edeecw', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'72bf3055-40cf-4924-bfed-a811d029754f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 16, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/16/'}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'edeecw', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'18fb0abf-9c9d-40c6-b4e1-ab31c38497f1', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'edeecw', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'72bf3055-40cf-4924-bfed-a811d029754f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 16, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/16/'}], u'min_hwe_kernel': u'ga-18.04', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'off', u'commissioning_status': 2, u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'edeecw', u'id': 11}], u'special_filesystems': [], u'current_commissioning_result_id': 4, 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 19}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'system_id': u'edeecw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 20}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'id': 9, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'effective_mtu': 1500, u'system_id': u'edeecw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 21}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'id': 10, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'effective_mtu': 1500, u'system_id': u'edeecw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/interfaces/10/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 23}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'parents': [], u'id': 11, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'effective_mtu': 1500, u'system_id': u'edeecw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'0dc78d91-1180-4a7a-8111-8d62816da306', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/partition/11', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'edeecw', u'filesystem': {u'label': None, u'uuid': u'3d8e80da-8d08-4e98-8fb8-eea3717be293', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 11, u'size': 2397992648704}], u'path': u'/dev/disk/by-dname/sda', u'used_for': u'GPT partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'system_id': u'edeecw', u'partition_table_type': u'GPT', u'filesystem': None, u'id': 2, u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/edeecw/blockdevices/2/'}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'ip_addresses': [u'192.168.11.38'], u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/edeecw/'}
2019-11-16 05:19:40,255 [salt.state       :300 ][INFO    ][10445] {'new': {'storage_layout': 'lvm'}}
2019-11-16 05:19:40,255 [salt.state       :1951][INFO    ][10445] Completed state [maas_machines_storage_cmp001_lvm] at time 05:19:40.255772 duration_in_ms=2883.091
2019-11-16 05:19:40,259 [salt.minion      :1711][INFO    ][10445] Returning information for job: 20191116051929021265
2019-11-16 05:19:40,894 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116051940882363
2019-11-16 05:19:40,917 [salt.minion      :1432][INFO    ][10512] Starting a new job with PID 10512
2019-11-16 05:19:41,698 [salt.state       :915 ][INFO    ][10512] Loading fresh modules for state activity
2019-11-16 05:19:41,751 [salt.fileclient  :1219][INFO    ][10512] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-16 05:19:41,791 [salt.state       :1780][INFO    ][10512] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:41.791409
2019-11-16 05:19:41,791 [salt.state       :1813][INFO    ][10512] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:19:41,793 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10512] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:19:43,305 [salt.state       :300 ][INFO    ][10512] {'pid': 10520, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:19:43,306 [salt.state       :1951][INFO    ][10512] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:43.305955 duration_in_ms=1514.545
2019-11-16 05:19:43,307 [salt.state       :1780][INFO    ][10512] Running state [maas.deploy_machines] at time 05:19:43.307646
2019-11-16 05:19:43,308 [salt.state       :1813][INFO    ][10512] Executing state module.run for [maas.deploy_machines]
2019-11-16 05:19:43,308 [salt.utils.decorators:613 ][WARNING ][10512] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:19:43,750 [salt.loaded.ext.module.maas:684 ][INFO    ][10512] deploymachines hwe_kernel=ga-18.04 system_id=86aayb distro_series=bionic
2019-11-16 05:19:46,031 [salt.loaded.ext.module.maas:684 ][INFO    ][10512] deploymachines hwe_kernel=ga-18.04 system_id=edeecw distro_series=bionic
2019-11-16 05:19:47,812 [salt.loaded.ext.module.maas:684 ][INFO    ][10512] deploymachines hwe_kernel=ga-18.04 system_id=xchxmm distro_series=bionic
2019-11-16 05:19:50,243 [salt.loaded.ext.module.maas:684 ][INFO    ][10512] deploymachines hwe_kernel=ga-18.04 system_id=ecm7q6 distro_series=bionic
2019-11-16 05:19:52,801 [salt.loaded.ext.module.maas:684 ][INFO    ][10512] deploymachines hwe_kernel=ga-18.04 system_id=deapsy distro_series=bionic
2019-11-16 05:19:55,182 [salt.state       :300 ][INFO    ][10512] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-16 05:19:55,182 [salt.state       :1951][INFO    ][10512] Completed state [maas.deploy_machines] at time 05:19:55.182613 duration_in_ms=11874.966
2019-11-16 05:19:55,186 [salt.minion      :1711][INFO    ][10512] Returning information for job: 20191116051940882363
2019-11-16 05:19:55,783 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116051955769844
2019-11-16 05:19:55,805 [salt.minion      :1432][INFO    ][10833] Starting a new job with PID 10833
2019-11-16 05:19:59,690 [salt.state       :915 ][INFO    ][10833] Loading fresh modules for state activity
2019-11-16 05:19:59,718 [salt.fileclient  :1219][INFO    ][10833] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-16 05:19:59,746 [salt.state       :1780][INFO    ][10833] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:59.746042
2019-11-16 05:19:59,746 [salt.state       :1813][INFO    ][10833] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:19:59,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10833] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:20:01,165 [salt.state       :300 ][INFO    ][10833] {'pid': 10847, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:20:01,165 [salt.state       :1951][INFO    ][10833] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:20:01.165595 duration_in_ms=1419.552
2019-11-16 05:20:01,167 [salt.state       :1780][INFO    ][10833] Running state [maas.wait_for_machine_status] at time 05:20:01.167097
2019-11-16 05:20:01,167 [salt.state       :1813][INFO    ][10833] Executing state module.run for [maas.wait_for_machine_status]
2019-11-16 05:20:01,167 [salt.utils.decorators:613 ][WARNING ][10833] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:20:04,438 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.73427701s left)
2019-11-16 05:20:10,871 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052010858328
2019-11-16 05:20:10,893 [salt.minion      :1432][INFO    ][10871] Starting a new job with PID 10871
2019-11-16 05:20:10,915 [salt.minion      :1711][INFO    ][10871] Returning information for job: 20191116052010858328
2019-11-16 05:20:37,997 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.17456388s left)
2019-11-16 05:20:40,913 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052040900736
2019-11-16 05:20:40,935 [salt.minion      :1432][INFO    ][10898] Starting a new job with PID 10898
2019-11-16 05:20:40,958 [salt.minion      :1711][INFO    ][10898] Returning information for job: 20191116052040900736
2019-11-16 05:21:10,729 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.44243979s left)
2019-11-16 05:21:10,959 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052110945855
2019-11-16 05:21:10,981 [salt.minion      :1432][INFO    ][10945] Starting a new job with PID 10945
2019-11-16 05:21:11,004 [salt.minion      :1711][INFO    ][10945] Returning information for job: 20191116052110945855
2019-11-16 05:21:40,997 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052140991018
2019-11-16 05:21:41,011 [salt.minion      :1432][INFO    ][11059] Starting a new job with PID 11059
2019-11-16 05:21:41,022 [salt.minion      :1711][INFO    ][11059] Returning information for job: 20191116052140991018
2019-11-16 05:21:44,239 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.93291783s left)
2019-11-16 05:22:11,032 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052211020101
2019-11-16 05:22:11,055 [salt.minion      :1432][INFO    ][11292] Starting a new job with PID 11292
2019-11-16 05:22:11,077 [salt.minion      :1711][INFO    ][11292] Returning information for job: 20191116052211020101
2019-11-16 05:22:17,156 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.01615191s left)
2019-11-16 05:22:41,091 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052241078457
2019-11-16 05:22:41,113 [salt.minion      :1432][INFO    ][11671] Starting a new job with PID 11671
2019-11-16 05:22:41,138 [salt.minion      :1711][INFO    ][11671] Returning information for job: 20191116052241078457
2019-11-16 05:22:49,746 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.42608595s left)
2019-11-16 05:23:11,150 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052311137211
2019-11-16 05:23:11,175 [salt.minion      :1432][INFO    ][12054] Starting a new job with PID 12054
2019-11-16 05:23:11,198 [salt.minion      :1711][INFO    ][12054] Returning information for job: 20191116052311137211
2019-11-16 05:23:23,328 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.84400296s left)
2019-11-16 05:23:41,212 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052341199803
2019-11-16 05:23:41,234 [salt.minion      :1432][INFO    ][12169] Starting a new job with PID 12169
2019-11-16 05:23:41,257 [salt.minion      :1711][INFO    ][12169] Returning information for job: 20191116052341199803
2019-11-16 05:23:56,797 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.37432885s left)
2019-11-16 05:24:11,273 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052411261177
2019-11-16 05:24:11,295 [salt.minion      :1432][INFO    ][12234] Starting a new job with PID 12234
2019-11-16 05:24:11,317 [salt.minion      :1711][INFO    ][12234] Returning information for job: 20191116052411261177
2019-11-16 05:24:30,458 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.71386194s left)
2019-11-16 05:24:41,340 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052441328450
2019-11-16 05:24:41,363 [salt.minion      :1432][INFO    ][12342] Starting a new job with PID 12342
2019-11-16 05:24:41,387 [salt.minion      :1711][INFO    ][12342] Returning information for job: 20191116052441328450
2019-11-16 05:25:03,942 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.22951579s left)
2019-11-16 05:25:11,406 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052511394292
2019-11-16 05:25:11,431 [salt.minion      :1432][INFO    ][12488] Starting a new job with PID 12488
2019-11-16 05:25:11,454 [salt.minion      :1711][INFO    ][12488] Returning information for job: 20191116052511394292
2019-11-16 05:25:37,561 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.61120391s left)
2019-11-16 05:25:41,490 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052541477087
2019-11-16 05:25:41,512 [salt.minion      :1432][INFO    ][12746] Starting a new job with PID 12746
2019-11-16 05:25:41,536 [salt.minion      :1711][INFO    ][12746] Returning information for job: 20191116052541477087
2019-11-16 05:26:10,628 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.54396081s left)
2019-11-16 05:26:11,572 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052611560541
2019-11-16 05:26:11,589 [salt.minion      :1432][INFO    ][13012] Starting a new job with PID 13012
2019-11-16 05:26:11,608 [salt.minion      :1711][INFO    ][13012] Returning information for job: 20191116052611560541
2019-11-16 05:26:41,646 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052641634143
2019-11-16 05:26:41,667 [salt.minion      :1432][INFO    ][13111] Starting a new job with PID 13111
2019-11-16 05:26:41,689 [salt.minion      :1711][INFO    ][13111] Returning information for job: 20191116052641634143
2019-11-16 05:26:44,361 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.81120086s left)
2019-11-16 05:27:11,734 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052711722952
2019-11-16 05:27:11,756 [salt.minion      :1432][INFO    ][13221] Starting a new job with PID 13221
2019-11-16 05:27:11,780 [salt.minion      :1711][INFO    ][13221] Returning information for job: 20191116052711722952
2019-11-16 05:27:17,524 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.64801788s left)
2019-11-16 05:27:41,799 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052741787006
2019-11-16 05:27:41,821 [salt.minion      :1432][INFO    ][13363] Starting a new job with PID 13363
2019-11-16 05:27:41,845 [salt.minion      :1711][INFO    ][13363] Returning information for job: 20191116052741787006
2019-11-16 05:27:50,798 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1780.37358093s left)
2019-11-16 05:28:11,908 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052811894768
2019-11-16 05:28:11,930 [salt.minion      :1432][INFO    ][13532] Starting a new job with PID 13532
2019-11-16 05:28:11,953 [salt.minion      :1711][INFO    ][13532] Returning information for job: 20191116052811894768
2019-11-16 05:28:23,803 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1747.36858201s left)
2019-11-16 05:28:42,022 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052842006011
2019-11-16 05:28:42,044 [salt.minion      :1432][INFO    ][13788] Starting a new job with PID 13788
2019-11-16 05:28:42,068 [salt.minion      :1711][INFO    ][13788] Returning information for job: 20191116052842006011
2019-11-16 05:28:57,364 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1713.80827999s left)
2019-11-16 05:29:12,146 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052912134303
2019-11-16 05:29:12,168 [salt.minion      :1432][INFO    ][13967] Starting a new job with PID 13967
2019-11-16 05:29:12,193 [salt.minion      :1711][INFO    ][13967] Returning information for job: 20191116052912134303
2019-11-16 05:29:30,614 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1680.55748081s left)
2019-11-16 05:29:42,276 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116052942262729
2019-11-16 05:29:42,299 [salt.minion      :1432][INFO    ][13995] Starting a new job with PID 13995
2019-11-16 05:29:42,323 [salt.minion      :1711][INFO    ][13995] Returning information for job: 20191116052942262729
2019-11-16 05:30:04,184 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1646.98772788s left)
2019-11-16 05:30:12,420 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053012407142
2019-11-16 05:30:12,442 [salt.minion      :1432][INFO    ][14041] Starting a new job with PID 14041
2019-11-16 05:30:12,466 [salt.minion      :1711][INFO    ][14041] Returning information for job: 20191116053012407142
2019-11-16 05:30:37,831 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1613.34074593s left)
2019-11-16 05:30:42,565 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053042551525
2019-11-16 05:30:42,588 [salt.minion      :1432][INFO    ][14070] Starting a new job with PID 14070
2019-11-16 05:30:42,613 [salt.minion      :1711][INFO    ][14070] Returning information for job: 20191116053042551525
2019-11-16 05:31:11,405 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1579.76643896s left)
2019-11-16 05:31:12,724 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053112707682
2019-11-16 05:31:12,746 [salt.minion      :1432][INFO    ][14119] Starting a new job with PID 14119
2019-11-16 05:31:12,769 [salt.minion      :1711][INFO    ][14119] Returning information for job: 20191116053112707682
2019-11-16 05:31:42,887 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053142871874
2019-11-16 05:31:42,908 [salt.minion      :1432][INFO    ][14148] Starting a new job with PID 14148
2019-11-16 05:31:42,931 [salt.minion      :1711][INFO    ][14148] Returning information for job: 20191116053142871874
2019-11-16 05:31:44,778 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1546.39338183s left)
2019-11-16 05:32:13,058 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053213045678
2019-11-16 05:32:13,081 [salt.minion      :1432][INFO    ][14284] Starting a new job with PID 14284
2019-11-16 05:32:13,104 [salt.minion      :1711][INFO    ][14284] Returning information for job: 20191116053213045678
2019-11-16 05:32:18,338 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1512.83425188s left)
2019-11-16 05:32:43,239 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053243227162
2019-11-16 05:32:43,261 [salt.minion      :1432][INFO    ][14330] Starting a new job with PID 14330
2019-11-16 05:32:43,284 [salt.minion      :1711][INFO    ][14330] Returning information for job: 20191116053243227162
2019-11-16 05:32:51,624 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1479.54743981s left)
2019-11-16 05:33:13,424 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053313411172
2019-11-16 05:33:13,447 [salt.minion      :1432][INFO    ][14379] Starting a new job with PID 14379
2019-11-16 05:33:13,470 [salt.minion      :1711][INFO    ][14379] Returning information for job: 20191116053313411172
2019-11-16 05:33:25,206 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1445.96547699s left)
2019-11-16 05:33:43,621 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053343607354
2019-11-16 05:33:43,643 [salt.minion      :1432][INFO    ][14408] Starting a new job with PID 14408
2019-11-16 05:33:43,668 [salt.minion      :1711][INFO    ][14408] Returning information for job: 20191116053343607354
2019-11-16 05:33:58,475 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1412.69698501s left)
2019-11-16 05:34:13,829 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053413817435
2019-11-16 05:34:13,852 [salt.minion      :1432][INFO    ][14453] Starting a new job with PID 14453
2019-11-16 05:34:13,877 [salt.minion      :1711][INFO    ][14453] Returning information for job: 20191116053413817435
2019-11-16 05:34:32,195 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1378.97684193s left)
2019-11-16 05:34:44,053 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053444040831
2019-11-16 05:34:44,068 [salt.minion      :1432][INFO    ][14481] Starting a new job with PID 14481
2019-11-16 05:34:44,092 [salt.minion      :1711][INFO    ][14481] Returning information for job: 20191116053444040831
2019-11-16 05:35:05,608 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1345.56375098s left)
2019-11-16 05:35:14,277 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053514264928
2019-11-16 05:35:14,299 [salt.minion      :1432][INFO    ][14526] Starting a new job with PID 14526
2019-11-16 05:35:14,323 [salt.minion      :1711][INFO    ][14526] Returning information for job: 20191116053514264928
2019-11-16 05:35:39,021 [salt.loaded.ext.module.maas:1023][INFO    ][10833] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1312.15112996s left)
2019-11-16 05:35:44,309 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053544296566
2019-11-16 05:35:44,333 [salt.minion      :1432][INFO    ][14555] Starting a new job with PID 14555
2019-11-16 05:35:44,355 [salt.minion      :1711][INFO    ][14555] Returning information for job: 20191116053544296566
2019-11-16 05:36:11,659 [salt.loaded.ext.module.maas:993 ][INFO    ][10833] Machine ecm7q6 mark broken
2019-11-16 05:36:12,442 [salt.loaded.ext.module.maas:996 ][INFO    ][10833] Machine ecm7q6 mark fixed
2019-11-16 05:36:13,596 [salt.loaded.ext.module.maas:684 ][INFO    ][10833] deploymachines hwe_kernel=ga-18.04 system_id=ecm7q6 distro_series=bionic
2019-11-16 05:36:14,358 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053614345115
2019-11-16 05:36:14,377 [salt.minion      :1432][INFO    ][14630] Starting a new job with PID 14630
2019-11-16 05:36:14,400 [salt.minion      :1711][INFO    ][14630] Returning information for job: 20191116053614345115
2019-11-16 05:36:16,164 [salt.loaded.ext.module.maas:160 ][ERROR   ][10833] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-11-16 05:36:16,165 [salt.state       :302 ][ERROR   ][10833] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-11-16 05:36:16,166 [salt.state       :1951][INFO    ][10833] Completed state [maas.wait_for_machine_status] at time 05:36:16.165945 duration_in_ms=974998.842
2019-11-16 05:36:16,171 [salt.minion      :1711][INFO    ][10833] Returning information for job: 20191116051955769844
2019-11-16 05:36:26,929 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command pillar.get with jid 20191116053626916960
2019-11-16 05:36:26,948 [salt.minion      :1432][INFO    ][14699] Starting a new job with PID 14699
2019-11-16 05:36:26,956 [salt.minion      :1711][INFO    ][14699] Returning information for job: 20191116053626916960
2019-11-16 05:36:27,471 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command service.status with jid 20191116053627458081
2019-11-16 05:36:27,493 [salt.minion      :1432][INFO    ][14704] Starting a new job with PID 14704
2019-11-16 05:36:27,893 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14704] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:27,926 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14704] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-16 05:36:27,942 [salt.minion      :1711][INFO    ][14704] Returning information for job: 20191116053627458081
2019-11-16 05:36:28,478 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116053628467258
2019-11-16 05:36:28,496 [salt.minion      :1432][INFO    ][14715] Starting a new job with PID 14715
2019-11-16 05:36:32,248 [salt.state       :915 ][INFO    ][14715] Loading fresh modules for state activity
2019-11-16 05:36:32,661 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'salt-minion --version' in directory '/root'
2019-11-16 05:36:32,994 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'salt-minion --version' in directory '/root'
2019-11-16 05:36:33,846 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'salt-minion --version' in directory '/root'
2019-11-16 05:36:34,218 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'salt-minion --version' in directory '/root'
2019-11-16 05:36:35,546 [salt.state       :1780][INFO    ][14715] Running state [salt-minion] at time 05:36:35.546914
2019-11-16 05:36:35,547 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [salt-minion]
2019-11-16 05:36:35,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-16 05:36:35,619 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,619 [salt.state       :1951][INFO    ][14715] Completed state [salt-minion] at time 05:36:35.619494 duration_in_ms=72.58
2019-11-16 05:36:35,619 [salt.state       :1780][INFO    ][14715] Running state [salt_minion_dependency_packages] at time 05:36:35.619738
2019-11-16 05:36:35,619 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-16 05:36:35,624 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,624 [salt.state       :1951][INFO    ][14715] Completed state [salt_minion_dependency_packages] at time 05:36:35.624629 duration_in_ms=4.892
2019-11-16 05:36:35,626 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/minion.d/minion.conf] at time 05:36:35.626888
2019-11-16 05:36:35,627 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-16 05:36:35,804 [salt.state       :300 ][INFO    ][14715] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-16 05:36:35,804 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/minion.d/minion.conf] at time 05:36:35.804446 duration_in_ms=177.558
2019-11-16 05:36:35,804 [salt.state       :1780][INFO    ][14715] Running state [python-netaddr] at time 05:36:35.804716
2019-11-16 05:36:35,804 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [python-netaddr]
2019-11-16 05:36:35,811 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,811 [salt.state       :1951][INFO    ][14715] Completed state [python-netaddr] at time 05:36:35.811593 duration_in_ms=6.877
2019-11-16 05:36:35,814 [salt.state       :1780][INFO    ][14715] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:36:35.814462
2019-11-16 05:36:35,814 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-16 05:36:35,825 [salt.state       :300 ][INFO    ][14715] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-16 05:36:35,825 [salt.state       :1951][INFO    ][14715] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:36:35.825767 duration_in_ms=11.305
2019-11-16 05:36:35,826 [salt.state       :1780][INFO    ][14715] Running state [salt-minion] at time 05:36:35.826733
2019-11-16 05:36:35,827 [salt.state       :1813][INFO    ][14715] Executing state service.running for [salt-minion]
2019-11-16 05:36:35,827 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:35,864 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-16 05:36:35,881 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-16 05:36:35,898 [salt.state       :300 ][INFO    ][14715] The service salt-minion is already running
2019-11-16 05:36:35,898 [salt.state       :1951][INFO    ][14715] Completed state [salt-minion] at time 05:36:35.898560 duration_in_ms=71.826
2019-11-16 05:36:35,900 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains.d] at time 05:36:35.900000
2019-11-16 05:36:35,900 [salt.state       :1813][INFO    ][14715] Executing state file.directory for [/etc/salt/grains.d]
2019-11-16 05:36:35,901 [salt.state       :300 ][INFO    ][14715] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-16 05:36:35,901 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains.d] at time 05:36:35.901476 duration_in_ms=1.476
2019-11-16 05:36:35,902 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains] at time 05:36:35.902135
2019-11-16 05:36:35,902 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/grains]
2019-11-16 05:36:35,903 [salt.state       :300 ][INFO    ][14715] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-16 05:36:35,903 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains] at time 05:36:35.903194 duration_in_ms=1.059
2019-11-16 05:36:35,903 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains.d/placeholder] at time 05:36:35.903649
2019-11-16 05:36:35,903 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-16 05:36:35,904 [salt.state       :300 ][INFO    ][14715] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-16 05:36:35,904 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains.d/placeholder] at time 05:36:35.904655 duration_in_ms=1.006
2019-11-16 05:36:35,905 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains.d/sphinx] at time 05:36:35.905095
2019-11-16 05:36:35,905 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-16 05:36:35,917 [salt.state       :300 ][INFO    ][14715] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-16 05:36:35,918 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains.d/sphinx] at time 05:36:35.918004 duration_in_ms=12.908
2019-11-16 05:36:35,920 [salt.state       :1780][INFO    ][14715] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.920164
2019-11-16 05:36:35,920 [salt.state       :1813][INFO    ][14715] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-16 05:36:35,920 [salt.state       :300 ][INFO    ][14715] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-16 05:36:35,921 [salt.state       :1951][INFO    ][14715] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.921006 duration_in_ms=0.843
2019-11-16 05:36:35,921 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains.d/dns_records] at time 05:36:35.921447
2019-11-16 05:36:35,921 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-16 05:36:35,935 [salt.state       :300 ][INFO    ][14715] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-16 05:36:35,935 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains.d/dns_records] at time 05:36:35.935922 duration_in_ms=14.475
2019-11-16 05:36:35,936 [salt.state       :1780][INFO    ][14715] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.936792
2019-11-16 05:36:35,937 [salt.state       :1813][INFO    ][14715] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-16 05:36:35,937 [salt.state       :300 ][INFO    ][14715] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-16 05:36:35,937 [salt.state       :1951][INFO    ][14715] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.937625 duration_in_ms=0.833
2019-11-16 05:36:35,938 [salt.state       :1780][INFO    ][14715] Running state [/etc/salt/grains.d/salt] at time 05:36:35.938070
2019-11-16 05:36:35,938 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-16 05:36:35,947 [salt.state       :300 ][INFO    ][14715] File /etc/salt/grains.d/salt is in the correct state
2019-11-16 05:36:35,947 [salt.state       :1951][INFO    ][14715] Completed state [/etc/salt/grains.d/salt] at time 05:36:35.947719 duration_in_ms=9.649
2019-11-16 05:36:35,948 [salt.state       :1780][INFO    ][14715] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.948552
2019-11-16 05:36:35,948 [salt.state       :1813][INFO    ][14715] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-16 05:36:35,949 [salt.state       :300 ][INFO    ][14715] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-16 05:36:35,949 [salt.state       :1951][INFO    ][14715] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:36:35.949374 duration_in_ms=0.822
2019-11-16 05:36:35,951 [salt.state       :1780][INFO    ][14715] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:36:35.951144
2019-11-16 05:36:35,951 [salt.state       :1813][INFO    ][14715] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-16 05:36:35,951 [salt.state       :300 ][INFO    ][14715] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-16 05:36:35,952 [salt.state       :1951][INFO    ][14715] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:36:35.951996 duration_in_ms=0.852
2019-11-16 05:36:35,952 [salt.state       :1780][INFO    ][14715] Running state [mine.update] at time 05:36:35.952636
2019-11-16 05:36:35,952 [salt.state       :1813][INFO    ][14715] Executing state module.wait for [mine.update]
2019-11-16 05:36:35,953 [salt.state       :300 ][INFO    ][14715] No changes made for mine.update
2019-11-16 05:36:35,953 [salt.state       :1951][INFO    ][14715] Completed state [mine.update] at time 05:36:35.953400 duration_in_ms=0.764
2019-11-16 05:36:35,953 [salt.state       :1780][INFO    ][14715] Running state [ca-certificates] at time 05:36:35.953657
2019-11-16 05:36:35,953 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [ca-certificates]
2019-11-16 05:36:35,960 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,960 [salt.state       :1951][INFO    ][14715] Completed state [ca-certificates] at time 05:36:35.960924 duration_in_ms=7.267
2019-11-16 05:36:35,961 [salt.state       :1780][INFO    ][14715] Running state [update-ca-certificates] at time 05:36:35.961553
2019-11-16 05:36:35,961 [salt.state       :1813][INFO    ][14715] Executing state cmd.wait for [update-ca-certificates]
2019-11-16 05:36:35,962 [salt.state       :300 ][INFO    ][14715] No changes made for update-ca-certificates
2019-11-16 05:36:35,962 [salt.state       :1951][INFO    ][14715] Completed state [update-ca-certificates] at time 05:36:35.962309 duration_in_ms=0.756
2019-11-16 05:36:35,962 [salt.state       :1780][INFO    ][14715] Running state [iptables] at time 05:36:35.962542
2019-11-16 05:36:35,962 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [iptables]
2019-11-16 05:36:35,968 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,969 [salt.state       :1951][INFO    ][14715] Completed state [iptables] at time 05:36:35.969044 duration_in_ms=6.502
2019-11-16 05:36:35,969 [salt.state       :1780][INFO    ][14715] Running state [iptables-persistent] at time 05:36:35.969277
2019-11-16 05:36:35,969 [salt.state       :1813][INFO    ][14715] Executing state pkg.installed for [iptables-persistent]
2019-11-16 05:36:35,975 [salt.state       :300 ][INFO    ][14715] All specified packages are already installed
2019-11-16 05:36:35,975 [salt.state       :1951][INFO    ][14715] Completed state [iptables-persistent] at time 05:36:35.975659 duration_in_ms=6.382
2019-11-16 05:36:35,976 [salt.state       :1780][INFO    ][14715] Running state [iptables_modules_v4_load] at time 05:36:35.976550
2019-11-16 05:36:35,976 [salt.state       :1813][INFO    ][14715] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-16 05:36:35,977 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'lsmod' in directory '/root'
2019-11-16 05:36:35,998 [salt.state       :300 ][INFO    ][14715] Kernel modules iptable_filter, ip_tables are already present
2019-11-16 05:36:35,999 [salt.state       :1951][INFO    ][14715] Completed state [iptables_modules_v4_load] at time 05:36:35.999071 duration_in_ms=22.521
2019-11-16 05:36:35,999 [salt.state       :1780][INFO    ][14715] Running state [/etc/iptables/rules.v4] at time 05:36:35.999688
2019-11-16 05:36:36,000 [salt.state       :1813][INFO    ][14715] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-16 05:36:36,085 [salt.state       :300 ][INFO    ][14715] File /etc/iptables/rules.v4 is in the correct state
2019-11-16 05:36:36,085 [salt.state       :1951][INFO    ][14715] Completed state [/etc/iptables/rules.v4] at time 05:36:36.085779 duration_in_ms=86.09
2019-11-16 05:36:36,086 [salt.state       :1780][INFO    ][14715] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:36:36.086674
2019-11-16 05:36:36,086 [salt.state       :1813][INFO    ][14715] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-16 05:36:36,087 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-16 05:36:36,105 [salt.state       :300 ][INFO    ][14715] onlyif execution failed
2019-11-16 05:36:36,105 [salt.state       :1951][INFO    ][14715] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:36:36.105499 duration_in_ms=18.825
2019-11-16 05:36:36,106 [salt.state       :1780][INFO    ][14715] Running state [netfilter-persistent] at time 05:36:36.106361
2019-11-16 05:36:36,106 [salt.state       :1813][INFO    ][14715] Executing state service.running for [netfilter-persistent]
2019-11-16 05:36:36,107 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:36,125 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-16 05:36:36,142 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-16 05:36:36,158 [salt.state       :300 ][INFO    ][14715] The service netfilter-persistent is already running
2019-11-16 05:36:36,159 [salt.state       :1951][INFO    ][14715] Completed state [netfilter-persistent] at time 05:36:36.159035 duration_in_ms=52.674
2019-11-16 05:36:36,159 [salt.state       :1780][INFO    ][14715] Running state [iptables_extra.remove_stale_tables] at time 05:36:36.159781
2019-11-16 05:36:36,160 [salt.state       :1813][INFO    ][14715] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-16 05:36:36,160 [salt.state       :300 ][INFO    ][14715] No changes made for iptables_extra.remove_stale_tables
2019-11-16 05:36:36,160 [salt.state       :1951][INFO    ][14715] Completed state [iptables_extra.remove_stale_tables] at time 05:36:36.160627 duration_in_ms=0.846
2019-11-16 05:36:36,160 [salt.state       :1780][INFO    ][14715] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:36:36.160859
2019-11-16 05:36:36,161 [salt.state       :1813][INFO    ][14715] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-16 05:36:36,161 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14715] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-16 05:36:36,176 [salt.state       :300 ][INFO    ][14715] onlyif execution failed
2019-11-16 05:36:36,176 [salt.state       :1951][INFO    ][14715] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:36:36.176673 duration_in_ms=15.814
2019-11-16 05:36:36,177 [salt.state       :1780][INFO    ][14715] Running state [/etc/iptables/rules.v6] at time 05:36:36.177533
2019-11-16 05:36:36,177 [salt.state       :1813][INFO    ][14715] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-16 05:36:36,178 [salt.state       :300 ][INFO    ][14715] File /etc/iptables/rules.v6 is not present
2019-11-16 05:36:36,178 [salt.state       :1951][INFO    ][14715] Completed state [/etc/iptables/rules.v6] at time 05:36:36.178466 duration_in_ms=0.933
2019-11-16 05:36:36,179 [salt.state       :1780][INFO    ][14715] Running state [iptables_extra.flush_all] at time 05:36:36.179090
2019-11-16 05:36:36,179 [salt.state       :1813][INFO    ][14715] Executing state module.wait for [iptables_extra.flush_all]
2019-11-16 05:36:36,179 [salt.state       :300 ][INFO    ][14715] No changes made for iptables_extra.flush_all
2019-11-16 05:36:36,179 [salt.state       :1951][INFO    ][14715] Completed state [iptables_extra.flush_all] at time 05:36:36.179841 duration_in_ms=0.751
2019-11-16 05:36:36,210 [salt.minion      :1711][INFO    ][14715] Returning information for job: 20191116053628467258
2019-11-16 05:36:36,863 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116053636850786
2019-11-16 05:36:36,886 [salt.minion      :1432][INFO    ][14790] Starting a new job with PID 14790
2019-11-16 05:36:37,649 [salt.state       :915 ][INFO    ][14790] Loading fresh modules for state activity
2019-11-16 05:36:38,318 [salt.state       :1780][INFO    ][14790] Running state [maas-rack-controller] at time 05:36:38.318218
2019-11-16 05:36:38,318 [salt.state       :1813][INFO    ][14790] Executing state pkg.installed for [maas-rack-controller]
2019-11-16 05:36:38,319 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14790] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-16 05:36:38,398 [salt.state       :300 ][INFO    ][14790] All specified packages are already installed
2019-11-16 05:36:38,398 [salt.state       :1951][INFO    ][14790] Completed state [maas-rack-controller] at time 05:36:38.398378 duration_in_ms=80.16
2019-11-16 05:36:38,398 [salt.state       :1780][INFO    ][14790] Running state [ipmitool] at time 05:36:38.398671
2019-11-16 05:36:38,398 [salt.state       :1813][INFO    ][14790] Executing state pkg.installed for [ipmitool]
2019-11-16 05:36:38,404 [salt.state       :300 ][INFO    ][14790] All specified packages are already installed
2019-11-16 05:36:38,404 [salt.state       :1951][INFO    ][14790] Completed state [ipmitool] at time 05:36:38.404306 duration_in_ms=5.635
2019-11-16 05:36:38,406 [salt.state       :1780][INFO    ][14790] Running state [/etc/maas/rackd.conf] at time 05:36:38.406880
2019-11-16 05:36:38,407 [salt.state       :1813][INFO    ][14790] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-16 05:36:38,408 [salt.state       :300 ][INFO    ][14790] No changes needed to be made
2019-11-16 05:36:38,408 [salt.state       :1951][INFO    ][14790] Completed state [/etc/maas/rackd.conf] at time 05:36:38.408176 duration_in_ms=1.296
2019-11-16 05:36:38,408 [salt.state       :1780][INFO    ][14790] Running state [/etc/maas/rackd.conf] at time 05:36:38.408364
2019-11-16 05:36:38,408 [salt.state       :1813][INFO    ][14790] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-16 05:36:38,408 [salt.loaded.int.states.file:2298][WARNING ][14790] 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-11-16 05:36:38,409 [salt.state       :300 ][INFO    ][14790] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-16 05:36:38,409 [salt.state       :1951][INFO    ][14790] Completed state [/etc/maas/rackd.conf] at time 05:36:38.409385 duration_in_ms=1.021
2019-11-16 05:36:38,410 [salt.state       :1780][INFO    ][14790] Running state [maas-rackd] at time 05:36:38.410179
2019-11-16 05:36:38,410 [salt.state       :1813][INFO    ][14790] Executing state service.running for [maas-rackd]
2019-11-16 05:36:38,410 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14790] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:38,445 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14790] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-16 05:36:38,465 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14790] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-16 05:36:38,484 [salt.state       :300 ][INFO    ][14790] The service maas-rackd is already running
2019-11-16 05:36:38,484 [salt.state       :1951][INFO    ][14790] Completed state [maas-rackd] at time 05:36:38.484597 duration_in_ms=74.417
2019-11-16 05:36:38,486 [salt.minion      :1711][INFO    ][14790] Returning information for job: 20191116053636850786
2019-11-16 05:36:39,122 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116053639109404
2019-11-16 05:36:39,147 [salt.minion      :1432][INFO    ][14817] Starting a new job with PID 14817
2019-11-16 05:36:39,884 [salt.state       :915 ][INFO    ][14817] Loading fresh modules for state activity
2019-11-16 05:36:40,572 [salt.state       :1780][INFO    ][14817] Running state [maas-region-controller] at time 05:36:40.572241
2019-11-16 05:36:40,572 [salt.state       :1813][INFO    ][14817] Executing state pkg.installed for [maas-region-controller]
2019-11-16 05:36:40,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-16 05:36:40,663 [salt.state       :300 ][INFO    ][14817] All specified packages are already installed
2019-11-16 05:36:40,664 [salt.state       :1951][INFO    ][14817] Completed state [maas-region-controller] at time 05:36:40.663980 duration_in_ms=91.738
2019-11-16 05:36:40,664 [salt.state       :1780][INFO    ][14817] Running state [python-oauth] at time 05:36:40.664398
2019-11-16 05:36:40,664 [salt.state       :1813][INFO    ][14817] Executing state pkg.installed for [python-oauth]
2019-11-16 05:36:40,671 [salt.state       :300 ][INFO    ][14817] All specified packages are already installed
2019-11-16 05:36:40,672 [salt.state       :1951][INFO    ][14817] Completed state [python-oauth] at time 05:36:40.672014 duration_in_ms=7.616
2019-11-16 05:36:40,675 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/regiond.conf] at time 05:36:40.675518
2019-11-16 05:36:40,675 [salt.state       :1813][INFO    ][14817] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-16 05:36:40,714 [salt.state       :300 ][INFO    ][14817] No changes needed to be made
2019-11-16 05:36:40,715 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/regiond.conf] at time 05:36:40.715155 duration_in_ms=39.637
2019-11-16 05:36:40,715 [salt.state       :1780][INFO    ][14817] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:36:40.715661
2019-11-16 05:36:40,715 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-16 05:36:40,768 [salt.state       :300 ][INFO    ][14817] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-16 05:36:40,768 [salt.state       :1951][INFO    ][14817] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:36:40.768482 duration_in_ms=52.821
2019-11-16 05:36:40,769 [salt.state       :1780][INFO    ][14817] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:40.769015
2019-11-16 05:36:40,769 [salt.state       :1813][INFO    ][14817] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-16 05:36:40,781 [salt.state       :300 ][INFO    ][14817] No changes needed to be made
2019-11-16 05:36:40,781 [salt.state       :1951][INFO    ][14817] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:40.781624 duration_in_ms=12.609
2019-11-16 05:36:40,782 [salt.state       :1780][INFO    ][14817] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:40.782062
2019-11-16 05:36:40,782 [salt.state       :1813][INFO    ][14817] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-16 05:36:40,815 [salt.state       :300 ][INFO    ][14817] No changes needed to be made
2019-11-16 05:36:40,815 [salt.state       :1951][INFO    ][14817] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:40.815441 duration_in_ms=33.378
2019-11-16 05:36:40,816 [salt.state       :1780][INFO    ][14817] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:36:40.816112
2019-11-16 05:36:40,816 [salt.state       :1813][INFO    ][14817] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-16 05:36:40,842 [salt.state       :300 ][INFO    ][14817] No changes needed to be made
2019-11-16 05:36:40,842 [salt.state       :1951][INFO    ][14817] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:36:40.842695 duration_in_ms=26.582
2019-11-16 05:36:40,843 [salt.state       :1780][INFO    ][14817] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:36:40.843257
2019-11-16 05:36:40,843 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-16 05:36:40,855 [salt.state       :300 ][INFO    ][14817] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-16 05:36:40,855 [salt.state       :1951][INFO    ][14817] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:36:40.855270 duration_in_ms=12.013
2019-11-16 05:36:40,856 [salt.state       :1780][INFO    ][14817] Running state [a2enmod headers] at time 05:36:40.856575
2019-11-16 05:36:40,856 [salt.state       :1813][INFO    ][14817] Executing state cmd.run for [a2enmod headers]
2019-11-16 05:36:40,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command 'a2enmod headers' in directory '/root'
2019-11-16 05:36:40,929 [salt.state       :300 ][INFO    ][14817] {'pid': 14836, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-16 05:36:40,930 [salt.state       :1951][INFO    ][14817] Completed state [a2enmod headers] at time 05:36:40.930201 duration_in_ms=73.624
2019-11-16 05:36:40,930 [salt.state       :1780][INFO    ][14817] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:36:40.930887
2019-11-16 05:36:40,931 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-16 05:36:40,950 [salt.state       :300 ][INFO    ][14817] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-16 05:36:40,950 [salt.state       :1951][INFO    ][14817] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:36:40.950685 duration_in_ms=19.798
2019-11-16 05:36:40,951 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:36:40.951543
2019-11-16 05:36:40,951 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-16 05:36:41,035 [salt.state       :300 ][INFO    ][14817] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-16 05:36:41,036 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:36:41.035979 duration_in_ms=84.433
2019-11-16 05:36:41,037 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:36:41.037107
2019-11-16 05:36:41,037 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-16 05:36:41,106 [salt.state       :300 ][INFO    ][14817] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-16 05:36:41,107 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:36:41.107271 duration_in_ms=70.164
2019-11-16 05:36:41,107 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:36:41.107920
2019-11-16 05:36:41,108 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-16 05:36:41,172 [salt.state       :300 ][INFO    ][14817] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-16 05:36:41,173 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:36:41.172952 duration_in_ms=65.032
2019-11-16 05:36:41,173 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:36:41.173505
2019-11-16 05:36:41,173 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-11-16 05:36:41,232 [salt.state       :300 ][INFO    ][14817] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-11-16 05:36:41,232 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:36:41.232914 duration_in_ms=59.409
2019-11-16 05:36:41,233 [salt.state       :1780][INFO    ][14817] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:36:41.233407
2019-11-16 05:36:41,233 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-11-16 05:36:41,286 [salt.state       :300 ][INFO    ][14817] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-11-16 05:36:41,286 [salt.state       :1951][INFO    ][14817] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:36:41.286421 duration_in_ms=53.014
2019-11-16 05:36:41,286 [salt.state       :1780][INFO    ][14817] Running state [/root/.pgpass] at time 05:36:41.286677
2019-11-16 05:36:41,286 [salt.state       :1813][INFO    ][14817] Executing state file.managed for [/root/.pgpass]
2019-11-16 05:36:41,328 [salt.state       :300 ][INFO    ][14817] File /root/.pgpass is in the correct state
2019-11-16 05:36:41,328 [salt.state       :1951][INFO    ][14817] Completed state [/root/.pgpass] at time 05:36:41.328263 duration_in_ms=41.586
2019-11-16 05:36:41,332 [salt.state       :1780][INFO    ][14817] Running state [maas-region syncdb --noinput] at time 05:36:41.332226
2019-11-16 05:36:41,332 [salt.state       :1813][INFO    ][14817] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-16 05:36:41,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-16 05:36:43,424 [salt.state       :300 ][INFO    ][14817] {'pid': 14853, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, contenttypes, auth, sessions, piston3, maasserver, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-16 05:36:43,425 [salt.state       :1951][INFO    ][14817] Completed state [maas-region syncdb --noinput] at time 05:36:43.425141 duration_in_ms=2092.913
2019-11-16 05:36:43,425 [salt.state       :2022][WARNING ][14817] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-16 05:36:43,428 [salt.state       :1780][INFO    ][14817] Running state [maas-regiond] at time 05:36:43.428535
2019-11-16 05:36:43,429 [salt.state       :1813][INFO    ][14817] Executing state service.running for [maas-regiond]
2019-11-16 05:36:43,430 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:43,467 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-16 05:36:43,484 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-16 05:36:43,499 [salt.state       :300 ][INFO    ][14817] The service maas-regiond is already running
2019-11-16 05:36:43,500 [salt.state       :1951][INFO    ][14817] Completed state [maas-regiond] at time 05:36:43.500322 duration_in_ms=71.787
2019-11-16 05:36:43,502 [salt.state       :1780][INFO    ][14817] Running state [bind9] at time 05:36:43.502725
2019-11-16 05:36:43,503 [salt.state       :1813][INFO    ][14817] Executing state service.running for [bind9]
2019-11-16 05:36:43,504 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:43,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-16 05:36:43,536 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-16 05:36:43,551 [salt.state       :300 ][INFO    ][14817] The service bind9 is already running
2019-11-16 05:36:43,551 [salt.state       :1951][INFO    ][14817] Completed state [bind9] at time 05:36:43.551734 duration_in_ms=49.009
2019-11-16 05:36:43,553 [salt.state       :1780][INFO    ][14817] Running state [apache2] at time 05:36:43.553797
2019-11-16 05:36:43,554 [salt.state       :1813][INFO    ][14817] Executing state service.running for [apache2]
2019-11-16 05:36:43,555 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-16 05:36:43,571 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-16 05:36:43,586 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-16 05:36:43,605 [salt.state       :300 ][INFO    ][14817] The service apache2 is already running
2019-11-16 05:36:43,606 [salt.state       :1951][INFO    ][14817] Completed state [apache2] at time 05:36:43.605989 duration_in_ms=52.192
2019-11-16 05:36:43,607 [salt.state       :1780][INFO    ][14817] Running state [maasng.wait_for_http_code] at time 05:36:43.607552
2019-11-16 05:36:43,607 [salt.state       :1813][INFO    ][14817] Executing state module.run for [maasng.wait_for_http_code]
2019-11-16 05:36:43,608 [salt.utils.decorators:613 ][WARNING ][14817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:36:43,708 [salt.state       :300 ][INFO    ][14817] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-16 05:36:43,709 [salt.state       :1951][INFO    ][14817] Completed state [maasng.wait_for_http_code] at time 05:36:43.709037 duration_in_ms=101.485
2019-11-16 05:36:43,710 [salt.state       :1780][INFO    ][14817] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:36:43.710416
2019-11-16 05:36:43,710 [salt.state       :1813][INFO    ][14817] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-16 05:36:43,711 [salt.state       :300 ][INFO    ][14817] /var/lib/maas/.setup_admin exists
2019-11-16 05:36:43,711 [salt.state       :1951][INFO    ][14817] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:36:43.711570 duration_in_ms=1.155
2019-11-16 05:36:43,712 [salt.state       :1780][INFO    ][14817] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:43.712315
2019-11-16 05:36:43,712 [salt.state       :1813][INFO    ][14817] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:36:43,713 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14817] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:36:45,223 [salt.state       :300 ][INFO    ][14817] {'pid': 14875, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:36:45,224 [salt.state       :1951][INFO    ][14817] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:45.224405 duration_in_ms=1512.088
2019-11-16 05:36:45,228 [salt.state       :1780][INFO    ][14817] Running state [maas_region_boot_source_resources_mirror] at time 05:36:45.228751
2019-11-16 05:36:45,229 [salt.state       :1813][INFO    ][14817] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-16 05:36:45,331 [salt.state       :300 ][INFO    ][14817] {'changes': {}}
2019-11-16 05:36:45,331 [salt.state       :1951][INFO    ][14817] Completed state [maas_region_boot_source_resources_mirror] at time 05:36:45.331795 duration_in_ms=103.043
2019-11-16 05:36:45,333 [salt.state       :1780][INFO    ][14817] Running state [maasng.boot_resources_import] at time 05:36:45.332963
2019-11-16 05:36:45,333 [salt.state       :1813][INFO    ][14817] Executing state module.run for [maasng.boot_resources_import]
2019-11-16 05:36:45,334 [salt.utils.decorators:613 ][WARNING ][14817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:36:45,505 [salt.loaded.ext.module.maasng:1600][INFO    ][14817] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-16 05:36:50,564 [salt.loaded.ext.module.maasng:1600][INFO    ][14817] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-16 05:36:54,155 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053654141740
2019-11-16 05:36:54,175 [salt.minion      :1432][INFO    ][14926] Starting a new job with PID 14926
2019-11-16 05:36:54,197 [salt.minion      :1711][INFO    ][14926] Returning information for job: 20191116053654141740
2019-11-16 05:36:55,627 [salt.loaded.ext.module.maasng:1600][INFO    ][14817] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-16 05:37:00,764 [salt.state       :300 ][INFO    ][14817] {'ret': True}
2019-11-16 05:37:00,765 [salt.state       :1951][INFO    ][14817] Completed state [maasng.boot_resources_import] at time 05:37:00.765126 duration_in_ms=15432.161
2019-11-16 05:37:00,766 [salt.state       :1780][INFO    ][14817] Running state [maas_region_boot_sources_selection_bionic] at time 05:37:00.766396
2019-11-16 05:37:00,766 [salt.state       :1813][INFO    ][14817] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-11-16 05:37:00,972 [salt.state       :300 ][INFO    ][14817] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-16 05:37:00,972 [salt.state       :1951][INFO    ][14817] Completed state [maas_region_boot_sources_selection_bionic] at time 05:37:00.972461 duration_in_ms=206.065
2019-11-16 05:37:00,973 [salt.state       :1780][INFO    ][14817] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:37:00.973848
2019-11-16 05:37:00,974 [salt.state       :1813][INFO    ][14817] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-16 05:37:00,974 [salt.utils.decorators:613 ][WARNING ][14817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:37:00,975 [salt.loaded.ext.module.maasng:1771][INFO    ][14817] boot-sources sync initiated for ALL Rack's
2019-11-16 05:37:01,720 [salt.state       :300 ][INFO    ][14817] {'ret': True}
2019-11-16 05:37:01,721 [salt.state       :1951][INFO    ][14817] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:37:01.721520 duration_in_ms=747.672
2019-11-16 05:37:01,723 [salt.state       :1780][INFO    ][14817] Running state [maas.process_maas_config] at time 05:37:01.723740
2019-11-16 05:37:01,724 [salt.state       :1813][INFO    ][14817] Executing state module.run for [maas.process_maas_config]
2019-11-16 05:37:01,724 [salt.utils.decorators:613 ][WARNING ][14817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:37:01,725 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=enable_http_proxy value=True
2019-11-16 05:37:01,788 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=upstream_dns value=8.8.8.8
2019-11-16 05:37:01,852 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=commissioning_distro_series value=bionic
2019-11-16 05:37:01,918 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=default_osystem value=ubuntu
2019-11-16 05:37:01,978 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=active_discovery_interval value=600
2019-11-16 05:37:02,038 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=dnssec_validation value=no
2019-11-16 05:37:02,098 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=maas_name value=mas01
2019-11-16 05:37:02,158 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=network_discovery value=enabled
2019-11-16 05:37:02,277 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=enable_third_party_drivers value=True
2019-11-16 05:37:02,331 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=default_storage_layout value=lvm
2019-11-16 05:37:05,042 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=ntp_external_only value=True
2019-11-16 05:37:05,101 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-16 05:37:05,143 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=default_distro_series value=bionic
2019-11-16 05:37:05,203 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-11-16 05:37:05,287 [salt.state       :300 ][INFO    ][14817] {'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-11-16 05:37:05,287 [salt.state       :1951][INFO    ][14817] Completed state [maas.process_maas_config] at time 05:37:05.287789 duration_in_ms=3564.048
2019-11-16 05:37:05,288 [salt.state       :1780][INFO    ][14817] Running state [pxe_admin] at time 05:37:05.288756
2019-11-16 05:37:05,289 [salt.state       :1813][INFO    ][14817] Executing state maasng.fabric_present for [pxe_admin]
2019-11-16 05:37:05,352 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:05,439 [salt.loaded.ext.module.maasng:1008][WARNING ][14817] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-16 05:37:05,440 [salt.loaded.ext.module.maasng:1011][WARNING ][14817] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-16 05:37:05,506 [salt.state       :300 ][INFO    ][14817] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-16 05:37:05,506 [salt.state       :1951][INFO    ][14817] Completed state [pxe_admin] at time 05:37:05.506698 duration_in_ms=217.941
2019-11-16 05:37:05,507 [salt.state       :1780][INFO    ][14817] Running state [vlan 0] at time 05:37:05.507139
2019-11-16 05:37:05,507 [salt.state       :1813][INFO    ][14817] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-16 05:37:05,565 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:05,676 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:05,966 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:06,052 [salt.state       :300 ][INFO    ][14817] {'new': 'Vlan untagged was updated'}
2019-11-16 05:37:06,052 [salt.state       :1951][INFO    ][14817] Completed state [vlan 0] at time 05:37:06.052620 duration_in_ms=545.48
2019-11-16 05:37:06,054 [salt.state       :1780][INFO    ][14817] Running state [192.168.11.0/24] at time 05:37:06.054202
2019-11-16 05:37:06,054 [salt.state       :1813][INFO    ][14817] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-16 05:37:06,250 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {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'primary_rack': u'6yp3my', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-11-16 05:37:06,251 [salt.loaded.ext.module.maasng:1235][WARNING ][14817] Ignoring parameter vlan:0
2019-11-16 05:37:06,333 [salt.state       :300 ][INFO    ][14817] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-16 05:37:06,333 [salt.state       :1951][INFO    ][14817] Completed state [192.168.11.0/24] at time 05:37:06.333621 duration_in_ms=279.419
2019-11-16 05:37:06,335 [salt.state       :1780][INFO    ][14817] Running state [maas_create_iprange_1] at time 05:37:06.335013
2019-11-16 05:37:06,335 [salt.state       :1813][INFO    ][14817] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-16 05:37:06,408 [salt.state       :300 ][INFO    ][14817] Iprange maas_create_iprange_1 already exist.
2019-11-16 05:37:06,408 [salt.state       :1951][INFO    ][14817] Completed state [maas_create_iprange_1] at time 05:37:06.408525 duration_in_ms=73.513
2019-11-16 05:37:06,408 [salt.state       :1780][INFO    ][14817] Running state [vlan 0] at time 05:37:06.408936
2019-11-16 05:37:06,409 [salt.state       :1813][INFO    ][14817] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-16 05:37:06,466 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:06,574 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:06,823 [salt.loaded.ext.module.maasng:945 ][INFO    ][14817] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6yp3my', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-16 05:37:06,877 [salt.state       :300 ][INFO    ][14817] {'new': 'Vlan untagged was updated'}
2019-11-16 05:37:06,877 [salt.state       :1951][INFO    ][14817] Completed state [vlan 0] at time 05:37:06.877820 duration_in_ms=468.883
2019-11-16 05:37:06,878 [salt.state       :1780][INFO    ][14817] Running state [opnfv] at time 05:37:06.878878
2019-11-16 05:37:06,879 [salt.state       :1813][INFO    ][14817] Executing state maasng.sshkey_present for [opnfv]
2019-11-16 05:37:06,937 [salt.loaded.ext.module.maasng:1903][INFO    ][14817] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-11-16 05:37:06,938 [salt.state       :300 ][INFO    ][14817] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-16 05:37:06,938 [salt.state       :1951][INFO    ][14817] Completed state [opnfv] at time 05:37:06.938738 duration_in_ms=59.859
2019-11-16 05:37:06,939 [salt.state       :1780][INFO    ][14817] Running state [maas.process_tags] at time 05:37:06.939641
2019-11-16 05:37:06,940 [salt.state       :1813][INFO    ][14817] Executing state module.run for [maas.process_tags]
2019-11-16 05:37:06,940 [salt.utils.decorators:613 ][WARNING ][14817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:37:06,991 [salt.loaded.ext.module.maas:92  ][INFO    ][14817] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-11-16 05:37:07,057 [salt.state       :300 ][INFO    ][14817] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-11-16 05:37:07,058 [salt.state       :1951][INFO    ][14817] Completed state [maas.process_tags] at time 05:37:07.058112 duration_in_ms=118.472
2019-11-16 05:37:07,061 [salt.minion      :1711][INFO    ][14817] Returning information for job: 20191116053639109404
2019-11-16 05:37:07,570 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116053707559348
2019-11-16 05:37:07,590 [salt.minion      :1432][INFO    ][15190] Starting a new job with PID 15190
2019-11-16 05:37:11,402 [salt.state       :915 ][INFO    ][15190] Loading fresh modules for state activity
2019-11-16 05:37:11,495 [salt.state       :1780][INFO    ][15190] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:11.495625
2019-11-16 05:37:11,496 [salt.state       :1813][INFO    ][15190] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:37:11,498 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15190] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:37:13,115 [salt.state       :300 ][INFO    ][15190] {'pid': 15226, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:37:13,116 [salt.state       :1951][INFO    ][15190] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:13.116120 duration_in_ms=1620.495
2019-11-16 05:37:13,118 [salt.state       :1780][INFO    ][15190] Running state [maas.process_machines] at time 05:37:13.118829
2019-11-16 05:37:13,119 [salt.state       :1813][INFO    ][15190] Executing state module.run for [maas.process_machines]
2019-11-16 05:37:13,120 [salt.utils.decorators:613 ][WARNING ][15190] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:37:13,861 [salt.loaded.ext.module.maas:412 ][WARNING ][15190] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:37:13,862 [salt.loaded.ext.module.maas:92  ][INFO    ][15190] 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=86aayb architecture=amd64/generic power_parameters_power_user=admin
2019-11-16 05:37:15,120 [salt.loaded.ext.module.maas:412 ][WARNING ][15190] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:37:15,121 [salt.loaded.ext.module.maas:92  ][INFO    ][15190] 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=edeecw architecture=amd64/generic power_parameters_power_user=admin
2019-11-16 05:37:16,229 [salt.loaded.ext.module.maas:412 ][WARNING ][15190] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:37:16,230 [salt.loaded.ext.module.maas:92  ][INFO    ][15190] 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=xchxmm architecture=amd64/generic power_parameters_power_user=admin
2019-11-16 05:37:17,492 [salt.loaded.ext.module.maas:412 ][WARNING ][15190] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:37:17,493 [salt.loaded.ext.module.maas:92  ][INFO    ][15190] 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=ecm7q6 architecture=amd64/generic power_parameters_power_user=admin
2019-11-16 05:37:18,605 [salt.loaded.ext.module.maas:412 ][WARNING ][15190] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-16 05:37:18,606 [salt.loaded.ext.module.maas:92  ][INFO    ][15190] 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=deapsy architecture=amd64/generic power_parameters_power_user=admin
2019-11-16 05:37:19,912 [salt.state       :300 ][INFO    ][15190] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-16 05:37:19,912 [salt.state       :1951][INFO    ][15190] Completed state [maas.process_machines] at time 05:37:19.912806 duration_in_ms=6793.975
2019-11-16 05:37:19,916 [salt.minion      :1711][INFO    ][15190] Returning information for job: 20191116053707559348
2019-11-16 05:37:53,300 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116053753287417
2019-11-16 05:37:53,324 [salt.minion      :1432][INFO    ][15482] Starting a new job with PID 15482
2019-11-16 05:37:57,277 [salt.state       :915 ][INFO    ][15482] Loading fresh modules for state activity
2019-11-16 05:37:57,363 [salt.state       :1780][INFO    ][15482] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:57.363502
2019-11-16 05:37:57,363 [salt.state       :1813][INFO    ][15482] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:37:57,365 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15482] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:37:58,502 [salt.state       :300 ][INFO    ][15482] {'pid': 15489, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:37:58,503 [salt.state       :1951][INFO    ][15482] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:58.503600 duration_in_ms=1140.099
2019-11-16 05:37:58,506 [salt.state       :1780][INFO    ][15482] Running state [maas.wait_for_machine_status] at time 05:37:58.506071
2019-11-16 05:37:58,506 [salt.state       :1813][INFO    ][15482] Executing state module.run for [maas.wait_for_machine_status]
2019-11-16 05:37:58,507 [salt.utils.decorators:613 ][WARNING ][15482] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:38:00,777 [salt.loaded.ext.module.maas:993 ][INFO    ][15482] Machine ecm7q6 mark broken
2019-11-16 05:38:01,378 [salt.loaded.ext.module.maas:996 ][INFO    ][15482] Machine ecm7q6 mark fixed
2019-11-16 05:38:02,551 [salt.loaded.ext.module.maas:684 ][INFO    ][15482] deploymachines hwe_kernel=ga-18.04 system_id=ecm7q6 distro_series=bionic
2019-11-16 05:38:06,015 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.50198793s left)
2019-11-16 05:38:08,393 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053808340215
2019-11-16 05:38:08,415 [salt.minion      :1432][INFO    ][15555] Starting a new job with PID 15555
2019-11-16 05:38:08,440 [salt.minion      :1711][INFO    ][15555] Returning information for job: 20191116053808340215
2019-11-16 05:38:38,450 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053838439215
2019-11-16 05:38:38,472 [salt.minion      :1432][INFO    ][15595] Starting a new job with PID 15595
2019-11-16 05:38:38,497 [salt.minion      :1711][INFO    ][15595] Returning information for job: 20191116053838439215
2019-11-16 05:38:39,513 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.00397205s left)
2019-11-16 05:39:08,492 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053908479757
2019-11-16 05:39:08,514 [salt.minion      :1432][INFO    ][15631] Starting a new job with PID 15631
2019-11-16 05:39:08,540 [salt.minion      :1711][INFO    ][15631] Returning information for job: 20191116053908479757
2019-11-16 05:39:12,908 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1425.60916495s left)
2019-11-16 05:39:38,541 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116053938529015
2019-11-16 05:39:38,564 [salt.minion      :1432][INFO    ][15670] Starting a new job with PID 15670
2019-11-16 05:39:38,588 [salt.minion      :1711][INFO    ][15670] Returning information for job: 20191116053938529015
2019-11-16 05:39:45,861 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.65592003s left)
2019-11-16 05:40:08,576 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054008563896
2019-11-16 05:40:08,599 [salt.minion      :1432][INFO    ][15770] Starting a new job with PID 15770
2019-11-16 05:40:08,626 [salt.minion      :1711][INFO    ][15770] Returning information for job: 20191116054008563896
2019-11-16 05:40:19,235 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.28206301s left)
2019-11-16 05:40:38,639 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054038625936
2019-11-16 05:40:38,661 [salt.minion      :1432][INFO    ][15888] Starting a new job with PID 15888
2019-11-16 05:40:38,689 [salt.minion      :1711][INFO    ][15888] Returning information for job: 20191116054038625936
2019-11-16 05:40:52,544 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.97272611s left)
2019-11-16 05:41:08,698 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054108686388
2019-11-16 05:41:08,716 [salt.minion      :1432][INFO    ][15957] Starting a new job with PID 15957
2019-11-16 05:41:08,739 [salt.minion      :1711][INFO    ][15957] Returning information for job: 20191116054108686388
2019-11-16 05:41:26,427 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1292.09018898s left)
2019-11-16 05:41:38,748 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054138735186
2019-11-16 05:41:38,770 [salt.minion      :1432][INFO    ][16018] Starting a new job with PID 16018
2019-11-16 05:41:38,796 [salt.minion      :1711][INFO    ][16018] Returning information for job: 20191116054138735186
2019-11-16 05:41:59,595 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1258.92189288s left)
2019-11-16 05:42:08,810 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054208797319
2019-11-16 05:42:08,833 [salt.minion      :1432][INFO    ][16070] Starting a new job with PID 16070
2019-11-16 05:42:08,861 [salt.minion      :1711][INFO    ][16070] Returning information for job: 20191116054208797319
2019-11-16 05:42:33,207 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1225.30978203s left)
2019-11-16 05:42:38,883 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054238870275
2019-11-16 05:42:38,905 [salt.minion      :1432][INFO    ][16135] Starting a new job with PID 16135
2019-11-16 05:42:38,931 [salt.minion      :1711][INFO    ][16135] Returning information for job: 20191116054238870275
2019-11-16 05:43:06,659 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1191.85772491s left)
2019-11-16 05:43:08,963 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054308949067
2019-11-16 05:43:08,985 [salt.minion      :1432][INFO    ][16203] Starting a new job with PID 16203
2019-11-16 05:43:09,012 [salt.minion      :1711][INFO    ][16203] Returning information for job: 20191116054308949067
2019-11-16 05:43:39,036 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054339023631
2019-11-16 05:43:39,059 [salt.minion      :1432][INFO    ][16277] Starting a new job with PID 16277
2019-11-16 05:43:39,085 [salt.minion      :1711][INFO    ][16277] Returning information for job: 20191116054339023631
2019-11-16 05:43:40,398 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1158.11900592s left)
2019-11-16 05:44:09,120 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054409107375
2019-11-16 05:44:09,144 [salt.minion      :1432][INFO    ][16349] Starting a new job with PID 16349
2019-11-16 05:44:09,169 [salt.minion      :1711][INFO    ][16349] Returning information for job: 20191116054409107375
2019-11-16 05:44:14,085 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1124.43166399s left)
2019-11-16 05:44:39,209 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054439199207
2019-11-16 05:44:39,233 [salt.minion      :1432][INFO    ][16414] Starting a new job with PID 16414
2019-11-16 05:44:39,260 [salt.minion      :1711][INFO    ][16414] Returning information for job: 20191116054439199207
2019-11-16 05:44:47,553 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1090.96369696s left)
2019-11-16 05:45:09,308 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054509294860
2019-11-16 05:45:09,330 [salt.minion      :1432][INFO    ][16466] Starting a new job with PID 16466
2019-11-16 05:45:09,357 [salt.minion      :1711][INFO    ][16466] Returning information for job: 20191116054509294860
2019-11-16 05:45:20,902 [salt.loaded.ext.module.maas:1023][INFO    ][15482] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1057.61509204s left)
2019-11-16 05:45:39,412 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command saltutil.find_job with jid 20191116054539400440
2019-11-16 05:45:39,435 [salt.minion      :1432][INFO    ][16525] Starting a new job with PID 16525
2019-11-16 05:45:39,462 [salt.minion      :1711][INFO    ][16525] Returning information for job: 20191116054539400440
2019-11-16 05:45:54,807 [salt.state       :300 ][INFO    ][15482] {'ret': True}
2019-11-16 05:45:54,808 [salt.state       :1951][INFO    ][15482] Completed state [maas.wait_for_machine_status] at time 05:45:54.807930 duration_in_ms=476301.857
2019-11-16 05:45:54,811 [salt.minion      :1711][INFO    ][15482] Returning information for job: 20191116053753287417
2019-11-16 05:45:55,457 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116054555444557
2019-11-16 05:45:55,479 [salt.minion      :1432][INFO    ][16599] Starting a new job with PID 16599
2019-11-16 05:45:59,188 [salt.state       :915 ][INFO    ][16599] Loading fresh modules for state activity
2019-11-16 05:45:59,317 [salt.state       :1780][INFO    ][16599] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:59.317345
2019-11-16 05:45:59,317 [salt.state       :1813][INFO    ][16599] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:45:59,319 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16599] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:46:00,747 [salt.state       :300 ][INFO    ][16599] {'pid': 16606, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:46:00,748 [salt.state       :1951][INFO    ][16599] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:46:00.748204 duration_in_ms=1430.86
2019-11-16 05:46:00,749 [salt.state       :1780][INFO    ][16599] Running state [maas_machines_storage_cmp002_lvm] at time 05:46:00.749515
2019-11-16 05:46:00,749 [salt.state       :1813][INFO    ][16599] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-16 05:46:01,495 [salt.state       :300 ][INFO    ][16599] Machine cmp002 is not in Ready state.
2019-11-16 05:46:01,495 [salt.state       :1951][INFO    ][16599] Completed state [maas_machines_storage_cmp002_lvm] at time 05:46:01.495785 duration_in_ms=746.269
2019-11-16 05:46:01,496 [salt.state       :1780][INFO    ][16599] Running state [maas_machines_storage_cmp001_lvm] at time 05:46:01.496126
2019-11-16 05:46:01,496 [salt.state       :1813][INFO    ][16599] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-16 05:46:02,188 [salt.state       :300 ][INFO    ][16599] Machine cmp001 is not in Ready state.
2019-11-16 05:46:02,188 [salt.state       :1951][INFO    ][16599] Completed state [maas_machines_storage_cmp001_lvm] at time 05:46:02.188887 duration_in_ms=692.76
2019-11-16 05:46:02,192 [salt.minion      :1711][INFO    ][16599] Returning information for job: 20191116054555444557
2019-11-16 05:46:02,802 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116054602792818
2019-11-16 05:46:02,825 [salt.minion      :1432][INFO    ][16617] Starting a new job with PID 16617
2019-11-16 05:46:03,622 [salt.state       :915 ][INFO    ][16617] Loading fresh modules for state activity
2019-11-16 05:46:03,707 [salt.state       :1780][INFO    ][16617] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:46:03.706987
2019-11-16 05:46:03,707 [salt.state       :1813][INFO    ][16617] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:46:03,709 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16617] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:46:05,156 [salt.state       :300 ][INFO    ][16617] {'pid': 16624, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:46:05,157 [salt.state       :1951][INFO    ][16617] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:46:05.157172 duration_in_ms=1450.185
2019-11-16 05:46:05,158 [salt.state       :1780][INFO    ][16617] Running state [maas.deploy_machines] at time 05:46:05.158389
2019-11-16 05:46:05,158 [salt.state       :1813][INFO    ][16617] Executing state module.run for [maas.deploy_machines]
2019-11-16 05:46:05,159 [salt.utils.decorators:613 ][WARNING ][16617] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:46:05,880 [salt.state       :300 ][INFO    ][16617] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-16 05:46:05,880 [salt.state       :1951][INFO    ][16617] Completed state [maas.deploy_machines] at time 05:46:05.880525 duration_in_ms=722.134
2019-11-16 05:46:05,884 [salt.minion      :1711][INFO    ][16617] Returning information for job: 20191116054602792818
2019-11-16 05:46:06,496 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command state.apply with jid 20191116054606482309
2019-11-16 05:46:06,518 [salt.minion      :1432][INFO    ][16636] Starting a new job with PID 16636
2019-11-16 05:46:07,297 [salt.state       :915 ][INFO    ][16636] Loading fresh modules for state activity
2019-11-16 05:46:07,386 [salt.state       :1780][INFO    ][16636] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:46:07.386016
2019-11-16 05:46:07,386 [salt.state       :1813][INFO    ][16636] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-16 05:46:07,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16636] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-16 05:46:08,734 [salt.state       :300 ][INFO    ][16636] {'pid': 16646, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-16 05:46:08,735 [salt.state       :1951][INFO    ][16636] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:46:08.735293 duration_in_ms=1349.276
2019-11-16 05:46:08,738 [salt.state       :1780][INFO    ][16636] Running state [maas.wait_for_machine_status] at time 05:46:08.738379
2019-11-16 05:46:08,738 [salt.state       :1813][INFO    ][16636] Executing state module.run for [maas.wait_for_machine_status]
2019-11-16 05:46:08,739 [salt.utils.decorators:613 ][WARNING ][16636] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-16 05:46:12,124 [salt.state       :300 ][INFO    ][16636] {'ret': True}
2019-11-16 05:46:12,125 [salt.state       :1951][INFO    ][16636] Completed state [maas.wait_for_machine_status] at time 05:46:12.124940 duration_in_ms=3386.56
2019-11-16 05:46:12,128 [salt.minion      :1711][INFO    ][16636] Returning information for job: 20191116054606482309
2019-11-16 06:14:59,532 [salt.utils.schedule:1377][INFO    ][8652] Running scheduled job: __mine_interval
2019-11-16 07:14:59,532 [salt.utils.schedule:1377][INFO    ][8652] Running scheduled job: __mine_interval
2019-11-16 07:16:43,394 [salt.minion      :1308][INFO    ][8652] User sudo_ubuntu Executing command cp.push_dir with jid 20191116071643383217
2019-11-16 07:16:43,416 [salt.minion      :1432][INFO    ][23066] Starting a new job with PID 23066
