2019-04-25 05:08:05,140 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-25 05:08:55,188 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-25 05:09:45,230 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-25 05:10:35,273 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-25 05:11:25,323 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-25 05:13:34,031 [salt.utils.decorators:613 ][WARNING ][2596] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:13:34,625 [salt.utils.decorators:613 ][WARNING ][2596] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:13:36,647 [salt.loaded.int.states.file:2298][WARNING ][2745] 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-04-25 05:13:42,366 [salt.state       :2022][WARNING ][2844] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-25 05:13:45,019 [salt.utils.decorators:613 ][WARNING ][2844] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:13:58,459 [salt.utils.decorators:613 ][WARNING ][2844] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:14:32,055 [salt.utils.decorators:613 ][WARNING ][2844] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:14:33,000 [salt.utils.decorators:613 ][WARNING ][2844] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:14:36,662 [salt.loaded.ext.module.maasng:1008][WARNING ][2844] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-04-25 05:14:36,663 [salt.loaded.ext.module.maasng:1011][WARNING ][2844] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-04-25 05:14:37,351 [salt.loaded.ext.module.maasng:1235][WARNING ][2844] Ignoring parameter vlan:0
2019-04-25 05:14:38,810 [salt.utils.decorators:613 ][WARNING ][2844] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:14:44,805 [salt.utils.decorators:613 ][WARNING ][5753] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:14:44,879 [salt.loaded.ext.module.maas:412 ][WARNING ][5753] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:14:46,683 [salt.loaded.ext.module.maas:412 ][WARNING ][5753] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:14:48,036 [salt.loaded.ext.module.maas:412 ][WARNING ][5753] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:14:49,385 [salt.loaded.ext.module.maas:412 ][WARNING ][5753] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:14:50,791 [salt.loaded.ext.module.maas:412 ][WARNING ][5753] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:14:53,650 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6360] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-25 05:14:53,682 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6360] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-04-25 05:14:53,705 [salt.utils.parsers:1051][WARNING ][359] Minion received a SIGTERM. Exiting.
2019-04-25 05:14:54,740 [salt.cli.daemons :293 ][INFO    ][6413] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-04-25 05:14:54,841 [salt.cli.daemons :82  ][INFO    ][6413] Starting up the Salt Minion
2019-04-25 05:14:54,842 [salt.utils.event :1017][INFO    ][6413] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-04-25 05:14:55,733 [salt.minion      :976 ][INFO    ][6413] Creating minion process manager
2019-04-25 05:14:57,104 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6413] Executing command ['date', '+%z'] in directory '/root'
2019-04-25 05:14:57,122 [salt.utils.schedule:568 ][INFO    ][6413] Updating job settings for scheduled job: __mine_interval
2019-04-25 05:14:57,123 [salt.minion      :1108][INFO    ][6413] Added mine.update to scheduler
2019-04-25 05:14:57,127 [salt.minion      :1975][INFO    ][6413] Minion is starting as user 'root'
2019-04-25 05:14:57,139 [salt.minion      :2336][INFO    ][6413] Minion is ready to receive requests!
2019-04-25 05:15:22,797 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425051522784026
2019-04-25 05:15:22,820 [salt.minion      :1432][INFO    ][6510] Starting a new job with PID 6510
2019-04-25 05:15:26,660 [salt.state       :915 ][INFO    ][6510] Loading fresh modules for state activity
2019-04-25 05:15:26,712 [salt.fileclient  :1219][INFO    ][6510] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-04-25 05:15:26,756 [salt.state       :1780][INFO    ][6510] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:26.756351
2019-04-25 05:15:26,756 [salt.state       :1813][INFO    ][6510] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:15:26,758 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6510] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:15:28,225 [salt.state       :300 ][INFO    ][6510] {'pid': 6518, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:15:28,226 [salt.state       :1951][INFO    ][6510] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:28.226626 duration_in_ms=1470.274
2019-04-25 05:15:28,230 [salt.state       :1780][INFO    ][6510] Running state [maas.wait_for_machine_status] at time 05:15:28.229943
2019-04-25 05:15:28,230 [salt.state       :1813][INFO    ][6510] Executing state module.run for [maas.wait_for_machine_status]
2019-04-25 05:15:28,231 [salt.utils.decorators:613 ][WARNING ][6510] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:15:29,224 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.01737189s left)
2019-04-25 05:15:37,832 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051537815466
2019-04-25 05:15:37,854 [salt.minion      :1432][INFO    ][6530] Starting a new job with PID 6530
2019-04-25 05:15:37,878 [salt.minion      :1711][INFO    ][6530] Returning information for job: 20190425051537815466
2019-04-25 05:16:00,232 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.00946593s left)
2019-04-25 05:16:07,881 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051607864729
2019-04-25 05:16:07,903 [salt.minion      :1432][INFO    ][6582] Starting a new job with PID 6582
2019-04-25 05:16:07,928 [salt.minion      :1711][INFO    ][6582] Returning information for job: 20190425051607864729
2019-04-25 05:16:31,158 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.08304s left)
2019-04-25 05:16:37,931 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051637919962
2019-04-25 05:16:37,950 [salt.minion      :1432][INFO    ][6719] Starting a new job with PID 6719
2019-04-25 05:16:37,971 [salt.minion      :1711][INFO    ][6719] Returning information for job: 20190425051637919962
2019-04-25 05:17:02,607 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.63389897s left)
2019-04-25 05:17:07,977 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051707964320
2019-04-25 05:17:07,998 [salt.minion      :1432][INFO    ][6869] Starting a new job with PID 6869
2019-04-25 05:17:08,020 [salt.minion      :1711][INFO    ][6869] Returning information for job: 20190425051707964320
2019-04-25 05:17:34,379 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.86241293s left)
2019-04-25 05:17:38,030 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051738017245
2019-04-25 05:17:38,053 [salt.minion      :1432][INFO    ][7032] Starting a new job with PID 7032
2019-04-25 05:17:38,080 [salt.minion      :1711][INFO    ][7032] Returning information for job: 20190425051738017245
2019-04-25 05:18:05,836 [salt.loaded.ext.module.maas:1023][INFO    ][6510] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.40550494s left)
2019-04-25 05:18:08,088 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051808076418
2019-04-25 05:18:08,107 [salt.minion      :1432][INFO    ][7628] Starting a new job with PID 7628
2019-04-25 05:18:08,127 [salt.minion      :1711][INFO    ][7628] Returning information for job: 20190425051808076418
2019-04-25 05:18:38,143 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051838131241
2019-04-25 05:18:38,159 [salt.minion      :1432][INFO    ][7818] Starting a new job with PID 7818
2019-04-25 05:18:38,175 [salt.minion      :1711][INFO    ][7818] Returning information for job: 20190425051838131241
2019-04-25 05:18:39,155 [salt.state       :300 ][INFO    ][6510] {'ret': True}
2019-04-25 05:18:39,156 [salt.state       :1951][INFO    ][6510] Completed state [maas.wait_for_machine_status] at time 05:18:39.155934 duration_in_ms=190925.99
2019-04-25 05:18:39,159 [salt.minion      :1711][INFO    ][6510] Returning information for job: 20190425051522784026
2019-04-25 05:18:39,791 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425051839774614
2019-04-25 05:18:39,813 [salt.minion      :1432][INFO    ][7826] Starting a new job with PID 7826
2019-04-25 05:18:43,559 [salt.state       :915 ][INFO    ][7826] Loading fresh modules for state activity
2019-04-25 05:18:43,612 [salt.fileclient  :1219][INFO    ][7826] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-04-25 05:18:43,701 [salt.state       :1780][INFO    ][7826] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:43.701004
2019-04-25 05:18:43,701 [salt.state       :1813][INFO    ][7826] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:18:43,703 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7826] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:18:45,224 [salt.state       :300 ][INFO    ][7826] {'pid': 7833, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:18:45,225 [salt.state       :1951][INFO    ][7826] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:45.225542 duration_in_ms=1524.537
2019-04-25 05:18:45,228 [salt.state       :1780][INFO    ][7826] Running state [maas_machines_storage_cmp002_lvm] at time 05:18:45.228175
2019-04-25 05:18:45,228 [salt.state       :1813][INFO    ][7826] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-25 05:18:46,624 [salt.loaded.ext.module.maasng:610 ][INFO    ][7826] rtwfkh
2019-04-25 05:18:46,625 [salt.loaded.ext.module.maasng:626 ][INFO    ][7826] sda
2019-04-25 05:18:47,183 [salt.loaded.ext.module.maasng:361 ][INFO    ][7826] rtwfkh
2019-04-25 05:18:47,298 [salt.loaded.ext.module.maasng:367 ][INFO    ][7826] [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'b3a197d4-bea8-4f00-87f4-c99611138f51', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rtwfkh', u'filesystem': {u'uuid': u'b47aa2cd-35ea-4d6f-b14b-2cb35b204fdd', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/partition/8'}], u'id': 5, u'system_id': u'rtwfkh', 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'block_size': 4096, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/'}, {u'size': 2397988454400, u'available_size': 0, u'uuid': u'14290c9b-3123-4d80-ac95-4d833d192c88', u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'partitions': [], u'id': 13, u'system_id': u'rtwfkh', u'partition_table_type': None, u'filesystem': {u'uuid': u'a1232775-5419-4107-8c39-11f02a5c2cf6', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/13/'}]
2019-04-25 05:18:47,298 [salt.loaded.ext.module.maasng:632 ][INFO    ][7826] vgroot
2019-04-25 05:18:47,299 [salt.loaded.ext.module.maasng:635 ][INFO    ][7826] lvroot
2019-04-25 05:18:47,299 [salt.loaded.ext.module.maasng:639 ][INFO    ][7826] 107374182400
2019-04-25 05:18:48,006 [salt.loaded.ext.module.maasng:645 ][INFO    ][7826] {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'status_action': u'modules-final', u'swap_size': None, u'ip_addresses': [u'192.168.11.42'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'memory_test_status_name': u'Unknown', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 47, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6a', 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'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', 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'effective_mtu': 1500, u'system_id': u'rtwfkh', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/interfaces/4/'}, u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 5, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'rtwfkh', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'5d542466-dba2-48ac-9aa6-2fd471f44c44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rtwfkh', u'filesystem': {u'label': None, u'uuid': u'53b41fa4-1f94-4c7f-a0b7-0b9e2bdc7681', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/partition/9', u'type': u'partition', u'id': 9, u'device_id': 5}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/'}, u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/rtwfkh/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'hwe_kernel': u'', u'owner_data': {}, u'system_id': u'rtwfkh', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'id': 14, u'uuid': u'e7442f03-84b7-4258-b464-fa4a3b5116b5', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'rtwfkh', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'279a1737-e3e2-4daa-a919-031145d5f658', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/14/'}], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'id': 5, u'system_id': u'rtwfkh', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'5d542466-dba2-48ac-9aa6-2fd471f44c44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rtwfkh', u'filesystem': {u'label': None, u'uuid': u'53b41fa4-1f94-4c7f-a0b7-0b9e2bdc7681', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/partition/9', u'type': u'partition', u'id': 9, u'device_id': 5}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/'}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'filesystem': {u'label': u'root', u'uuid': u'279a1737-e3e2-4daa-a919-031145d5f658', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'uuid': u'e7442f03-84b7-4258-b464-fa4a3b5116b5', u'id': 14, u'system_id': u'rtwfkh', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/14/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'on', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 5, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'rtwfkh', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'5d542466-dba2-48ac-9aa6-2fd471f44c44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rtwfkh', u'filesystem': {u'label': None, u'uuid': u'53b41fa4-1f94-4c7f-a0b7-0b9e2bdc7681', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/partition/9', u'type': u'partition', u'id': 9, u'device_id': 5}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/blockdevices/5/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'rtwfkh', u'id': 9}], u'special_filesystems': [], u'current_commissioning_result_id': 2, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 47, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6a', 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'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', 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'effective_mtu': 1500, u'system_id': u'rtwfkh', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'id': 48, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6b', u'id': 21, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'rtwfkh', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/interfaces/21/'}, {u'name': u'enp8s0', u'links': [{u'id': 49, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6c', u'id': 22, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'rtwfkh', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/interfaces/22/'}, {u'name': u'enp9s0', u'links': [{u'id': 50, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6d', u'id': 23, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'rtwfkh', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rtwfkh/interfaces/23/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-04-25 05:18:48,009 [salt.state       :300 ][INFO    ][7826] {'new': {'storage_layout': 'lvm'}}
2019-04-25 05:18:48,009 [salt.state       :1951][INFO    ][7826] Completed state [maas_machines_storage_cmp002_lvm] at time 05:18:48.009412 duration_in_ms=2781.236
2019-04-25 05:18:48,010 [salt.state       :1780][INFO    ][7826] Running state [maas_machines_storage_cmp001_lvm] at time 05:18:48.010004
2019-04-25 05:18:48,010 [salt.state       :1813][INFO    ][7826] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-25 05:18:49,350 [salt.loaded.ext.module.maasng:610 ][INFO    ][7826] gwryrd
2019-04-25 05:18:49,350 [salt.loaded.ext.module.maasng:626 ][INFO    ][7826] sda
2019-04-25 05:18:49,841 [salt.loaded.ext.module.maasng:361 ][INFO    ][7826] gwryrd
2019-04-25 05:18:49,975 [salt.loaded.ext.module.maasng:367 ][INFO    ][7826] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'bdb0b2e3-b776-484b-9d69-332f8f2d3dc8', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gwryrd', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'414f13ae-4193-448f-91aa-3258af834a11', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 3}], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'gwryrd', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/'}, {u'size': 2397988454400, u'model': None, u'uuid': u'59558b84-a266-4dee-83dc-c737f48a4ebd', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'partitions': [], u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'gwryrd', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ce6d4c23-811e-4e5d-98c4-e4b34d7fe651', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/12/'}]
2019-04-25 05:18:49,976 [salt.loaded.ext.module.maasng:632 ][INFO    ][7826] vgroot
2019-04-25 05:18:49,976 [salt.loaded.ext.module.maasng:635 ][INFO    ][7826] lvroot
2019-04-25 05:18:49,977 [salt.loaded.ext.module.maasng:639 ][INFO    ][7826] 107374182400
2019-04-25 05:18:50,624 [salt.loaded.ext.module.maasng:645 ][INFO    ][7826] {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'status_action': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'memory_test_status_name': u'Unknown', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 42, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', 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'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'gwryrd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 3, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'gwryrd', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6b60d8b9-e349-43ad-abd4-1b51057e6f83', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gwryrd', u'filesystem': {u'label': None, u'uuid': u'464d6092-b603-48dc-8c9b-6d480e48580a', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}], u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/'}, u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/gwryrd/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'hwe_kernel': u'', u'owner_data': {}, u'system_id': u'gwryrd', 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'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'id': 15, u'uuid': u'9cb7b376-4580-4772-b406-b3cdf736c344', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'gwryrd', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'908173c4-c229-4e95-8c54-82316ad27cce', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/15/'}], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'id': 3, u'system_id': u'gwryrd', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6b60d8b9-e349-43ad-abd4-1b51057e6f83', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gwryrd', u'filesystem': {u'label': None, u'uuid': u'464d6092-b603-48dc-8c9b-6d480e48580a', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}], u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/'}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'filesystem': {u'label': u'root', u'uuid': u'908173c4-c229-4e95-8c54-82316ad27cce', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'uuid': u'9cb7b376-4580-4772-b406-b3cdf736c344', u'id': 15, u'system_id': u'gwryrd', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/15/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 3, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'gwryrd', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6b60d8b9-e349-43ad-abd4-1b51057e6f83', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gwryrd', u'filesystem': {u'label': None, u'uuid': u'464d6092-b603-48dc-8c9b-6d480e48580a', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}], u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/blockdevices/3/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'gwryrd', u'id': 10}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 42, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', 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'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'gwryrd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'id': 43, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:5b', u'id': 13, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'gwryrd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/interfaces/13/'}, {u'name': u'enp8s0', u'links': [{u'id': 44, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:5c', u'id': 16, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'gwryrd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/interfaces/16/'}, {u'name': u'enp9s0', u'links': [{u'id': 45, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:5d', u'id': 17, u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'gwryrd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/gwryrd/interfaces/17/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-04-25 05:18:50,627 [salt.state       :300 ][INFO    ][7826] {'new': {'storage_layout': 'lvm'}}
2019-04-25 05:18:50,628 [salt.state       :1951][INFO    ][7826] Completed state [maas_machines_storage_cmp001_lvm] at time 05:18:50.628111 duration_in_ms=2618.104
2019-04-25 05:18:50,633 [salt.minion      :1711][INFO    ][7826] Returning information for job: 20190425051839774614
2019-04-25 05:18:51,280 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425051851263684
2019-04-25 05:18:51,302 [salt.minion      :1432][INFO    ][7999] Starting a new job with PID 7999
2019-04-25 05:18:52,083 [salt.state       :915 ][INFO    ][7999] Loading fresh modules for state activity
2019-04-25 05:18:52,136 [salt.fileclient  :1219][INFO    ][7999] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-04-25 05:18:52,182 [salt.state       :1780][INFO    ][7999] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:52.181932
2019-04-25 05:18:52,182 [salt.state       :1813][INFO    ][7999] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:18:52,184 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7999] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:18:53,657 [salt.state       :300 ][INFO    ][7999] {'pid': 8014, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:18:53,657 [salt.state       :1951][INFO    ][7999] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:53.657423 duration_in_ms=1475.492
2019-04-25 05:18:53,658 [salt.state       :1780][INFO    ][7999] Running state [maas.deploy_machines] at time 05:18:53.658635
2019-04-25 05:18:53,658 [salt.state       :1813][INFO    ][7999] Executing state module.run for [maas.deploy_machines]
2019-04-25 05:18:53,659 [salt.utils.decorators:613 ][WARNING ][7999] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:18:54,190 [salt.loaded.ext.module.maas:684 ][INFO    ][7999] deploymachines hwe_kernel=hwe-16.04 system_id=rtwfkh distro_series=xenial
2019-04-25 05:18:56,654 [salt.loaded.ext.module.maas:684 ][INFO    ][7999] deploymachines hwe_kernel=hwe-16.04 system_id=gwryrd distro_series=xenial
2019-04-25 05:18:59,273 [salt.loaded.ext.module.maas:684 ][INFO    ][7999] deploymachines hwe_kernel=hwe-16.04 system_id=nycn64 distro_series=xenial
2019-04-25 05:19:01,998 [salt.loaded.ext.module.maas:684 ][INFO    ][7999] deploymachines hwe_kernel=hwe-16.04 system_id=8xx7sg distro_series=xenial
2019-04-25 05:19:04,819 [salt.loaded.ext.module.maas:684 ][INFO    ][7999] deploymachines hwe_kernel=hwe-16.04 system_id=4dwbhn distro_series=xenial
2019-04-25 05:19:06,357 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051906344472
2019-04-25 05:19:06,376 [salt.minion      :1432][INFO    ][8274] Starting a new job with PID 8274
2019-04-25 05:19:06,399 [salt.minion      :1711][INFO    ][8274] Returning information for job: 20190425051906344472
2019-04-25 05:19:07,475 [salt.state       :300 ][INFO    ][7999] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-04-25 05:19:07,475 [salt.state       :1951][INFO    ][7999] Completed state [maas.deploy_machines] at time 05:19:07.475519 duration_in_ms=13816.881
2019-04-25 05:19:07,479 [salt.minion      :1711][INFO    ][7999] Returning information for job: 20190425051851263684
2019-04-25 05:19:08,120 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425051908108147
2019-04-25 05:19:08,141 [salt.minion      :1432][INFO    ][8293] Starting a new job with PID 8293
2019-04-25 05:19:11,472 [salt.state       :915 ][INFO    ][8293] Loading fresh modules for state activity
2019-04-25 05:19:11,524 [salt.fileclient  :1219][INFO    ][8293] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-04-25 05:19:11,571 [salt.state       :1780][INFO    ][8293] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:11.571896
2019-04-25 05:19:11,572 [salt.state       :1813][INFO    ][8293] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:19:11,574 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8293] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:19:12,931 [salt.state       :300 ][INFO    ][8293] {'pid': 8305, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:19:12,932 [salt.state       :1951][INFO    ][8293] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:12.932289 duration_in_ms=1360.395
2019-04-25 05:19:12,933 [salt.state       :1780][INFO    ][8293] Running state [maas.wait_for_machine_status] at time 05:19:12.933805
2019-04-25 05:19:12,934 [salt.state       :1813][INFO    ][8293] Executing state module.run for [maas.wait_for_machine_status]
2019-04-25 05:19:12,934 [salt.utils.decorators:613 ][WARNING ][8293] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:19:16,334 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.60407901s left)
2019-04-25 05:19:23,202 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051923187388
2019-04-25 05:19:23,224 [salt.minion      :1432][INFO    ][8323] Starting a new job with PID 8323
2019-04-25 05:19:23,249 [salt.minion      :1711][INFO    ][8323] Returning information for job: 20190425051923187388
2019-04-25 05:19:49,765 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.17323995s left)
2019-04-25 05:19:53,259 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425051953245147
2019-04-25 05:19:53,282 [salt.minion      :1432][INFO    ][8379] Starting a new job with PID 8379
2019-04-25 05:19:53,306 [salt.minion      :1711][INFO    ][8379] Returning information for job: 20190425051953245147
2019-04-25 05:20:23,313 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.62526608s left)
2019-04-25 05:20:23,352 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052023339789
2019-04-25 05:20:23,374 [salt.minion      :1432][INFO    ][8398] Starting a new job with PID 8398
2019-04-25 05:20:23,399 [salt.minion      :1711][INFO    ][8398] Returning information for job: 20190425052023339789
2019-04-25 05:20:53,398 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052053387561
2019-04-25 05:20:53,420 [salt.minion      :1432][INFO    ][8537] Starting a new job with PID 8537
2019-04-25 05:20:53,442 [salt.minion      :1711][INFO    ][8537] Returning information for job: 20190425052053387561
2019-04-25 05:20:56,955 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2145.98336816s left)
2019-04-25 05:21:23,455 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052123442805
2019-04-25 05:21:23,477 [salt.minion      :1432][INFO    ][8708] Starting a new job with PID 8708
2019-04-25 05:21:23,502 [salt.minion      :1711][INFO    ][8708] Returning information for job: 20190425052123442805
2019-04-25 05:21:30,261 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.67718005s left)
2019-04-25 05:21:53,516 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052153502896
2019-04-25 05:21:53,538 [salt.minion      :1432][INFO    ][9492] Starting a new job with PID 9492
2019-04-25 05:21:53,562 [salt.minion      :1711][INFO    ][9492] Returning information for job: 20190425052153502896
2019-04-25 05:22:03,485 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.45344996s left)
2019-04-25 05:22:23,572 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052223559434
2019-04-25 05:22:23,594 [salt.minion      :1432][INFO    ][9513] Starting a new job with PID 9513
2019-04-25 05:22:23,616 [salt.minion      :1711][INFO    ][9513] Returning information for job: 20190425052223559434
2019-04-25 05:22:37,157 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.78158498s left)
2019-04-25 05:22:53,635 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052253622436
2019-04-25 05:22:53,658 [salt.minion      :1432][INFO    ][9657] Starting a new job with PID 9657
2019-04-25 05:22:53,681 [salt.minion      :1711][INFO    ][9657] Returning information for job: 20190425052253622436
2019-04-25 05:23:10,143 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.79555202s left)
2019-04-25 05:23:23,701 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052323687836
2019-04-25 05:23:23,723 [salt.minion      :1432][INFO    ][9687] Starting a new job with PID 9687
2019-04-25 05:23:23,746 [salt.minion      :1711][INFO    ][9687] Returning information for job: 20190425052323687836
2019-04-25 05:23:42,837 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.10103607s left)
2019-04-25 05:23:53,777 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052353760925
2019-04-25 05:23:53,800 [salt.minion      :1432][INFO    ][10323] Starting a new job with PID 10323
2019-04-25 05:23:53,824 [salt.minion      :1711][INFO    ][10323] Returning information for job: 20190425052353760925
2019-04-25 05:24:16,416 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.52228808s left)
2019-04-25 05:24:23,853 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052423839791
2019-04-25 05:24:23,874 [salt.minion      :1432][INFO    ][10357] Starting a new job with PID 10357
2019-04-25 05:24:23,896 [salt.minion      :1711][INFO    ][10357] Returning information for job: 20190425052423839791
2019-04-25 05:24:49,535 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.40315795s left)
2019-04-25 05:24:53,922 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052453909831
2019-04-25 05:24:53,944 [salt.minion      :1432][INFO    ][10752] Starting a new job with PID 10752
2019-04-25 05:24:53,968 [salt.minion      :1711][INFO    ][10752] Returning information for job: 20190425052453909831
2019-04-25 05:25:23,086 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.85242796s left)
2019-04-25 05:25:24,006 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052523994022
2019-04-25 05:25:24,028 [salt.minion      :1432][INFO    ][10776] Starting a new job with PID 10776
2019-04-25 05:25:24,050 [salt.minion      :1711][INFO    ][10776] Returning information for job: 20190425052523994022
2019-04-25 05:25:54,092 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052554079273
2019-04-25 05:25:54,115 [salt.minion      :1432][INFO    ][10831] Starting a new job with PID 10831
2019-04-25 05:25:54,137 [salt.minion      :1711][INFO    ][10831] Returning information for job: 20190425052554079273
2019-04-25 05:25:56,429 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.50996113s left)
2019-04-25 05:26:24,194 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052624181140
2019-04-25 05:26:24,216 [salt.minion      :1432][INFO    ][10977] Starting a new job with PID 10977
2019-04-25 05:26:24,240 [salt.minion      :1711][INFO    ][10977] Returning information for job: 20190425052624181140
2019-04-25 05:26:29,602 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.33684301s left)
2019-04-25 05:26:54,287 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052654275648
2019-04-25 05:26:54,307 [salt.minion      :1432][INFO    ][11396] Starting a new job with PID 11396
2019-04-25 05:26:54,328 [salt.minion      :1711][INFO    ][11396] Returning information for job: 20190425052654275648
2019-04-25 05:27:02,615 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1780.32315397s left)
2019-04-25 05:27:24,387 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052724374843
2019-04-25 05:27:24,410 [salt.minion      :1432][INFO    ][11412] Starting a new job with PID 11412
2019-04-25 05:27:24,434 [salt.minion      :1711][INFO    ][11412] Returning information for job: 20190425052724374843
2019-04-25 05:27:35,726 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1747.21288013s left)
2019-04-25 05:27:54,501 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052754488735
2019-04-25 05:27:54,525 [salt.minion      :1432][INFO    ][11558] Starting a new job with PID 11558
2019-04-25 05:27:54,549 [salt.minion      :1711][INFO    ][11558] Returning information for job: 20190425052754488735
2019-04-25 05:28:09,005 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1713.93356895s left)
2019-04-25 05:28:24,630 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052824614102
2019-04-25 05:28:24,652 [salt.minion      :1432][INFO    ][11578] Starting a new job with PID 11578
2019-04-25 05:28:24,676 [salt.minion      :1711][INFO    ][11578] Returning information for job: 20190425052824614102
2019-04-25 05:28:42,329 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1680.60925007s left)
2019-04-25 05:28:54,765 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052854750107
2019-04-25 05:28:54,788 [salt.minion      :1432][INFO    ][11631] Starting a new job with PID 11631
2019-04-25 05:28:54,811 [salt.minion      :1711][INFO    ][11631] Returning information for job: 20190425052854750107
2019-04-25 05:29:15,818 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1647.12083697s left)
2019-04-25 05:29:24,888 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052924874971
2019-04-25 05:29:24,911 [salt.minion      :1432][INFO    ][11651] Starting a new job with PID 11651
2019-04-25 05:29:24,934 [salt.minion      :1711][INFO    ][11651] Returning information for job: 20190425052924874971
2019-04-25 05:29:49,336 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1613.60283494s left)
2019-04-25 05:29:55,038 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425052955023666
2019-04-25 05:29:55,060 [salt.minion      :1432][INFO    ][11707] Starting a new job with PID 11707
2019-04-25 05:29:55,084 [salt.minion      :1711][INFO    ][11707] Returning information for job: 20190425052955023666
2019-04-25 05:30:23,002 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1579.93732095s left)
2019-04-25 05:30:25,198 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053025183321
2019-04-25 05:30:25,221 [salt.minion      :1432][INFO    ][11729] Starting a new job with PID 11729
2019-04-25 05:30:25,244 [salt.minion      :1711][INFO    ][11729] Returning information for job: 20190425053025183321
2019-04-25 05:30:55,362 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053055350351
2019-04-25 05:30:55,384 [salt.minion      :1432][INFO    ][11793] Starting a new job with PID 11793
2019-04-25 05:30:55,408 [salt.minion      :1711][INFO    ][11793] Returning information for job: 20190425053055350351
2019-04-25 05:30:56,533 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1546.40592408s left)
2019-04-25 05:31:25,534 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053125517468
2019-04-25 05:31:25,556 [salt.minion      :1432][INFO    ][11808] Starting a new job with PID 11808
2019-04-25 05:31:25,580 [salt.minion      :1711][INFO    ][11808] Returning information for job: 20190425053125517468
2019-04-25 05:31:29,800 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1513.13852406s left)
2019-04-25 05:31:55,717 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053155704075
2019-04-25 05:31:55,739 [salt.minion      :1432][INFO    ][11867] Starting a new job with PID 11867
2019-04-25 05:31:55,763 [salt.minion      :1711][INFO    ][11867] Returning information for job: 20190425053155704075
2019-04-25 05:32:03,015 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1479.92314911s left)
2019-04-25 05:32:25,905 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053225892913
2019-04-25 05:32:25,927 [salt.minion      :1432][INFO    ][11886] Starting a new job with PID 11886
2019-04-25 05:32:25,951 [salt.minion      :1711][INFO    ][11886] Returning information for job: 20190425053225892913
2019-04-25 05:32:36,327 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1446.61174703s left)
2019-04-25 05:32:56,107 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053256093817
2019-04-25 05:32:56,130 [salt.minion      :1432][INFO    ][11942] Starting a new job with PID 11942
2019-04-25 05:32:56,152 [salt.minion      :1711][INFO    ][11942] Returning information for job: 20190425053256093817
2019-04-25 05:33:09,999 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1412.93998408s left)
2019-04-25 05:33:26,320 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053326308129
2019-04-25 05:33:26,342 [salt.minion      :1432][INFO    ][11962] Starting a new job with PID 11962
2019-04-25 05:33:26,365 [salt.minion      :1711][INFO    ][11962] Returning information for job: 20190425053326308129
2019-04-25 05:33:43,468 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1379.47020817s left)
2019-04-25 05:33:56,539 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053356526183
2019-04-25 05:33:56,561 [salt.minion      :1432][INFO    ][12158] Starting a new job with PID 12158
2019-04-25 05:33:56,583 [salt.minion      :1711][INFO    ][12158] Returning information for job: 20190425053356526183
2019-04-25 05:34:16,953 [salt.loaded.ext.module.maas:1023][INFO    ][8293] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1345.98602509s left)
2019-04-25 05:34:26,564 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053426551885
2019-04-25 05:34:26,586 [salt.minion      :1432][INFO    ][12185] Starting a new job with PID 12185
2019-04-25 05:34:26,610 [salt.minion      :1711][INFO    ][12185] Returning information for job: 20190425053426551885
2019-04-25 05:34:50,106 [salt.loaded.ext.module.maas:993 ][INFO    ][8293] Machine 4dwbhn mark broken
2019-04-25 05:34:50,874 [salt.loaded.ext.module.maas:996 ][INFO    ][8293] Machine 4dwbhn mark fixed
2019-04-25 05:34:52,047 [salt.loaded.ext.module.maas:684 ][INFO    ][8293] deploymachines hwe_kernel=hwe-16.04 system_id=4dwbhn distro_series=xenial
2019-04-25 05:34:54,808 [salt.loaded.ext.module.maas:160 ][ERROR   ][8293] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-04-25 05:34:54,810 [salt.state       :302 ][ERROR   ][8293] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-04-25 05:34:54,811 [salt.state       :1951][INFO    ][8293] Completed state [maas.wait_for_machine_status] at time 05:34:54.810871 duration_in_ms=941877.059
2019-04-25 05:34:54,820 [salt.minion      :1711][INFO    ][8293] Returning information for job: 20190425051908108147
2019-04-25 05:35:05,553 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command pillar.get with jid 20190425053505541018
2019-04-25 05:35:05,574 [salt.minion      :1432][INFO    ][12319] Starting a new job with PID 12319
2019-04-25 05:35:05,583 [salt.minion      :1711][INFO    ][12319] Returning information for job: 20190425053505541018
2019-04-25 05:35:06,087 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command service.status with jid 20190425053506073595
2019-04-25 05:35:06,108 [salt.minion      :1432][INFO    ][12324] Starting a new job with PID 12324
2019-04-25 05:35:06,496 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12324] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:06,530 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12324] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-04-25 05:35:06,545 [salt.minion      :1711][INFO    ][12324] Returning information for job: 20190425053506073595
2019-04-25 05:35:07,048 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425053507035638
2019-04-25 05:35:07,069 [salt.minion      :1432][INFO    ][12335] Starting a new job with PID 12335
2019-04-25 05:35:10,589 [salt.state       :915 ][INFO    ][12335] Loading fresh modules for state activity
2019-04-25 05:35:11,028 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'salt-minion --version' in directory '/root'
2019-04-25 05:35:11,393 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'salt-minion --version' in directory '/root'
2019-04-25 05:35:12,291 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'salt-minion --version' in directory '/root'
2019-04-25 05:35:12,665 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'salt-minion --version' in directory '/root'
2019-04-25 05:35:14,074 [salt.state       :1780][INFO    ][12335] Running state [salt-minion] at time 05:35:14.074932
2019-04-25 05:35:14,075 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [salt-minion]
2019-04-25 05:35:14,075 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-25 05:35:14,186 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,186 [salt.state       :1951][INFO    ][12335] Completed state [salt-minion] at time 05:35:14.186754 duration_in_ms=111.822
2019-04-25 05:35:14,187 [salt.state       :1780][INFO    ][12335] Running state [salt_minion_dependency_packages] at time 05:35:14.187233
2019-04-25 05:35:14,187 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-04-25 05:35:14,197 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,197 [salt.state       :1951][INFO    ][12335] Completed state [salt_minion_dependency_packages] at time 05:35:14.197817 duration_in_ms=10.584
2019-04-25 05:35:14,202 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/minion.d/minion.conf] at time 05:35:14.202188
2019-04-25 05:35:14,202 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-04-25 05:35:14,436 [salt.state       :300 ][INFO    ][12335] File /etc/salt/minion.d/minion.conf is in the correct state
2019-04-25 05:35:14,436 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/minion.d/minion.conf] at time 05:35:14.436677 duration_in_ms=234.49
2019-04-25 05:35:14,436 [salt.state       :1780][INFO    ][12335] Running state [python-netaddr] at time 05:35:14.436873
2019-04-25 05:35:14,437 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [python-netaddr]
2019-04-25 05:35:14,442 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,442 [salt.state       :1951][INFO    ][12335] Completed state [python-netaddr] at time 05:35:14.442342 duration_in_ms=5.469
2019-04-25 05:35:14,444 [salt.state       :1780][INFO    ][12335] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:35:14.444698
2019-04-25 05:35:14,444 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-04-25 05:35:14,455 [salt.state       :300 ][INFO    ][12335] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-04-25 05:35:14,455 [salt.state       :1951][INFO    ][12335] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:35:14.455784 duration_in_ms=11.086
2019-04-25 05:35:14,456 [salt.state       :1780][INFO    ][12335] Running state [salt-minion] at time 05:35:14.456504
2019-04-25 05:35:14,456 [salt.state       :1813][INFO    ][12335] Executing state service.running for [salt-minion]
2019-04-25 05:35:14,457 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:14,493 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-04-25 05:35:14,509 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-04-25 05:35:14,526 [salt.state       :300 ][INFO    ][12335] The service salt-minion is already running
2019-04-25 05:35:14,526 [salt.state       :1951][INFO    ][12335] Completed state [salt-minion] at time 05:35:14.526696 duration_in_ms=70.191
2019-04-25 05:35:14,528 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains.d] at time 05:35:14.528032
2019-04-25 05:35:14,528 [salt.state       :1813][INFO    ][12335] Executing state file.directory for [/etc/salt/grains.d]
2019-04-25 05:35:14,529 [salt.state       :300 ][INFO    ][12335] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-04-25 05:35:14,529 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains.d] at time 05:35:14.529416 duration_in_ms=1.383
2019-04-25 05:35:14,530 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains] at time 05:35:14.530023
2019-04-25 05:35:14,530 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/grains]
2019-04-25 05:35:14,530 [salt.state       :300 ][INFO    ][12335] File /etc/salt/grains exists with proper permissions. No changes made.
2019-04-25 05:35:14,531 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains] at time 05:35:14.531004 duration_in_ms=0.981
2019-04-25 05:35:14,531 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains.d/placeholder] at time 05:35:14.531413
2019-04-25 05:35:14,531 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-04-25 05:35:14,532 [salt.state       :300 ][INFO    ][12335] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-04-25 05:35:14,532 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains.d/placeholder] at time 05:35:14.532363 duration_in_ms=0.949
2019-04-25 05:35:14,532 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains.d/sphinx] at time 05:35:14.532792
2019-04-25 05:35:14,533 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-04-25 05:35:14,544 [salt.state       :300 ][INFO    ][12335] File /etc/salt/grains.d/sphinx is in the correct state
2019-04-25 05:35:14,544 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains.d/sphinx] at time 05:35:14.544372 duration_in_ms=11.58
2019-04-25 05:35:14,546 [salt.state       :1780][INFO    ][12335] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.546401
2019-04-25 05:35:14,546 [salt.state       :1813][INFO    ][12335] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-04-25 05:35:14,547 [salt.state       :300 ][INFO    ][12335] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-04-25 05:35:14,547 [salt.state       :1951][INFO    ][12335] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.547205 duration_in_ms=0.804
2019-04-25 05:35:14,547 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains.d/dns_records] at time 05:35:14.547639
2019-04-25 05:35:14,547 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-04-25 05:35:14,562 [salt.state       :300 ][INFO    ][12335] File /etc/salt/grains.d/dns_records is in the correct state
2019-04-25 05:35:14,562 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains.d/dns_records] at time 05:35:14.562288 duration_in_ms=14.648
2019-04-25 05:35:14,563 [salt.state       :1780][INFO    ][12335] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.563149
2019-04-25 05:35:14,563 [salt.state       :1813][INFO    ][12335] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-04-25 05:35:14,563 [salt.state       :300 ][INFO    ][12335] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-04-25 05:35:14,564 [salt.state       :1951][INFO    ][12335] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.563964 duration_in_ms=0.815
2019-04-25 05:35:14,564 [salt.state       :1780][INFO    ][12335] Running state [/etc/salt/grains.d/salt] at time 05:35:14.564394
2019-04-25 05:35:14,564 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-04-25 05:35:14,580 [salt.state       :300 ][INFO    ][12335] File /etc/salt/grains.d/salt is in the correct state
2019-04-25 05:35:14,580 [salt.state       :1951][INFO    ][12335] Completed state [/etc/salt/grains.d/salt] at time 05:35:14.580248 duration_in_ms=15.853
2019-04-25 05:35:14,581 [salt.state       :1780][INFO    ][12335] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.581072
2019-04-25 05:35:14,581 [salt.state       :1813][INFO    ][12335] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-04-25 05:35:14,581 [salt.state       :300 ][INFO    ][12335] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-04-25 05:35:14,581 [salt.state       :1951][INFO    ][12335] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:35:14.581910 duration_in_ms=0.838
2019-04-25 05:35:14,583 [salt.state       :1780][INFO    ][12335] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:35:14.583650
2019-04-25 05:35:14,583 [salt.state       :1813][INFO    ][12335] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-04-25 05:35:14,584 [salt.state       :300 ][INFO    ][12335] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-04-25 05:35:14,584 [salt.state       :1951][INFO    ][12335] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:35:14.584491 duration_in_ms=0.829
2019-04-25 05:35:14,585 [salt.state       :1780][INFO    ][12335] Running state [mine.update] at time 05:35:14.585131
2019-04-25 05:35:14,585 [salt.state       :1813][INFO    ][12335] Executing state module.wait for [mine.update]
2019-04-25 05:35:14,585 [salt.state       :300 ][INFO    ][12335] No changes made for mine.update
2019-04-25 05:35:14,585 [salt.state       :1951][INFO    ][12335] Completed state [mine.update] at time 05:35:14.585922 duration_in_ms=0.791
2019-04-25 05:35:14,586 [salt.state       :1780][INFO    ][12335] Running state [ca-certificates] at time 05:35:14.586160
2019-04-25 05:35:14,586 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [ca-certificates]
2019-04-25 05:35:14,593 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,593 [salt.state       :1951][INFO    ][12335] Completed state [ca-certificates] at time 05:35:14.593609 duration_in_ms=7.448
2019-04-25 05:35:14,594 [salt.state       :1780][INFO    ][12335] Running state [update-ca-certificates] at time 05:35:14.594249
2019-04-25 05:35:14,594 [salt.state       :1813][INFO    ][12335] Executing state cmd.wait for [update-ca-certificates]
2019-04-25 05:35:14,594 [salt.state       :300 ][INFO    ][12335] No changes made for update-ca-certificates
2019-04-25 05:35:14,595 [salt.state       :1951][INFO    ][12335] Completed state [update-ca-certificates] at time 05:35:14.595037 duration_in_ms=0.788
2019-04-25 05:35:14,595 [salt.state       :1780][INFO    ][12335] Running state [iptables] at time 05:35:14.595270
2019-04-25 05:35:14,595 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [iptables]
2019-04-25 05:35:14,602 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,602 [salt.state       :1951][INFO    ][12335] Completed state [iptables] at time 05:35:14.602204 duration_in_ms=6.934
2019-04-25 05:35:14,602 [salt.state       :1780][INFO    ][12335] Running state [iptables-persistent] at time 05:35:14.602437
2019-04-25 05:35:14,602 [salt.state       :1813][INFO    ][12335] Executing state pkg.installed for [iptables-persistent]
2019-04-25 05:35:14,608 [salt.state       :300 ][INFO    ][12335] All specified packages are already installed
2019-04-25 05:35:14,609 [salt.state       :1951][INFO    ][12335] Completed state [iptables-persistent] at time 05:35:14.609122 duration_in_ms=6.684
2019-04-25 05:35:14,610 [salt.state       :1780][INFO    ][12335] Running state [iptables_modules_v4_load] at time 05:35:14.610053
2019-04-25 05:35:14,610 [salt.state       :1813][INFO    ][12335] Executing state kmod.present for [iptables_modules_v4_load]
2019-04-25 05:35:14,610 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'lsmod' in directory '/root'
2019-04-25 05:35:14,632 [salt.state       :300 ][INFO    ][12335] Kernel modules iptable_filter, ip_tables are already present
2019-04-25 05:35:14,633 [salt.state       :1951][INFO    ][12335] Completed state [iptables_modules_v4_load] at time 05:35:14.633243 duration_in_ms=23.19
2019-04-25 05:35:14,633 [salt.state       :1780][INFO    ][12335] Running state [/etc/iptables/rules.v4] at time 05:35:14.633840
2019-04-25 05:35:14,634 [salt.state       :1813][INFO    ][12335] Executing state file.managed for [/etc/iptables/rules.v4]
2019-04-25 05:35:14,717 [salt.state       :300 ][INFO    ][12335] File /etc/iptables/rules.v4 is in the correct state
2019-04-25 05:35:14,718 [salt.state       :1951][INFO    ][12335] Completed state [/etc/iptables/rules.v4] at time 05:35:14.718034 duration_in_ms=84.194
2019-04-25 05:35:14,718 [salt.state       :1780][INFO    ][12335] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:35:14.718847
2019-04-25 05:35:14,719 [salt.state       :1813][INFO    ][12335] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-04-25 05:35:14,719 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-04-25 05:35:14,739 [salt.state       :300 ][INFO    ][12335] onlyif execution failed
2019-04-25 05:35:14,739 [salt.state       :1951][INFO    ][12335] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:35:14.739510 duration_in_ms=20.662
2019-04-25 05:35:14,741 [salt.state       :1780][INFO    ][12335] Running state [netfilter-persistent] at time 05:35:14.741143
2019-04-25 05:35:14,741 [salt.state       :1813][INFO    ][12335] Executing state service.running for [netfilter-persistent]
2019-04-25 05:35:14,742 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:14,763 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-04-25 05:35:14,781 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-04-25 05:35:14,800 [salt.state       :300 ][INFO    ][12335] The service netfilter-persistent is already running
2019-04-25 05:35:14,801 [salt.state       :1951][INFO    ][12335] Completed state [netfilter-persistent] at time 05:35:14.801058 duration_in_ms=59.915
2019-04-25 05:35:14,802 [salt.state       :1780][INFO    ][12335] Running state [iptables_extra.remove_stale_tables] at time 05:35:14.802369
2019-04-25 05:35:14,802 [salt.state       :1813][INFO    ][12335] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-04-25 05:35:14,803 [salt.state       :300 ][INFO    ][12335] No changes made for iptables_extra.remove_stale_tables
2019-04-25 05:35:14,803 [salt.state       :1951][INFO    ][12335] Completed state [iptables_extra.remove_stale_tables] at time 05:35:14.803744 duration_in_ms=1.376
2019-04-25 05:35:14,804 [salt.state       :1780][INFO    ][12335] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:35:14.804119
2019-04-25 05:35:14,804 [salt.state       :1813][INFO    ][12335] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-04-25 05:35:14,805 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12335] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-04-25 05:35:14,820 [salt.state       :300 ][INFO    ][12335] onlyif execution failed
2019-04-25 05:35:14,821 [salt.state       :1951][INFO    ][12335] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:35:14.821359 duration_in_ms=17.239
2019-04-25 05:35:14,822 [salt.state       :1780][INFO    ][12335] Running state [/etc/iptables/rules.v6] at time 05:35:14.822822
2019-04-25 05:35:14,823 [salt.state       :1813][INFO    ][12335] Executing state file.absent for [/etc/iptables/rules.v6]
2019-04-25 05:35:14,824 [salt.state       :300 ][INFO    ][12335] File /etc/iptables/rules.v6 is not present
2019-04-25 05:35:14,824 [salt.state       :1951][INFO    ][12335] Completed state [/etc/iptables/rules.v6] at time 05:35:14.824278 duration_in_ms=1.456
2019-04-25 05:35:14,825 [salt.state       :1780][INFO    ][12335] Running state [iptables_extra.flush_all] at time 05:35:14.825263
2019-04-25 05:35:14,825 [salt.state       :1813][INFO    ][12335] Executing state module.wait for [iptables_extra.flush_all]
2019-04-25 05:35:14,826 [salt.state       :300 ][INFO    ][12335] No changes made for iptables_extra.flush_all
2019-04-25 05:35:14,826 [salt.state       :1951][INFO    ][12335] Completed state [iptables_extra.flush_all] at time 05:35:14.826405 duration_in_ms=1.141
2019-04-25 05:35:14,830 [salt.minion      :1711][INFO    ][12335] Returning information for job: 20190425053507035638
2019-04-25 05:35:15,450 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425053515437702
2019-04-25 05:35:15,472 [salt.minion      :1432][INFO    ][12421] Starting a new job with PID 12421
2019-04-25 05:35:16,180 [salt.state       :915 ][INFO    ][12421] Loading fresh modules for state activity
2019-04-25 05:35:16,766 [salt.state       :1780][INFO    ][12421] Running state [maas-rack-controller] at time 05:35:16.766695
2019-04-25 05:35:16,767 [salt.state       :1813][INFO    ][12421] Executing state pkg.installed for [maas-rack-controller]
2019-04-25 05:35:16,767 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12421] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-25 05:35:16,843 [salt.state       :300 ][INFO    ][12421] All specified packages are already installed
2019-04-25 05:35:16,843 [salt.state       :1951][INFO    ][12421] Completed state [maas-rack-controller] at time 05:35:16.843295 duration_in_ms=76.601
2019-04-25 05:35:16,843 [salt.state       :1780][INFO    ][12421] Running state [ipmitool] at time 05:35:16.843554
2019-04-25 05:35:16,843 [salt.state       :1813][INFO    ][12421] Executing state pkg.installed for [ipmitool]
2019-04-25 05:35:16,848 [salt.state       :300 ][INFO    ][12421] All specified packages are already installed
2019-04-25 05:35:16,848 [salt.state       :1951][INFO    ][12421] Completed state [ipmitool] at time 05:35:16.848417 duration_in_ms=4.863
2019-04-25 05:35:16,850 [salt.state       :1780][INFO    ][12421] Running state [/etc/maas/rackd.conf] at time 05:35:16.850700
2019-04-25 05:35:16,850 [salt.state       :1813][INFO    ][12421] Executing state file.line for [/etc/maas/rackd.conf]
2019-04-25 05:35:16,851 [salt.state       :300 ][INFO    ][12421] No changes needed to be made
2019-04-25 05:35:16,851 [salt.state       :1951][INFO    ][12421] Completed state [/etc/maas/rackd.conf] at time 05:35:16.851825 duration_in_ms=1.125
2019-04-25 05:35:16,852 [salt.state       :1780][INFO    ][12421] Running state [/etc/maas/rackd.conf] at time 05:35:16.851992
2019-04-25 05:35:16,852 [salt.state       :1813][INFO    ][12421] Executing state file.managed for [/etc/maas/rackd.conf]
2019-04-25 05:35:16,852 [salt.loaded.int.states.file:2298][WARNING ][12421] 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-04-25 05:35:16,852 [salt.state       :300 ][INFO    ][12421] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-04-25 05:35:16,852 [salt.state       :1951][INFO    ][12421] Completed state [/etc/maas/rackd.conf] at time 05:35:16.852875 duration_in_ms=0.884
2019-04-25 05:35:16,853 [salt.state       :1780][INFO    ][12421] Running state [maas-rackd] at time 05:35:16.853568
2019-04-25 05:35:16,853 [salt.state       :1813][INFO    ][12421] Executing state service.running for [maas-rackd]
2019-04-25 05:35:16,854 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12421] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:16,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12421] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-04-25 05:35:16,899 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12421] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-04-25 05:35:16,914 [salt.state       :300 ][INFO    ][12421] The service maas-rackd is already running
2019-04-25 05:35:16,914 [salt.state       :1951][INFO    ][12421] Completed state [maas-rackd] at time 05:35:16.914885 duration_in_ms=61.316
2019-04-25 05:35:16,916 [salt.minion      :1711][INFO    ][12421] Returning information for job: 20190425053515437702
2019-04-25 05:35:17,525 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425053517512100
2019-04-25 05:35:17,547 [salt.minion      :1432][INFO    ][12444] Starting a new job with PID 12444
2019-04-25 05:35:18,296 [salt.state       :915 ][INFO    ][12444] Loading fresh modules for state activity
2019-04-25 05:35:18,905 [salt.state       :1780][INFO    ][12444] Running state [maas-region-controller] at time 05:35:18.905074
2019-04-25 05:35:18,905 [salt.state       :1813][INFO    ][12444] Executing state pkg.installed for [maas-region-controller]
2019-04-25 05:35:18,905 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-25 05:35:19,006 [salt.state       :300 ][INFO    ][12444] All specified packages are already installed
2019-04-25 05:35:19,007 [salt.state       :1951][INFO    ][12444] Completed state [maas-region-controller] at time 05:35:19.007096 duration_in_ms=102.021
2019-04-25 05:35:19,007 [salt.state       :1780][INFO    ][12444] Running state [python-oauth] at time 05:35:19.007569
2019-04-25 05:35:19,008 [salt.state       :1813][INFO    ][12444] Executing state pkg.installed for [python-oauth]
2019-04-25 05:35:19,017 [salt.state       :300 ][INFO    ][12444] All specified packages are already installed
2019-04-25 05:35:19,018 [salt.state       :1951][INFO    ][12444] Completed state [python-oauth] at time 05:35:19.018197 duration_in_ms=10.628
2019-04-25 05:35:19,022 [salt.state       :1780][INFO    ][12444] Running state [/etc/maas/regiond.conf] at time 05:35:19.022590
2019-04-25 05:35:19,023 [salt.state       :1813][INFO    ][12444] Executing state file.replace for [/etc/maas/regiond.conf]
2019-04-25 05:35:19,079 [salt.state       :300 ][INFO    ][12444] No changes needed to be made
2019-04-25 05:35:19,079 [salt.state       :1951][INFO    ][12444] Completed state [/etc/maas/regiond.conf] at time 05:35:19.079455 duration_in_ms=56.864
2019-04-25 05:35:19,080 [salt.state       :1780][INFO    ][12444] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:35:19.080124
2019-04-25 05:35:19,080 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-04-25 05:35:19,150 [salt.state       :300 ][INFO    ][12444] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-04-25 05:35:19,150 [salt.state       :1951][INFO    ][12444] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:35:19.150458 duration_in_ms=70.334
2019-04-25 05:35:19,151 [salt.state       :1780][INFO    ][12444] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:35:19.151073
2019-04-25 05:35:19,151 [salt.state       :1813][INFO    ][12444] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-25 05:35:19,163 [salt.state       :300 ][INFO    ][12444] No changes needed to be made
2019-04-25 05:35:19,164 [salt.state       :1951][INFO    ][12444] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:35:19.164077 duration_in_ms=13.004
2019-04-25 05:35:19,164 [salt.state       :1780][INFO    ][12444] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:35:19.164666
2019-04-25 05:35:19,165 [salt.state       :1813][INFO    ][12444] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-25 05:35:19,187 [salt.state       :300 ][INFO    ][12444] No changes needed to be made
2019-04-25 05:35:19,187 [salt.state       :1951][INFO    ][12444] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:35:19.187751 duration_in_ms=23.085
2019-04-25 05:35:19,188 [salt.state       :1780][INFO    ][12444] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:35:19.188307
2019-04-25 05:35:19,188 [salt.state       :1813][INFO    ][12444] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-04-25 05:35:19,214 [salt.state       :300 ][INFO    ][12444] No changes needed to be made
2019-04-25 05:35:19,215 [salt.state       :1951][INFO    ][12444] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:35:19.215175 duration_in_ms=26.867
2019-04-25 05:35:19,215 [salt.state       :1780][INFO    ][12444] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:35:19.215683
2019-04-25 05:35:19,216 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-04-25 05:35:19,228 [salt.state       :300 ][INFO    ][12444] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-04-25 05:35:19,228 [salt.state       :1951][INFO    ][12444] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:35:19.228258 duration_in_ms=12.575
2019-04-25 05:35:19,229 [salt.state       :1780][INFO    ][12444] Running state [a2enmod headers] at time 05:35:19.229567
2019-04-25 05:35:19,229 [salt.state       :1813][INFO    ][12444] Executing state cmd.run for [a2enmod headers]
2019-04-25 05:35:19,230 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command 'a2enmod headers' in directory '/root'
2019-04-25 05:35:19,305 [salt.state       :300 ][INFO    ][12444] {'pid': 12463, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-04-25 05:35:19,306 [salt.state       :1951][INFO    ][12444] Completed state [a2enmod headers] at time 05:35:19.306207 duration_in_ms=76.639
2019-04-25 05:35:19,306 [salt.state       :1780][INFO    ][12444] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:35:19.306824
2019-04-25 05:35:19,307 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-04-25 05:35:19,326 [salt.state       :300 ][INFO    ][12444] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-04-25 05:35:19,327 [salt.state       :1951][INFO    ][12444] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:35:19.327295 duration_in_ms=20.47
2019-04-25 05:35:19,328 [salt.state       :1780][INFO    ][12444] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:35:19.328206
2019-04-25 05:35:19,328 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-04-25 05:35:19,408 [salt.state       :300 ][INFO    ][12444] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-04-25 05:35:19,408 [salt.state       :1951][INFO    ][12444] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:35:19.408535 duration_in_ms=80.329
2019-04-25 05:35:19,409 [salt.state       :1780][INFO    ][12444] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:35:19.409313
2019-04-25 05:35:19,409 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-04-25 05:35:19,492 [salt.state       :300 ][INFO    ][12444] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-04-25 05:35:19,492 [salt.state       :1951][INFO    ][12444] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:35:19.492580 duration_in_ms=83.266
2019-04-25 05:35:19,493 [salt.state       :1780][INFO    ][12444] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:35:19.493418
2019-04-25 05:35:19,493 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-04-25 05:35:19,551 [salt.state       :300 ][INFO    ][12444] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-04-25 05:35:19,551 [salt.state       :1951][INFO    ][12444] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:35:19.551657 duration_in_ms=58.24
2019-04-25 05:35:19,551 [salt.state       :1780][INFO    ][12444] Running state [/root/.pgpass] at time 05:35:19.551907
2019-04-25 05:35:19,552 [salt.state       :1813][INFO    ][12444] Executing state file.managed for [/root/.pgpass]
2019-04-25 05:35:19,593 [salt.state       :300 ][INFO    ][12444] File /root/.pgpass is in the correct state
2019-04-25 05:35:19,593 [salt.state       :1951][INFO    ][12444] Completed state [/root/.pgpass] at time 05:35:19.593497 duration_in_ms=41.571
2019-04-25 05:35:19,597 [salt.state       :1780][INFO    ][12444] Running state [maas-region syncdb --noinput] at time 05:35:19.597823
2019-04-25 05:35:19,598 [salt.state       :1813][INFO    ][12444] Executing state cmd.run for [maas-region syncdb --noinput]
2019-04-25 05:35:19,598 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-04-25 05:35:21,424 [salt.state       :300 ][INFO    ][12444] {'pid': 12476, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: piston3, metadataserver, sessions, auth, maasserver, contenttypes, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-04-25 05:35:21,424 [salt.state       :1951][INFO    ][12444] Completed state [maas-region syncdb --noinput] at time 05:35:21.424908 duration_in_ms=1827.085
2019-04-25 05:35:21,425 [salt.state       :2022][WARNING ][12444] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-25 05:35:21,426 [salt.state       :1780][INFO    ][12444] Running state [maas-regiond] at time 05:35:21.426122
2019-04-25 05:35:21,426 [salt.state       :1813][INFO    ][12444] Executing state service.running for [maas-regiond]
2019-04-25 05:35:21,426 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:21,461 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-04-25 05:35:21,476 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-04-25 05:35:21,492 [salt.state       :300 ][INFO    ][12444] The service maas-regiond is already running
2019-04-25 05:35:21,492 [salt.state       :1951][INFO    ][12444] Completed state [maas-regiond] at time 05:35:21.492493 duration_in_ms=66.371
2019-04-25 05:35:21,493 [salt.state       :1780][INFO    ][12444] Running state [bind9] at time 05:35:21.493512
2019-04-25 05:35:21,493 [salt.state       :1813][INFO    ][12444] Executing state service.running for [bind9]
2019-04-25 05:35:21,494 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:21,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-04-25 05:35:21,530 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-04-25 05:35:21,545 [salt.state       :300 ][INFO    ][12444] The service bind9 is already running
2019-04-25 05:35:21,546 [salt.state       :1951][INFO    ][12444] Completed state [bind9] at time 05:35:21.546100 duration_in_ms=52.587
2019-04-25 05:35:21,547 [salt.state       :1780][INFO    ][12444] Running state [apache2] at time 05:35:21.547205
2019-04-25 05:35:21,547 [salt.state       :1813][INFO    ][12444] Executing state service.running for [apache2]
2019-04-25 05:35:21,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-04-25 05:35:21,564 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-04-25 05:35:21,580 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-04-25 05:35:21,599 [salt.state       :300 ][INFO    ][12444] The service apache2 is already running
2019-04-25 05:35:21,600 [salt.state       :1951][INFO    ][12444] Completed state [apache2] at time 05:35:21.599991 duration_in_ms=52.786
2019-04-25 05:35:21,601 [salt.state       :1780][INFO    ][12444] Running state [maasng.wait_for_http_code] at time 05:35:21.600983
2019-04-25 05:35:21,601 [salt.state       :1813][INFO    ][12444] Executing state module.run for [maasng.wait_for_http_code]
2019-04-25 05:35:21,601 [salt.utils.decorators:613 ][WARNING ][12444] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:21,721 [salt.state       :300 ][INFO    ][12444] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-04-25 05:35:21,722 [salt.state       :1951][INFO    ][12444] Completed state [maasng.wait_for_http_code] at time 05:35:21.722375 duration_in_ms=121.39
2019-04-25 05:35:21,723 [salt.state       :1780][INFO    ][12444] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:35:21.723792
2019-04-25 05:35:21,724 [salt.state       :1813][INFO    ][12444] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-04-25 05:35:21,725 [salt.state       :300 ][INFO    ][12444] /var/lib/maas/.setup_admin exists
2019-04-25 05:35:21,725 [salt.state       :1951][INFO    ][12444] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:35:21.725411 duration_in_ms=1.619
2019-04-25 05:35:21,726 [salt.state       :1780][INFO    ][12444] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:35:21.726548
2019-04-25 05:35:21,727 [salt.state       :1813][INFO    ][12444] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:35:21,727 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12444] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:35:23,135 [salt.state       :300 ][INFO    ][12444] {'pid': 12497, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:35:23,136 [salt.state       :1951][INFO    ][12444] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:35:23.136594 duration_in_ms=1410.046
2019-04-25 05:35:23,145 [salt.state       :1780][INFO    ][12444] Running state [maas_region_boot_source_resources_mirror] at time 05:35:23.144952
2019-04-25 05:35:23,145 [salt.state       :1813][INFO    ][12444] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-04-25 05:35:23,260 [salt.state       :300 ][INFO    ][12444] {'changes': {}}
2019-04-25 05:35:23,260 [salt.state       :1951][INFO    ][12444] Completed state [maas_region_boot_source_resources_mirror] at time 05:35:23.260728 duration_in_ms=115.777
2019-04-25 05:35:23,261 [salt.state       :1780][INFO    ][12444] Running state [maasng.boot_resources_import] at time 05:35:23.261513
2019-04-25 05:35:23,261 [salt.state       :1813][INFO    ][12444] Executing state module.run for [maasng.boot_resources_import]
2019-04-25 05:35:23,262 [salt.utils.decorators:613 ][WARNING ][12444] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:23,363 [salt.loaded.ext.module.maasng:1600][INFO    ][12444] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-04-25 05:35:28,417 [salt.loaded.ext.module.maasng:1600][INFO    ][12444] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-04-25 05:35:32,570 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053532557261
2019-04-25 05:35:32,595 [salt.minion      :1432][INFO    ][12530] Starting a new job with PID 12530
2019-04-25 05:35:32,619 [salt.minion      :1711][INFO    ][12530] Returning information for job: 20190425053532557261
2019-04-25 05:35:33,481 [salt.loaded.ext.module.maasng:1600][INFO    ][12444] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-04-25 05:35:38,583 [salt.state       :300 ][INFO    ][12444] {'ret': True}
2019-04-25 05:35:38,583 [salt.state       :1951][INFO    ][12444] Completed state [maasng.boot_resources_import] at time 05:35:38.583693 duration_in_ms=15322.178
2019-04-25 05:35:38,584 [salt.state       :1780][INFO    ][12444] Running state [maas_region_boot_sources_selection_xenial] at time 05:35:38.584891
2019-04-25 05:35:38,585 [salt.state       :1813][INFO    ][12444] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-04-25 05:35:38,786 [salt.state       :300 ][INFO    ][12444] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-04-25 05:35:38,787 [salt.state       :1951][INFO    ][12444] Completed state [maas_region_boot_sources_selection_xenial] at time 05:35:38.786920 duration_in_ms=202.029
2019-04-25 05:35:38,788 [salt.state       :1780][INFO    ][12444] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:35:38.788330
2019-04-25 05:35:38,788 [salt.state       :1813][INFO    ][12444] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-04-25 05:35:38,789 [salt.utils.decorators:613 ][WARNING ][12444] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:38,790 [salt.loaded.ext.module.maasng:1771][INFO    ][12444] boot-sources sync initiated for ALL Rack's
2019-04-25 05:35:39,750 [salt.state       :300 ][INFO    ][12444] {'ret': True}
2019-04-25 05:35:39,751 [salt.state       :1951][INFO    ][12444] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:35:39.751088 duration_in_ms=962.756
2019-04-25 05:35:39,753 [salt.state       :1780][INFO    ][12444] Running state [maas.process_maas_config] at time 05:35:39.753869
2019-04-25 05:35:39,754 [salt.state       :1813][INFO    ][12444] Executing state module.run for [maas.process_maas_config]
2019-04-25 05:35:39,755 [salt.utils.decorators:613 ][WARNING ][12444] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:39,755 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=enable_http_proxy value=True
2019-04-25 05:35:39,818 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=upstream_dns value=8.8.8.8
2019-04-25 05:35:42,812 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=commissioning_distro_series value=xenial
2019-04-25 05:35:42,888 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=default_osystem value=ubuntu
2019-04-25 05:35:42,971 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=active_discovery_interval value=600
2019-04-25 05:35:43,030 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=dnssec_validation value=no
2019-04-25 05:35:43,086 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=maas_name value=mas01
2019-04-25 05:35:43,134 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=network_discovery value=enabled
2019-04-25 05:35:43,230 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=enable_third_party_drivers value=True
2019-04-25 05:35:43,301 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=default_storage_layout value=lvm
2019-04-25 05:35:43,355 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=ntp_external_only value=True
2019-04-25 05:35:43,407 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=disk_erase_with_secure_erase value=False
2019-04-25 05:35:43,460 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=default_distro_series value=xenial
2019-04-25 05:35:43,514 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-04-25 05:35:43,623 [salt.state       :300 ][INFO    ][12444] {'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-04-25 05:35:43,623 [salt.state       :1951][INFO    ][12444] Completed state [maas.process_maas_config] at time 05:35:43.623754 duration_in_ms=3869.884
2019-04-25 05:35:43,625 [salt.state       :1780][INFO    ][12444] Running state [pxe_admin] at time 05:35:43.625039
2019-04-25 05:35:43,625 [salt.state       :1813][INFO    ][12444] Executing state maasng.fabric_present for [pxe_admin]
2019-04-25 05:35:43,688 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-25 05:35:43,760 [salt.loaded.ext.module.maasng:1008][WARNING ][12444] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-04-25 05:35:43,760 [salt.loaded.ext.module.maasng:1011][WARNING ][12444] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-04-25 05:35:43,841 [salt.state       :300 ][INFO    ][12444] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-04-25 05:35:43,841 [salt.state       :1951][INFO    ][12444] Completed state [pxe_admin] at time 05:35:43.841348 duration_in_ms=216.31
2019-04-25 05:35:43,841 [salt.state       :1780][INFO    ][12444] Running state [vlan 0] at time 05:35:43.841838
2019-04-25 05:35:43,842 [salt.state       :1813][INFO    ][12444] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-25 05:35:43,919 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, 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'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pm7aqx', 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'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-25 05:35:44,026 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-25 05:35:44,263 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pm7aqx', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-25 05:35:44,338 [salt.state       :300 ][INFO    ][12444] {'new': 'Vlan untagged was updated'}
2019-04-25 05:35:44,339 [salt.state       :1951][INFO    ][12444] Completed state [vlan 0] at time 05:35:44.339277 duration_in_ms=497.439
2019-04-25 05:35:44,340 [salt.state       :1780][INFO    ][12444] Running state [192.168.11.0/24] at time 05:35:44.340692
2019-04-25 05:35:44,341 [salt.state       :1813][INFO    ][12444] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-04-25 05:35:44,635 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-04-25 05:35:44,635 [salt.loaded.ext.module.maasng:1235][WARNING ][12444] Ignoring parameter vlan:0
2019-04-25 05:35:44,739 [salt.state       :300 ][INFO    ][12444] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-04-25 05:35:44,739 [salt.state       :1951][INFO    ][12444] Completed state [192.168.11.0/24] at time 05:35:44.739296 duration_in_ms=398.604
2019-04-25 05:35:44,740 [salt.state       :1780][INFO    ][12444] Running state [maas_create_iprange_1] at time 05:35:44.740334
2019-04-25 05:35:44,740 [salt.state       :1813][INFO    ][12444] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-04-25 05:35:44,809 [salt.state       :300 ][INFO    ][12444] Iprange maas_create_iprange_1 already exist.
2019-04-25 05:35:44,809 [salt.state       :1951][INFO    ][12444] Completed state [maas_create_iprange_1] at time 05:35:44.809649 duration_in_ms=69.315
2019-04-25 05:35:44,809 [salt.state       :1780][INFO    ][12444] Running state [vlan 0] at time 05:35:44.809927
2019-04-25 05:35:44,810 [salt.state       :1813][INFO    ][12444] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-25 05:35:44,860 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, 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'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pm7aqx', 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'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-25 05:35:44,936 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pm7aqx', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-25 05:35:45,122 [salt.loaded.ext.module.maasng:945 ][INFO    ][12444] [{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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'pm7aqx', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-25 05:35:45,207 [salt.state       :300 ][INFO    ][12444] {'new': 'Vlan untagged was updated'}
2019-04-25 05:35:45,207 [salt.state       :1951][INFO    ][12444] Completed state [vlan 0] at time 05:35:45.207868 duration_in_ms=397.939
2019-04-25 05:35:45,208 [salt.state       :1780][INFO    ][12444] Running state [opnfv] at time 05:35:45.208884
2019-04-25 05:35:45,209 [salt.state       :1813][INFO    ][12444] Executing state maasng.sshkey_present for [opnfv]
2019-04-25 05:35:45,248 [salt.loaded.ext.module.maasng:1903][INFO    ][12444] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-04-25 05:35:45,248 [salt.state       :300 ][INFO    ][12444] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-04-25 05:35:45,249 [salt.state       :1951][INFO    ][12444] Completed state [opnfv] at time 05:35:45.249120 duration_in_ms=40.236
2019-04-25 05:35:45,250 [salt.state       :1780][INFO    ][12444] Running state [maas.process_tags] at time 05:35:45.250055
2019-04-25 05:35:45,250 [salt.state       :1813][INFO    ][12444] Executing state module.run for [maas.process_tags]
2019-04-25 05:35:45,251 [salt.utils.decorators:613 ][WARNING ][12444] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:45,302 [salt.loaded.ext.module.maas:92  ][INFO    ][12444] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-04-25 05:35:45,368 [salt.state       :300 ][INFO    ][12444] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-04-25 05:35:45,369 [salt.state       :1951][INFO    ][12444] Completed state [maas.process_tags] at time 05:35:45.369072 duration_in_ms=119.017
2019-04-25 05:35:45,374 [salt.minion      :1711][INFO    ][12444] Returning information for job: 20190425053517512100
2019-04-25 05:35:45,965 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425053545952210
2019-04-25 05:35:45,983 [salt.minion      :1432][INFO    ][12930] Starting a new job with PID 12930
2019-04-25 05:35:49,708 [salt.state       :915 ][INFO    ][12930] Loading fresh modules for state activity
2019-04-25 05:35:49,809 [salt.state       :1780][INFO    ][12930] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:35:49.809510
2019-04-25 05:35:49,810 [salt.state       :1813][INFO    ][12930] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:35:49,812 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12930] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:35:51,237 [salt.state       :300 ][INFO    ][12930] {'pid': 12954, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:35:51,238 [salt.state       :1951][INFO    ][12930] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:35:51.238370 duration_in_ms=1428.86
2019-04-25 05:35:51,241 [salt.state       :1780][INFO    ][12930] Running state [maas.process_machines] at time 05:35:51.240987
2019-04-25 05:35:51,241 [salt.state       :1813][INFO    ][12930] Executing state module.run for [maas.process_machines]
2019-04-25 05:35:51,242 [salt.utils.decorators:613 ][WARNING ][12930] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:35:51,939 [salt.loaded.ext.module.maas:412 ][WARNING ][12930] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:35:51,940 [salt.loaded.ext.module.maas:92  ][INFO    ][12930] 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=rtwfkh architecture=amd64/generic power_parameters_power_user=admin
2019-04-25 05:35:53,199 [salt.loaded.ext.module.maas:412 ][WARNING ][12930] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:35:53,200 [salt.loaded.ext.module.maas:92  ][INFO    ][12930] 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=gwryrd architecture=amd64/generic power_parameters_power_user=admin
2019-04-25 05:35:54,439 [salt.loaded.ext.module.maas:412 ][WARNING ][12930] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:35:54,439 [salt.loaded.ext.module.maas:92  ][INFO    ][12930] 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=nycn64 architecture=amd64/generic power_parameters_power_user=admin
2019-04-25 05:35:55,606 [salt.loaded.ext.module.maas:412 ][WARNING ][12930] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:35:55,606 [salt.loaded.ext.module.maas:92  ][INFO    ][12930] 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=8xx7sg architecture=amd64/generic power_parameters_power_user=admin
2019-04-25 05:35:56,906 [salt.loaded.ext.module.maas:412 ][WARNING ][12930] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-25 05:35:56,907 [salt.loaded.ext.module.maas:92  ][INFO    ][12930] 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=4dwbhn architecture=amd64/generic power_parameters_power_user=admin
2019-04-25 05:35:58,061 [salt.state       :300 ][INFO    ][12930] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-04-25 05:35:58,061 [salt.state       :1951][INFO    ][12930] Completed state [maas.process_machines] at time 05:35:58.061915 duration_in_ms=6820.928
2019-04-25 05:35:58,065 [salt.minion      :1711][INFO    ][12930] Returning information for job: 20190425053545952210
2019-04-25 05:36:30,518 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425053630506240
2019-04-25 05:36:30,536 [salt.minion      :1432][INFO    ][13182] Starting a new job with PID 13182
2019-04-25 05:36:34,096 [salt.state       :915 ][INFO    ][13182] Loading fresh modules for state activity
2019-04-25 05:36:34,184 [salt.state       :1780][INFO    ][13182] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:34.184781
2019-04-25 05:36:34,185 [salt.state       :1813][INFO    ][13182] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:36:34,187 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13182] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:36:35,518 [salt.state       :300 ][INFO    ][13182] {'pid': 13189, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:36:35,519 [salt.state       :1951][INFO    ][13182] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:35.519259 duration_in_ms=1334.477
2019-04-25 05:36:35,522 [salt.state       :1780][INFO    ][13182] Running state [maas.wait_for_machine_status] at time 05:36:35.522456
2019-04-25 05:36:35,523 [salt.state       :1813][INFO    ][13182] Executing state module.run for [maas.wait_for_machine_status]
2019-04-25 05:36:35,523 [salt.utils.decorators:613 ][WARNING ][13182] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:36:38,718 [salt.loaded.ext.module.maas:993 ][INFO    ][13182] Machine 4dwbhn mark broken
2019-04-25 05:36:39,330 [salt.loaded.ext.module.maas:996 ][INFO    ][13182] Machine 4dwbhn mark fixed
2019-04-25 05:36:40,312 [salt.loaded.ext.module.maas:684 ][INFO    ][13182] deploymachines hwe_kernel=hwe-16.04 system_id=4dwbhn distro_series=xenial
2019-04-25 05:36:42,949 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1492.58439493s left)
2019-04-25 05:36:45,649 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053645592340
2019-04-25 05:36:45,669 [salt.minion      :1432][INFO    ][13298] Starting a new job with PID 13298
2019-04-25 05:36:45,692 [salt.minion      :1711][INFO    ][13298] Returning information for job: 20190425053645592340
2019-04-25 05:37:15,690 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053715676333
2019-04-25 05:37:15,712 [salt.minion      :1432][INFO    ][13328] Starting a new job with PID 13328
2019-04-25 05:37:15,737 [salt.minion      :1711][INFO    ][13328] Returning information for job: 20190425053715676333
2019-04-25 05:37:16,235 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1459.2976768s left)
2019-04-25 05:37:45,794 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053745780753
2019-04-25 05:37:45,816 [salt.minion      :1432][INFO    ][13375] Starting a new job with PID 13375
2019-04-25 05:37:45,843 [salt.minion      :1711][INFO    ][13375] Returning information for job: 20190425053745780753
2019-04-25 05:37:49,540 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1425.99300194s left)
2019-04-25 05:38:15,845 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053815831285
2019-04-25 05:38:15,868 [salt.minion      :1432][INFO    ][13396] Starting a new job with PID 13396
2019-04-25 05:38:15,894 [salt.minion      :1711][INFO    ][13396] Returning information for job: 20190425053815831285
2019-04-25 05:38:22,308 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1393.22446299s left)
2019-04-25 05:38:45,904 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053845886956
2019-04-25 05:38:45,925 [salt.minion      :1432][INFO    ][13545] Starting a new job with PID 13545
2019-04-25 05:38:45,950 [salt.minion      :1711][INFO    ][13545] Returning information for job: 20190425053845886956
2019-04-25 05:38:55,638 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.89467382s left)
2019-04-25 05:39:15,956 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053915943830
2019-04-25 05:39:15,978 [salt.minion      :1432][INFO    ][13570] Starting a new job with PID 13570
2019-04-25 05:39:16,004 [salt.minion      :1711][INFO    ][13570] Returning information for job: 20190425053915943830
2019-04-25 05:39:29,093 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1326.44015479s left)
2019-04-25 05:39:46,013 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425053946001088
2019-04-25 05:39:46,033 [salt.minion      :1432][INFO    ][13735] Starting a new job with PID 13735
2019-04-25 05:39:46,058 [salt.minion      :1711][INFO    ][13735] Returning information for job: 20190425053946001088
2019-04-25 05:40:02,760 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1292.77319479s left)
2019-04-25 05:40:16,071 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054016058443
2019-04-25 05:40:16,094 [salt.minion      :1432][INFO    ][13762] Starting a new job with PID 13762
2019-04-25 05:40:16,120 [salt.minion      :1711][INFO    ][13762] Returning information for job: 20190425054016058443
2019-04-25 05:40:36,334 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1259.19880986s left)
2019-04-25 05:40:46,142 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054046129385
2019-04-25 05:40:46,161 [salt.minion      :1432][INFO    ][13853] Starting a new job with PID 13853
2019-04-25 05:40:46,186 [salt.minion      :1711][INFO    ][13853] Returning information for job: 20190425054046129385
2019-04-25 05:41:10,016 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1225.51648092s left)
2019-04-25 05:41:16,216 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054116202254
2019-04-25 05:41:16,239 [salt.minion      :1432][INFO    ][13875] Starting a new job with PID 13875
2019-04-25 05:41:16,266 [salt.minion      :1711][INFO    ][13875] Returning information for job: 20190425054116202254
2019-04-25 05:41:43,419 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1192.11420798s left)
2019-04-25 05:41:46,297 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054146283060
2019-04-25 05:41:46,319 [salt.minion      :1432][INFO    ][14017] Starting a new job with PID 14017
2019-04-25 05:41:46,347 [salt.minion      :1711][INFO    ][14017] Returning information for job: 20190425054146283060
2019-04-25 05:42:16,380 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054216367111
2019-04-25 05:42:16,401 [salt.minion      :1432][INFO    ][14043] Starting a new job with PID 14043
2019-04-25 05:42:16,426 [salt.minion      :1711][INFO    ][14043] Returning information for job: 20190425054216367111
2019-04-25 05:42:16,838 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1158.69501901s left)
2019-04-25 05:42:46,464 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054246451798
2019-04-25 05:42:46,486 [salt.minion      :1432][INFO    ][14158] Starting a new job with PID 14158
2019-04-25 05:42:46,511 [salt.minion      :1711][INFO    ][14158] Returning information for job: 20190425054246451798
2019-04-25 05:42:50,329 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1125.20420599s left)
2019-04-25 05:43:16,551 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054316539655
2019-04-25 05:43:16,573 [salt.minion      :1432][INFO    ][14181] Starting a new job with PID 14181
2019-04-25 05:43:16,598 [salt.minion      :1711][INFO    ][14181] Returning information for job: 20190425054316539655
2019-04-25 05:43:23,910 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1091.6233089s left)
2019-04-25 05:43:46,648 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054346635605
2019-04-25 05:43:46,671 [salt.minion      :1432][INFO    ][14268] Starting a new job with PID 14268
2019-04-25 05:43:46,697 [salt.minion      :1711][INFO    ][14268] Returning information for job: 20190425054346635605
2019-04-25 05:43:57,641 [salt.loaded.ext.module.maas:1023][INFO    ][13182] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1057.89139795s left)
2019-04-25 05:44:16,854 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command saltutil.find_job with jid 20190425054416841173
2019-04-25 05:44:16,877 [salt.minion      :1432][INFO    ][14319] Starting a new job with PID 14319
2019-04-25 05:44:16,903 [salt.minion      :1711][INFO    ][14319] Returning information for job: 20190425054416841173
2019-04-25 05:44:31,198 [salt.state       :300 ][INFO    ][13182] {'ret': True}
2019-04-25 05:44:31,198 [salt.state       :1951][INFO    ][13182] Completed state [maas.wait_for_machine_status] at time 05:44:31.198511 duration_in_ms=475676.054
2019-04-25 05:44:31,202 [salt.minion      :1711][INFO    ][13182] Returning information for job: 20190425053630506240
2019-04-25 05:44:31,905 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425054431891702
2019-04-25 05:44:31,927 [salt.minion      :1432][INFO    ][14351] Starting a new job with PID 14351
2019-04-25 05:44:35,645 [salt.state       :915 ][INFO    ][14351] Loading fresh modules for state activity
2019-04-25 05:44:35,782 [salt.state       :1780][INFO    ][14351] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:35.781964
2019-04-25 05:44:35,782 [salt.state       :1813][INFO    ][14351] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:44:35,783 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14351] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:44:37,219 [salt.state       :300 ][INFO    ][14351] {'pid': 14358, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:44:37,220 [salt.state       :1951][INFO    ][14351] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:37.220250 duration_in_ms=1438.287
2019-04-25 05:44:37,221 [salt.state       :1780][INFO    ][14351] Running state [maas_machines_storage_cmp002_lvm] at time 05:44:37.221640
2019-04-25 05:44:37,221 [salt.state       :1813][INFO    ][14351] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-25 05:44:37,912 [salt.state       :300 ][INFO    ][14351] Machine cmp002 is not in Ready state.
2019-04-25 05:44:37,913 [salt.state       :1951][INFO    ][14351] Completed state [maas_machines_storage_cmp002_lvm] at time 05:44:37.913372 duration_in_ms=691.73
2019-04-25 05:44:37,914 [salt.state       :1780][INFO    ][14351] Running state [maas_machines_storage_cmp001_lvm] at time 05:44:37.913970
2019-04-25 05:44:37,914 [salt.state       :1813][INFO    ][14351] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-25 05:44:38,468 [salt.state       :300 ][INFO    ][14351] Machine cmp001 is not in Ready state.
2019-04-25 05:44:38,469 [salt.state       :1951][INFO    ][14351] Completed state [maas_machines_storage_cmp001_lvm] at time 05:44:38.468981 duration_in_ms=555.011
2019-04-25 05:44:38,472 [salt.minion      :1711][INFO    ][14351] Returning information for job: 20190425054431891702
2019-04-25 05:44:39,079 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425054439070134
2019-04-25 05:44:39,102 [salt.minion      :1432][INFO    ][14381] Starting a new job with PID 14381
2019-04-25 05:44:39,822 [salt.state       :915 ][INFO    ][14381] Loading fresh modules for state activity
2019-04-25 05:44:39,871 [salt.state       :1780][INFO    ][14381] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:39.871076
2019-04-25 05:44:39,871 [salt.state       :1813][INFO    ][14381] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:44:39,872 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14381] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:44:41,302 [salt.state       :300 ][INFO    ][14381] {'pid': 14388, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:44:41,303 [salt.state       :1951][INFO    ][14381] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:41.303244 duration_in_ms=1432.168
2019-04-25 05:44:41,304 [salt.state       :1780][INFO    ][14381] Running state [maas.deploy_machines] at time 05:44:41.304362
2019-04-25 05:44:41,304 [salt.state       :1813][INFO    ][14381] Executing state module.run for [maas.deploy_machines]
2019-04-25 05:44:41,305 [salt.utils.decorators:613 ][WARNING ][14381] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:44:42,023 [salt.state       :300 ][INFO    ][14381] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-04-25 05:44:42,023 [salt.state       :1951][INFO    ][14381] Completed state [maas.deploy_machines] at time 05:44:42.023834 duration_in_ms=719.471
2019-04-25 05:44:42,026 [salt.minion      :1711][INFO    ][14381] Returning information for job: 20190425054439070134
2019-04-25 05:44:42,672 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command state.apply with jid 20190425054442656761
2019-04-25 05:44:42,694 [salt.minion      :1432][INFO    ][14397] Starting a new job with PID 14397
2019-04-25 05:44:43,487 [salt.state       :915 ][INFO    ][14397] Loading fresh modules for state activity
2019-04-25 05:44:43,576 [salt.state       :1780][INFO    ][14397] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:43.576626
2019-04-25 05:44:43,577 [salt.state       :1813][INFO    ][14397] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-25 05:44:43,579 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14397] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-25 05:44:45,054 [salt.state       :300 ][INFO    ][14397] {'pid': 14404, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-25 05:44:45,055 [salt.state       :1951][INFO    ][14397] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:44:45.055348 duration_in_ms=1478.723
2019-04-25 05:44:45,056 [salt.state       :1780][INFO    ][14397] Running state [maas.wait_for_machine_status] at time 05:44:45.056788
2019-04-25 05:44:45,057 [salt.state       :1813][INFO    ][14397] Executing state module.run for [maas.wait_for_machine_status]
2019-04-25 05:44:45,057 [salt.utils.decorators:613 ][WARNING ][14397] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-25 05:44:48,347 [salt.state       :300 ][INFO    ][14397] {'ret': True}
2019-04-25 05:44:48,347 [salt.state       :1951][INFO    ][14397] Completed state [maas.wait_for_machine_status] at time 05:44:48.347841 duration_in_ms=3291.051
2019-04-25 05:44:48,351 [salt.minion      :1711][INFO    ][14397] Returning information for job: 20190425054442656761
2019-04-25 06:14:58,141 [salt.utils.schedule:1377][INFO    ][6413] Running scheduled job: __mine_interval
2019-04-25 07:14:58,140 [salt.utils.schedule:1377][INFO    ][6413] Running scheduled job: __mine_interval
2019-04-25 07:21:13,313 [salt.minion      :1308][INFO    ][6413] User sudo_ubuntu Executing command cp.push_dir with jid 20190425072113301557
2019-04-25 07:21:13,334 [salt.minion      :1432][INFO    ][21491] Starting a new job with PID 21491
