2019-05-18 05:02:39,378 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-18 05:03:29,419 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-18 05:04:19,457 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-18 05:05:09,504 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-18 05:05:59,552 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-18 05:08:09,710 [salt.utils.decorators:613 ][WARNING ][2715] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 05:08:10,278 [salt.utils.decorators:613 ][WARNING ][2715] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 05:08:12,421 [salt.loaded.int.states.file:2298][WARNING ][2854] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-18 05:08:18,144 [salt.state       :2022][WARNING ][2965] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-18 05:08:20,783 [salt.utils.decorators:613 ][WARNING ][2965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 05:23:29,546 [salt.utils.decorators:613 ][WARNING ][2965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 05:45:01,323 [salt.utils.decorators:613 ][WARNING ][2965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:00:02,794 [salt.utils.decorators:613 ][WARNING ][2965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:00:06,682 [salt.loaded.ext.module.maasng:1008][WARNING ][2965] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-18 06:00:06,682 [salt.loaded.ext.module.maasng:1011][WARNING ][2965] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-18 06:00:07,336 [salt.loaded.ext.module.maasng:1235][WARNING ][2965] Ignoring parameter vlan:0
2019-05-18 06:00:08,152 [salt.utils.decorators:613 ][WARNING ][2965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:00:13,969 [salt.utils.decorators:613 ][WARNING ][32180] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:00:14,036 [salt.loaded.ext.module.maas:412 ][WARNING ][32180] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:00:18,487 [salt.loaded.ext.module.maas:412 ][WARNING ][32180] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:00:21,797 [salt.loaded.ext.module.maas:412 ][WARNING ][32180] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:00:24,595 [salt.loaded.ext.module.maas:412 ][WARNING ][32180] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:00:28,051 [salt.loaded.ext.module.maas:412 ][WARNING ][32180] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:00:34,366 [salt.loaded.int.module.cmdmod:395 ][INFO    ][598] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-18 06:00:34,399 [salt.loaded.int.module.cmdmod:395 ][INFO    ][598] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-18 06:00:34,420 [salt.utils.parsers:1051][WARNING ][360] Minion received a SIGTERM. Exiting.
2019-05-18 06:00:35,504 [salt.cli.daemons :293 ][INFO    ][650] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-05-18 06:00:35,604 [salt.cli.daemons :82  ][INFO    ][650] Starting up the Salt Minion
2019-05-18 06:00:35,605 [salt.utils.event :1017][INFO    ][650] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-05-18 06:00:36,546 [salt.minion      :976 ][INFO    ][650] Creating minion process manager
2019-05-18 06:00:38,017 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][650] Executing command ['date', '+%z'] in directory '/root'
2019-05-18 06:00:38,036 [salt.utils.schedule:568 ][INFO    ][650] Updating job settings for scheduled job: __mine_interval
2019-05-18 06:00:38,037 [salt.minion      :1108][INFO    ][650] Added mine.update to scheduler
2019-05-18 06:00:38,041 [salt.minion      :1975][INFO    ][650] Minion is starting as user 'root'
2019-05-18 06:00:38,053 [salt.minion      :2336][INFO    ][650] Minion is ready to receive requests!
2019-05-18 06:01:02,869 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518060102856617
2019-05-18 06:01:02,891 [salt.minion      :1432][INFO    ][743] Starting a new job with PID 743
2019-05-18 06:01:06,514 [salt.state       :915 ][INFO    ][743] Loading fresh modules for state activity
2019-05-18 06:01:06,542 [salt.fileclient  :1219][INFO    ][743] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-18 06:01:06,568 [salt.state       :1780][INFO    ][743] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:01:06.568888
2019-05-18 06:01:06,569 [salt.state       :1813][INFO    ][743] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:01:06,570 [salt.loaded.int.module.cmdmod:395 ][INFO    ][743] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:01:07,997 [salt.state       :300 ][INFO    ][743] {'pid': 751, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:01:07,998 [salt.state       :1951][INFO    ][743] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:01:07.998722 duration_in_ms=1429.833
2019-05-18 06:01:08,002 [salt.state       :1780][INFO    ][743] Running state [maas.wait_for_machine_status] at time 06:01:08.002154
2019-05-18 06:01:08,002 [salt.state       :1813][INFO    ][743] Executing state module.run for [maas.wait_for_machine_status]
2019-05-18 06:01:08,003 [salt.utils.decorators:613 ][WARNING ][743] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:01:08,877 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.13729811s left)
2019-05-18 06:01:17,921 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060117904427
2019-05-18 06:01:17,944 [salt.minion      :1432][INFO    ][776] Starting a new job with PID 776
2019-05-18 06:01:17,968 [salt.minion      :1711][INFO    ][776] Returning information for job: 20190518060117904427
2019-05-18 06:01:39,842 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.17231202s left)
2019-05-18 06:01:47,975 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060147962930
2019-05-18 06:01:47,997 [salt.minion      :1432][INFO    ][819] Starting a new job with PID 819
2019-05-18 06:01:48,019 [salt.minion      :1711][INFO    ][819] Returning information for job: 20190518060147962930
2019-05-18 06:02:11,141 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.87290502s left)
2019-05-18 06:02:18,004 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060217998096
2019-05-18 06:02:18,024 [salt.minion      :1432][INFO    ][981] Starting a new job with PID 981
2019-05-18 06:02:18,035 [salt.minion      :1711][INFO    ][981] Returning information for job: 20190518060217998096
2019-05-18 06:02:42,490 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.52346897s left)
2019-05-18 06:02:48,038 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060248025157
2019-05-18 06:02:48,060 [salt.minion      :1432][INFO    ][1187] Starting a new job with PID 1187
2019-05-18 06:02:48,083 [salt.minion      :1711][INFO    ][1187] Returning information for job: 20190518060248025157
2019-05-18 06:03:14,217 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.79706907s left)
2019-05-18 06:03:18,098 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060318085599
2019-05-18 06:03:18,119 [salt.minion      :1432][INFO    ][1352] Starting a new job with PID 1352
2019-05-18 06:03:18,142 [salt.minion      :1711][INFO    ][1352] Returning information for job: 20190518060318085599
2019-05-18 06:03:45,783 [salt.loaded.ext.module.maas:1023][INFO    ][743] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.23123097s left)
2019-05-18 06:03:48,145 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060348133716
2019-05-18 06:03:48,164 [salt.minion      :1432][INFO    ][1902] Starting a new job with PID 1902
2019-05-18 06:03:48,183 [salt.minion      :1711][INFO    ][1902] Returning information for job: 20190518060348133716
2019-05-18 06:04:18,205 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060418192964
2019-05-18 06:04:18,229 [salt.minion      :1432][INFO    ][2253] Starting a new job with PID 2253
2019-05-18 06:04:18,253 [salt.minion      :1711][INFO    ][2253] Returning information for job: 20190518060418192964
2019-05-18 06:04:19,595 [salt.state       :300 ][INFO    ][743] {'ret': True}
2019-05-18 06:04:19,595 [salt.state       :1951][INFO    ][743] Completed state [maas.wait_for_machine_status] at time 06:04:19.595553 duration_in_ms=191593.396
2019-05-18 06:04:19,599 [salt.minion      :1711][INFO    ][743] Returning information for job: 20190518060102856617
2019-05-18 06:04:20,245 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518060420232939
2019-05-18 06:04:20,265 [salt.minion      :1432][INFO    ][2268] Starting a new job with PID 2268
2019-05-18 06:04:23,894 [salt.state       :915 ][INFO    ][2268] Loading fresh modules for state activity
2019-05-18 06:04:23,947 [salt.fileclient  :1219][INFO    ][2268] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-18 06:04:24,042 [salt.state       :1780][INFO    ][2268] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:24.042533
2019-05-18 06:04:24,042 [salt.state       :1813][INFO    ][2268] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:04:24,044 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2268] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:04:25,568 [salt.state       :300 ][INFO    ][2268] {'pid': 2299, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:04:25,569 [salt.state       :1951][INFO    ][2268] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:25.568896 duration_in_ms=1526.361
2019-05-18 06:04:25,572 [salt.state       :1780][INFO    ][2268] Running state [maas_machines_storage_cmp002_lvm] at time 06:04:25.572154
2019-05-18 06:04:25,572 [salt.state       :1813][INFO    ][2268] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-18 06:04:27,072 [salt.loaded.ext.module.maasng:610 ][INFO    ][2268] btabyy
2019-05-18 06:04:27,073 [salt.loaded.ext.module.maasng:626 ][INFO    ][2268] sda
2019-05-18 06:04:27,806 [salt.loaded.ext.module.maasng:361 ][INFO    ][2268] btabyy
2019-05-18 06:04:27,943 [salt.loaded.ext.module.maasng:367 ][INFO    ][2268] [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'btabyy', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'33cf9a34-b681-4239-bf3e-86e4e4836aee', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/partition/3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btabyy', u'filesystem': {u'uuid': u'29fe1930-caf4-40a4-a949-2dae338c5579', 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'size': 2397992648704, u'type': u'partition', u'id': 3, u'device_id': 3}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'tags': [u'rotary'], u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'813168c3-a202-44f7-a069-18190f5a8ece', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/8/', u'used_size': 2397988454400, u'id': 8, u'filesystem': {u'uuid': u'87dded7d-1305-4a5f-8aa4-5768fecca476', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'btabyy', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'tags': [], u'size': 2397988454400}]
2019-05-18 06:04:27,944 [salt.loaded.ext.module.maasng:632 ][INFO    ][2268] vgroot
2019-05-18 06:04:27,944 [salt.loaded.ext.module.maasng:635 ][INFO    ][2268] lvroot
2019-05-18 06:04:27,944 [salt.loaded.ext.module.maasng:639 ][INFO    ][2268] 107374182400
2019-05-18 06:04:28,593 [salt.loaded.ext.module.maasng:645 ][INFO    ][2268] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'ip_addresses': [u'192.168.11.41'], u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 27}], 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'primary_rack': u'fneaqm', 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'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'btabyy', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/interfaces/4/'}, u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/btabyy/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'btabyy', 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'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/11/', u'available_size': 0, u'uuid': u'10471ef1-57b2-42ca-8fb7-3cc3310cbc66', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'btabyy', u'block_size': 4096, u'partition_table_type': None, u'filesystem': {u'uuid': u'7214c28b-5c41-45de-9376-3f31ff64b1a6', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'partitions': [], u'used_size': 107374182400, u'serial': None, u'size': 107374182400}], u'blockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'btabyy', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'24cfc671-4b66-42e4-a0b0-7d3c8ea1cb4d', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btabyy', u'filesystem': {u'uuid': u'8fe28bcf-8c50-4d50-b997-07b4ee7f8ed6', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'tags': [u'rotary'], u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'10471ef1-57b2-42ca-8fb7-3cc3310cbc66', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/11/', u'used_size': 107374182400, u'id': 11, u'filesystem': {u'uuid': u'7214c28b-5c41-45de-9376-3f31ff64b1a6', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'btabyy', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'tags': [], u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'btabyy', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'memory_test_status_name': u'Unknown', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'btabyy', u'block_size': 4096, 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'partitions': [{u'uuid': u'24cfc671-4b66-42e4-a0b0-7d3c8ea1cb4d', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btabyy', u'filesystem': {u'uuid': u'8fe28bcf-8c50-4d50-b997-07b4ee7f8ed6', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 27}], 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'primary_rack': u'fneaqm', 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'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'btabyy', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 29}], 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'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'enabled': True, u'id': 16, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'btabyy', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/interfaces/16/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 33}], 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'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'enabled': True, u'id': 20, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'btabyy', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/interfaces/20/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 36}], 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'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'enabled': True, u'id': 21, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'btabyy', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/interfaces/21/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'btabyy', u'block_size': 4096, 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'partitions': [{u'uuid': u'24cfc671-4b66-42e4-a0b0-7d3c8ea1cb4d', u'resource_uri': u'/MAAS/api/2.0/nodes/btabyy/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'btabyy', u'filesystem': {u'uuid': u'8fe28bcf-8c50-4d50-b997-07b4ee7f8ed6', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}}
2019-05-18 06:04:28,595 [salt.state       :300 ][INFO    ][2268] {'new': {'storage_layout': 'lvm'}}
2019-05-18 06:04:28,596 [salt.state       :1951][INFO    ][2268] Completed state [maas_machines_storage_cmp002_lvm] at time 06:04:28.596055 duration_in_ms=3023.9
2019-05-18 06:04:28,596 [salt.state       :1780][INFO    ][2268] Running state [maas_machines_storage_cmp001_lvm] at time 06:04:28.596542
2019-05-18 06:04:28,596 [salt.state       :1813][INFO    ][2268] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-18 06:04:29,939 [salt.loaded.ext.module.maasng:610 ][INFO    ][2268] efwn6b
2019-05-18 06:04:29,940 [salt.loaded.ext.module.maasng:626 ][INFO    ][2268] sda
2019-05-18 06:04:30,663 [salt.loaded.ext.module.maasng:361 ][INFO    ][2268] efwn6b
2019-05-18 06:04:30,783 [salt.loaded.ext.module.maasng:367 ][INFO    ][2268] [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/', u'type': u'physical', u'id': 1, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'efwn6b', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'42d1a627-e5ae-4cdd-ba91-b0c5943c9c35', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'efwn6b', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'04e17206-1dc5-4b02-9546-bea0bb5f0883', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/partition/1'}]}, {u'size': 2397988454400, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/6/', u'type': u'virtual', u'id': 6, u'tags': [], u'uuid': u'e3f7432d-962d-462d-b74b-127f45d46a79', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'efwn6b', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'78f522fd-8672-4234-b6d4-315c2c0a411d', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'partitions': []}]
2019-05-18 06:04:30,784 [salt.loaded.ext.module.maasng:632 ][INFO    ][2268] vgroot
2019-05-18 06:04:30,784 [salt.loaded.ext.module.maasng:635 ][INFO    ][2268] lvroot
2019-05-18 06:04:30,784 [salt.loaded.ext.module.maasng:639 ][INFO    ][2268] 107374182400
2019-05-18 06:04:31,467 [salt.loaded.ext.module.maasng:645 ][INFO    ][2268] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'vlan': {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'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 15}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'efwn6b', u'params': u'', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'filesystem': None, u'name': u'sda', u'system_id': u'efwn6b', 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'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'af7065d3-e6e6-4521-bb81-d1309a0bf495', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'efwn6b', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'c8df0275-a5cb-40d2-bcca-7375cd042dc5'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/partition/7'}]}, u'fqdn': u'cmp001.maas', 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/efwn6b/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'efwn6b', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'name': u'sda', u'system_id': u'efwn6b', 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'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'af7065d3-e6e6-4521-bb81-d1309a0bf495', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'efwn6b', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'c8df0275-a5cb-40d2-bcca-7375cd042dc5'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/partition/7'}]}, {u'size': 107374182400, u'uuid': u'7ebe1bac-1ec4-4280-93d5-6ec9d056e6f1', u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/12/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'158ac528-7f51-46bc-aeda-5abeb8b2a5c4'}, u'name': u'vgroot-lvroot', u'system_id': u'efwn6b', 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'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'filesystem': None, u'name': u'sda', u'system_id': u'efwn6b', 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'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'af7065d3-e6e6-4521-bb81-d1309a0bf495', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'efwn6b', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'c8df0275-a5cb-40d2-bcca-7375cd042dc5'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/1/partition/7'}]}], u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'efwn6b', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {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'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 15}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'fneaqm', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'efwn6b', u'params': u'', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'efwn6b', u'params': u'', u'parents': [], u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/interfaces/9/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'efwn6b', u'params': u'', u'parents': [], u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/interfaces/10/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'efwn6b', u'params': u'', u'parents': [], u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'disable_ipv4': False, u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'uuid': u'7ebe1bac-1ec4-4280-93d5-6ec9d056e6f1', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'158ac528-7f51-46bc-aeda-5abeb8b2a5c4'}, u'name': u'vgroot-lvroot', u'system_id': u'efwn6b', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/efwn6b/blockdevices/12/', u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'current_commissioning_result_id': 4, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-05-18 06:04:31,469 [salt.state       :300 ][INFO    ][2268] {'new': {'storage_layout': 'lvm'}}
2019-05-18 06:04:31,470 [salt.state       :1951][INFO    ][2268] Completed state [maas_machines_storage_cmp001_lvm] at time 06:04:31.470288 duration_in_ms=2873.745
2019-05-18 06:04:31,474 [salt.minion      :1711][INFO    ][2268] Returning information for job: 20190518060420232939
2019-05-18 06:04:32,044 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518060432031602
2019-05-18 06:04:32,066 [salt.minion      :1432][INFO    ][2354] Starting a new job with PID 2354
2019-05-18 06:04:32,800 [salt.state       :915 ][INFO    ][2354] Loading fresh modules for state activity
2019-05-18 06:04:32,850 [salt.fileclient  :1219][INFO    ][2354] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-18 06:04:32,893 [salt.state       :1780][INFO    ][2354] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:32.893817
2019-05-18 06:04:32,894 [salt.state       :1813][INFO    ][2354] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:04:32,896 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2354] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:04:34,319 [salt.state       :300 ][INFO    ][2354] {'pid': 2361, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:04:34,320 [salt.state       :1951][INFO    ][2354] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:04:34.320330 duration_in_ms=1426.514
2019-05-18 06:04:34,321 [salt.state       :1780][INFO    ][2354] Running state [maas.deploy_machines] at time 06:04:34.321468
2019-05-18 06:04:34,321 [salt.state       :1813][INFO    ][2354] Executing state module.run for [maas.deploy_machines]
2019-05-18 06:04:34,322 [salt.utils.decorators:613 ][WARNING ][2354] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:04:34,743 [salt.loaded.ext.module.maas:684 ][INFO    ][2354] deploymachines hwe_kernel=hwe-16.04 system_id=btabyy distro_series=xenial
2019-05-18 06:04:41,916 [salt.loaded.ext.module.maas:684 ][INFO    ][2354] deploymachines hwe_kernel=hwe-16.04 system_id=efwn6b distro_series=xenial
2019-05-18 06:04:47,069 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060447057362
2019-05-18 06:04:47,090 [salt.minion      :1432][INFO    ][2471] Starting a new job with PID 2471
2019-05-18 06:04:47,111 [salt.minion      :1711][INFO    ][2471] Returning information for job: 20190518060447057362
2019-05-18 06:04:49,289 [salt.loaded.ext.module.maas:684 ][INFO    ][2354] deploymachines hwe_kernel=hwe-16.04 system_id=6ry76x distro_series=xenial
2019-05-18 06:04:56,496 [salt.loaded.ext.module.maas:684 ][INFO    ][2354] deploymachines hwe_kernel=hwe-16.04 system_id=ah8g3b distro_series=xenial
2019-05-18 06:05:03,813 [salt.loaded.ext.module.maas:684 ][INFO    ][2354] deploymachines hwe_kernel=hwe-16.04 system_id=fss87y distro_series=xenial
2019-05-18 06:05:11,195 [salt.state       :300 ][INFO    ][2354] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-18 06:05:11,195 [salt.state       :1951][INFO    ][2354] Completed state [maas.deploy_machines] at time 06:05:11.195794 duration_in_ms=36874.323
2019-05-18 06:05:11,199 [salt.minion      :1711][INFO    ][2354] Returning information for job: 20190518060432031602
2019-05-18 06:05:11,838 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518060511824796
2019-05-18 06:05:11,860 [salt.minion      :1432][INFO    ][2646] Starting a new job with PID 2646
2019-05-18 06:05:15,538 [salt.state       :915 ][INFO    ][2646] Loading fresh modules for state activity
2019-05-18 06:05:15,586 [salt.fileclient  :1219][INFO    ][2646] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-18 06:05:15,623 [salt.state       :1780][INFO    ][2646] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:05:15.623357
2019-05-18 06:05:15,623 [salt.state       :1813][INFO    ][2646] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:05:15,625 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2646] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:05:17,190 [salt.state       :300 ][INFO    ][2646] {'pid': 2671, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:05:17,191 [salt.state       :1951][INFO    ][2646] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:05:17.190941 duration_in_ms=1567.584
2019-05-18 06:05:17,194 [salt.state       :1780][INFO    ][2646] Running state [maas.wait_for_machine_status] at time 06:05:17.194284
2019-05-18 06:05:17,194 [salt.state       :1813][INFO    ][2646] Executing state module.run for [maas.wait_for_machine_status]
2019-05-18 06:05:17,195 [salt.utils.decorators:613 ][WARNING ][2646] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:05:20,421 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.78426504s left)
2019-05-18 06:05:26,934 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060526921603
2019-05-18 06:05:26,957 [salt.minion      :1432][INFO    ][2709] Starting a new job with PID 2709
2019-05-18 06:05:26,981 [salt.minion      :1711][INFO    ][2709] Returning information for job: 20190518060526921603
2019-05-18 06:05:54,099 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.10626006s left)
2019-05-18 06:05:56,988 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060556974150
2019-05-18 06:05:57,011 [salt.minion      :1432][INFO    ][2729] Starting a new job with PID 2729
2019-05-18 06:05:57,035 [salt.minion      :1711][INFO    ][2729] Returning information for job: 20190518060556974150
2019-05-18 06:06:27,080 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060627071499
2019-05-18 06:06:27,098 [salt.minion      :1432][INFO    ][2818] Starting a new job with PID 2818
2019-05-18 06:06:27,116 [salt.minion      :1711][INFO    ][2818] Returning information for job: 20190518060627071499
2019-05-18 06:06:27,342 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.86342001s left)
2019-05-18 06:06:57,114 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060657103037
2019-05-18 06:06:57,133 [salt.minion      :1432][INFO    ][2980] Starting a new job with PID 2980
2019-05-18 06:06:57,157 [salt.minion      :1711][INFO    ][2980] Returning information for job: 20190518060657103037
2019-05-18 06:07:00,837 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.36841893s left)
2019-05-18 06:07:27,172 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060727159293
2019-05-18 06:07:27,194 [salt.minion      :1432][INFO    ][3781] Starting a new job with PID 3781
2019-05-18 06:07:27,217 [salt.minion      :1711][INFO    ][3781] Returning information for job: 20190518060727159293
2019-05-18 06:07:34,086 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.1190691s left)
2019-05-18 06:07:57,227 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060757214041
2019-05-18 06:07:57,249 [salt.minion      :1432][INFO    ][3818] Starting a new job with PID 3818
2019-05-18 06:07:57,273 [salt.minion      :1711][INFO    ][3818] Returning information for job: 20190518060757214041
2019-05-18 06:08:07,675 [salt.loaded.ext.module.maas:1023][INFO    ][2646] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.53048587s left)
2019-05-18 06:08:27,286 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060827273061
2019-05-18 06:08:27,308 [salt.minion      :1432][INFO    ][4142] Starting a new job with PID 4142
2019-05-18 06:08:27,331 [salt.minion      :1711][INFO    ][4142] Returning information for job: 20190518060827273061
2019-05-18 06:08:57,368 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060857361391
2019-05-18 06:08:57,386 [salt.minion      :1432][INFO    ][4224] Starting a new job with PID 4224
2019-05-18 06:08:57,406 [salt.minion      :1711][INFO    ][4224] Returning information for job: 20190518060857361391
2019-05-18 06:09:27,461 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060927452082
2019-05-18 06:09:27,477 [salt.minion      :1432][INFO    ][4486] Starting a new job with PID 4486
2019-05-18 06:09:27,494 [salt.minion      :1711][INFO    ][4486] Returning information for job: 20190518060927452082
2019-05-18 06:09:57,549 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518060957533748
2019-05-18 06:09:57,571 [salt.minion      :1432][INFO    ][4624] Starting a new job with PID 4624
2019-05-18 06:09:57,592 [salt.minion      :1711][INFO    ][4624] Returning information for job: 20190518060957533748
2019-05-18 06:10:27,638 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061027626079
2019-05-18 06:10:27,661 [salt.minion      :1432][INFO    ][4797] Starting a new job with PID 4797
2019-05-18 06:10:27,684 [salt.minion      :1711][INFO    ][4797] Returning information for job: 20190518061027626079
2019-05-18 06:10:57,750 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061057737941
2019-05-18 06:10:57,770 [salt.minion      :1432][INFO    ][4833] Starting a new job with PID 4833
2019-05-18 06:10:57,788 [salt.minion      :1711][INFO    ][4833] Returning information for job: 20190518061057737941
2019-05-18 06:11:27,861 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061127852733
2019-05-18 06:11:27,880 [salt.minion      :1432][INFO    ][4935] Starting a new job with PID 4935
2019-05-18 06:11:27,896 [salt.minion      :1711][INFO    ][4935] Returning information for job: 20190518061127852733
2019-05-18 06:11:57,972 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061157960120
2019-05-18 06:11:57,995 [salt.minion      :1432][INFO    ][4968] Starting a new job with PID 4968
2019-05-18 06:11:58,022 [salt.minion      :1711][INFO    ][4968] Returning information for job: 20190518061157960120
2019-05-18 06:12:28,096 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061228084231
2019-05-18 06:12:28,115 [salt.minion      :1432][INFO    ][5012] Starting a new job with PID 5012
2019-05-18 06:12:28,138 [salt.minion      :1711][INFO    ][5012] Returning information for job: 20190518061228084231
2019-05-18 06:12:58,222 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061258209568
2019-05-18 06:12:58,244 [salt.minion      :1432][INFO    ][5051] Starting a new job with PID 5051
2019-05-18 06:12:58,266 [salt.minion      :1711][INFO    ][5051] Returning information for job: 20190518061258209568
2019-05-18 06:13:28,357 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061328345479
2019-05-18 06:13:28,380 [salt.minion      :1432][INFO    ][5095] Starting a new job with PID 5095
2019-05-18 06:13:28,404 [salt.minion      :1711][INFO    ][5095] Returning information for job: 20190518061328345479
2019-05-18 06:13:58,490 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061358482707
2019-05-18 06:13:58,512 [salt.minion      :1432][INFO    ][5124] Starting a new job with PID 5124
2019-05-18 06:13:58,526 [salt.minion      :1711][INFO    ][5124] Returning information for job: 20190518061358482707
2019-05-18 06:14:10,087 [salt.state       :302 ][ERROR   ][2646] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-05-18 06:14:10,087 [salt.state       :1951][INFO    ][2646] Completed state [maas.wait_for_machine_status] at time 06:14:10.087743 duration_in_ms=532893.459
2019-05-18 06:14:10,090 [salt.minion      :1711][INFO    ][2646] Returning information for job: 20190518060511824796
2019-05-18 06:14:20,776 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command pillar.get with jid 20190518061420763717
2019-05-18 06:14:20,801 [salt.minion      :1432][INFO    ][5428] Starting a new job with PID 5428
2019-05-18 06:14:20,810 [salt.minion      :1711][INFO    ][5428] Returning information for job: 20190518061420763717
2019-05-18 06:14:21,367 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command service.status with jid 20190518061421359944
2019-05-18 06:14:21,384 [salt.minion      :1432][INFO    ][5453] Starting a new job with PID 5453
2019-05-18 06:14:21,694 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5453] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:21,718 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5453] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-18 06:14:21,736 [salt.minion      :1711][INFO    ][5453] Returning information for job: 20190518061421359944
2019-05-18 06:14:22,199 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518061422187896
2019-05-18 06:14:22,220 [salt.minion      :1432][INFO    ][5514] Starting a new job with PID 5514
2019-05-18 06:14:25,788 [salt.state       :915 ][INFO    ][5514] Loading fresh modules for state activity
2019-05-18 06:14:26,119 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:14:26,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:14:27,308 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:14:27,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:14:29,008 [salt.state       :1780][INFO    ][5514] Running state [salt-minion] at time 06:14:29.008025
2019-05-18 06:14:29,008 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [salt-minion]
2019-05-18 06:14:29,008 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:14:29,102 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,102 [salt.state       :1951][INFO    ][5514] Completed state [salt-minion] at time 06:14:29.102806 duration_in_ms=94.78
2019-05-18 06:14:29,103 [salt.state       :1780][INFO    ][5514] Running state [salt_minion_dependency_packages] at time 06:14:29.103153
2019-05-18 06:14:29,103 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-18 06:14:29,110 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,110 [salt.state       :1951][INFO    ][5514] Completed state [salt_minion_dependency_packages] at time 06:14:29.110396 duration_in_ms=7.243
2019-05-18 06:14:29,113 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/minion.d/minion.conf] at time 06:14:29.113662
2019-05-18 06:14:29,113 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-18 06:14:29,330 [salt.state       :300 ][INFO    ][5514] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-18 06:14:29,331 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/minion.d/minion.conf] at time 06:14:29.331140 duration_in_ms=217.478
2019-05-18 06:14:29,331 [salt.state       :1780][INFO    ][5514] Running state [python-netaddr] at time 06:14:29.331367
2019-05-18 06:14:29,331 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [python-netaddr]
2019-05-18 06:14:29,337 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,337 [salt.state       :1951][INFO    ][5514] Completed state [python-netaddr] at time 06:14:29.337761 duration_in_ms=6.394
2019-05-18 06:14:29,340 [salt.state       :1780][INFO    ][5514] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:14:29.340444
2019-05-18 06:14:29,340 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-18 06:14:29,350 [salt.state       :300 ][INFO    ][5514] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-18 06:14:29,350 [salt.state       :1951][INFO    ][5514] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:14:29.350913 duration_in_ms=10.469
2019-05-18 06:14:29,351 [salt.state       :1780][INFO    ][5514] Running state [salt-minion] at time 06:14:29.351762
2019-05-18 06:14:29,352 [salt.state       :1813][INFO    ][5514] Executing state service.running for [salt-minion]
2019-05-18 06:14:29,352 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:29,389 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-18 06:14:29,406 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-18 06:14:29,424 [salt.state       :300 ][INFO    ][5514] The service salt-minion is already running
2019-05-18 06:14:29,424 [salt.state       :1951][INFO    ][5514] Completed state [salt-minion] at time 06:14:29.424495 duration_in_ms=72.733
2019-05-18 06:14:29,426 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains.d] at time 06:14:29.426252
2019-05-18 06:14:29,426 [salt.state       :1813][INFO    ][5514] Executing state file.directory for [/etc/salt/grains.d]
2019-05-18 06:14:29,427 [salt.state       :300 ][INFO    ][5514] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-18 06:14:29,428 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains.d] at time 06:14:29.428022 duration_in_ms=1.769
2019-05-18 06:14:29,428 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains] at time 06:14:29.428799
2019-05-18 06:14:29,429 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/grains]
2019-05-18 06:14:29,429 [salt.state       :300 ][INFO    ][5514] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-18 06:14:29,430 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains] at time 06:14:29.430041 duration_in_ms=1.242
2019-05-18 06:14:29,430 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains.d/placeholder] at time 06:14:29.430577
2019-05-18 06:14:29,430 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-18 06:14:29,431 [salt.state       :300 ][INFO    ][5514] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-18 06:14:29,431 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains.d/placeholder] at time 06:14:29.431776 duration_in_ms=1.2
2019-05-18 06:14:29,432 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains.d/sphinx] at time 06:14:29.432298
2019-05-18 06:14:29,432 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-18 06:14:29,450 [salt.state       :300 ][INFO    ][5514] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-18 06:14:29,450 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains.d/sphinx] at time 06:14:29.450851 duration_in_ms=18.553
2019-05-18 06:14:29,453 [salt.state       :1780][INFO    ][5514] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.453370
2019-05-18 06:14:29,453 [salt.state       :1813][INFO    ][5514] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:14:29,454 [salt.state       :300 ][INFO    ][5514] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:14:29,454 [salt.state       :1951][INFO    ][5514] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.454370 duration_in_ms=0.999
2019-05-18 06:14:29,454 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains.d/dns_records] at time 06:14:29.454930
2019-05-18 06:14:29,455 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-18 06:14:29,468 [salt.state       :300 ][INFO    ][5514] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-18 06:14:29,468 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains.d/dns_records] at time 06:14:29.468680 duration_in_ms=13.75
2019-05-18 06:14:29,469 [salt.state       :1780][INFO    ][5514] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.469720
2019-05-18 06:14:29,470 [salt.state       :1813][INFO    ][5514] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:14:29,470 [salt.state       :300 ][INFO    ][5514] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:14:29,470 [salt.state       :1951][INFO    ][5514] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.470722 duration_in_ms=1.002
2019-05-18 06:14:29,471 [salt.state       :1780][INFO    ][5514] Running state [/etc/salt/grains.d/salt] at time 06:14:29.471255
2019-05-18 06:14:29,471 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-18 06:14:29,486 [salt.state       :300 ][INFO    ][5514] File /etc/salt/grains.d/salt is in the correct state
2019-05-18 06:14:29,486 [salt.state       :1951][INFO    ][5514] Completed state [/etc/salt/grains.d/salt] at time 06:14:29.486606 duration_in_ms=15.351
2019-05-18 06:14:29,487 [salt.state       :1780][INFO    ][5514] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.487608
2019-05-18 06:14:29,487 [salt.state       :1813][INFO    ][5514] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:14:29,488 [salt.state       :300 ][INFO    ][5514] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:14:29,488 [salt.state       :1951][INFO    ][5514] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:14:29.488590 duration_in_ms=0.983
2019-05-18 06:14:29,490 [salt.state       :1780][INFO    ][5514] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:14:29.490741
2019-05-18 06:14:29,491 [salt.state       :1813][INFO    ][5514] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-18 06:14:29,491 [salt.state       :300 ][INFO    ][5514] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-18 06:14:29,491 [salt.state       :1951][INFO    ][5514] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:14:29.491729 duration_in_ms=0.987
2019-05-18 06:14:29,492 [salt.state       :1780][INFO    ][5514] Running state [mine.update] at time 06:14:29.492482
2019-05-18 06:14:29,492 [salt.state       :1813][INFO    ][5514] Executing state module.wait for [mine.update]
2019-05-18 06:14:29,493 [salt.state       :300 ][INFO    ][5514] No changes made for mine.update
2019-05-18 06:14:29,493 [salt.state       :1951][INFO    ][5514] Completed state [mine.update] at time 06:14:29.493399 duration_in_ms=0.916
2019-05-18 06:14:29,493 [salt.state       :1780][INFO    ][5514] Running state [ca-certificates] at time 06:14:29.493705
2019-05-18 06:14:29,494 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [ca-certificates]
2019-05-18 06:14:29,502 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,502 [salt.state       :1951][INFO    ][5514] Completed state [ca-certificates] at time 06:14:29.502571 duration_in_ms=8.866
2019-05-18 06:14:29,503 [salt.state       :1780][INFO    ][5514] Running state [update-ca-certificates] at time 06:14:29.503325
2019-05-18 06:14:29,503 [salt.state       :1813][INFO    ][5514] Executing state cmd.wait for [update-ca-certificates]
2019-05-18 06:14:29,504 [salt.state       :300 ][INFO    ][5514] No changes made for update-ca-certificates
2019-05-18 06:14:29,504 [salt.state       :1951][INFO    ][5514] Completed state [update-ca-certificates] at time 06:14:29.504243 duration_in_ms=0.918
2019-05-18 06:14:29,504 [salt.state       :1780][INFO    ][5514] Running state [iptables] at time 06:14:29.504531
2019-05-18 06:14:29,504 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [iptables]
2019-05-18 06:14:29,512 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,512 [salt.state       :1951][INFO    ][5514] Completed state [iptables] at time 06:14:29.512625 duration_in_ms=8.094
2019-05-18 06:14:29,512 [salt.state       :1780][INFO    ][5514] Running state [iptables-persistent] at time 06:14:29.512889
2019-05-18 06:14:29,513 [salt.state       :1813][INFO    ][5514] Executing state pkg.installed for [iptables-persistent]
2019-05-18 06:14:29,520 [salt.state       :300 ][INFO    ][5514] All specified packages are already installed
2019-05-18 06:14:29,520 [salt.state       :1951][INFO    ][5514] Completed state [iptables-persistent] at time 06:14:29.520683 duration_in_ms=7.793
2019-05-18 06:14:29,521 [salt.state       :1780][INFO    ][5514] Running state [iptables_modules_v4_load] at time 06:14:29.521709
2019-05-18 06:14:29,522 [salt.state       :1813][INFO    ][5514] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-18 06:14:29,522 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'lsmod' in directory '/root'
2019-05-18 06:14:29,545 [salt.state       :300 ][INFO    ][5514] Kernel modules iptable_filter, ip_tables are already present
2019-05-18 06:14:29,545 [salt.state       :1951][INFO    ][5514] Completed state [iptables_modules_v4_load] at time 06:14:29.545382 duration_in_ms=23.674
2019-05-18 06:14:29,546 [salt.state       :1780][INFO    ][5514] Running state [/etc/iptables/rules.v4] at time 06:14:29.546081
2019-05-18 06:14:29,546 [salt.state       :1813][INFO    ][5514] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-18 06:14:29,636 [salt.state       :300 ][INFO    ][5514] File /etc/iptables/rules.v4 is in the correct state
2019-05-18 06:14:29,636 [salt.state       :1951][INFO    ][5514] Completed state [/etc/iptables/rules.v4] at time 06:14:29.636419 duration_in_ms=90.338
2019-05-18 06:14:29,637 [salt.state       :1780][INFO    ][5514] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:14:29.637355
2019-05-18 06:14:29,637 [salt.state       :1813][INFO    ][5514] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-18 06:14:29,638 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-18 06:14:29,655 [salt.state       :300 ][INFO    ][5514] onlyif execution failed
2019-05-18 06:14:29,655 [salt.state       :1951][INFO    ][5514] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:14:29.655928 duration_in_ms=18.573
2019-05-18 06:14:29,656 [salt.state       :1780][INFO    ][5514] Running state [netfilter-persistent] at time 06:14:29.656834
2019-05-18 06:14:29,657 [salt.state       :1813][INFO    ][5514] Executing state service.running for [netfilter-persistent]
2019-05-18 06:14:29,657 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:29,676 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-18 06:14:29,693 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-18 06:14:29,710 [salt.state       :300 ][INFO    ][5514] The service netfilter-persistent is already running
2019-05-18 06:14:29,710 [salt.state       :1951][INFO    ][5514] Completed state [netfilter-persistent] at time 06:14:29.710840 duration_in_ms=54.006
2019-05-18 06:14:29,711 [salt.state       :1780][INFO    ][5514] Running state [iptables_extra.remove_stale_tables] at time 06:14:29.711637
2019-05-18 06:14:29,711 [salt.state       :1813][INFO    ][5514] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-18 06:14:29,712 [salt.state       :300 ][INFO    ][5514] No changes made for iptables_extra.remove_stale_tables
2019-05-18 06:14:29,712 [salt.state       :1951][INFO    ][5514] Completed state [iptables_extra.remove_stale_tables] at time 06:14:29.712545 duration_in_ms=0.907
2019-05-18 06:14:29,712 [salt.state       :1780][INFO    ][5514] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:14:29.712794
2019-05-18 06:14:29,713 [salt.state       :1813][INFO    ][5514] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-18 06:14:29,713 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5514] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-18 06:14:29,727 [salt.state       :300 ][INFO    ][5514] onlyif execution failed
2019-05-18 06:14:29,728 [salt.state       :1951][INFO    ][5514] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:14:29.728233 duration_in_ms=15.439
2019-05-18 06:14:29,729 [salt.state       :1780][INFO    ][5514] Running state [/etc/iptables/rules.v6] at time 06:14:29.729258
2019-05-18 06:14:29,729 [salt.state       :1813][INFO    ][5514] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-18 06:14:29,730 [salt.state       :300 ][INFO    ][5514] File /etc/iptables/rules.v6 is not present
2019-05-18 06:14:29,730 [salt.state       :1951][INFO    ][5514] Completed state [/etc/iptables/rules.v6] at time 06:14:29.730375 duration_in_ms=1.118
2019-05-18 06:14:29,731 [salt.state       :1780][INFO    ][5514] Running state [iptables_extra.flush_all] at time 06:14:29.731110
2019-05-18 06:14:29,731 [salt.state       :1813][INFO    ][5514] Executing state module.wait for [iptables_extra.flush_all]
2019-05-18 06:14:29,731 [salt.state       :300 ][INFO    ][5514] No changes made for iptables_extra.flush_all
2019-05-18 06:14:29,732 [salt.state       :1951][INFO    ][5514] Completed state [iptables_extra.flush_all] at time 06:14:29.731978 duration_in_ms=0.868
2019-05-18 06:14:29,735 [salt.minion      :1711][INFO    ][5514] Returning information for job: 20190518061422187896
2019-05-18 06:14:30,361 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518061430348633
2019-05-18 06:14:30,382 [salt.minion      :1432][INFO    ][5635] Starting a new job with PID 5635
2019-05-18 06:14:31,118 [salt.state       :915 ][INFO    ][5635] Loading fresh modules for state activity
2019-05-18 06:14:31,781 [salt.state       :1780][INFO    ][5635] Running state [maas-rack-controller] at time 06:14:31.781621
2019-05-18 06:14:31,781 [salt.state       :1813][INFO    ][5635] Executing state pkg.installed for [maas-rack-controller]
2019-05-18 06:14:31,782 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5635] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:14:31,862 [salt.state       :300 ][INFO    ][5635] All specified packages are already installed
2019-05-18 06:14:31,862 [salt.state       :1951][INFO    ][5635] Completed state [maas-rack-controller] at time 06:14:31.862710 duration_in_ms=81.089
2019-05-18 06:14:31,863 [salt.state       :1780][INFO    ][5635] Running state [ipmitool] at time 06:14:31.862987
2019-05-18 06:14:31,863 [salt.state       :1813][INFO    ][5635] Executing state pkg.installed for [ipmitool]
2019-05-18 06:14:31,867 [salt.state       :300 ][INFO    ][5635] All specified packages are already installed
2019-05-18 06:14:31,868 [salt.state       :1951][INFO    ][5635] Completed state [ipmitool] at time 06:14:31.867998 duration_in_ms=5.011
2019-05-18 06:14:31,870 [salt.state       :1780][INFO    ][5635] Running state [/etc/maas/rackd.conf] at time 06:14:31.870514
2019-05-18 06:14:31,870 [salt.state       :1813][INFO    ][5635] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-18 06:14:31,871 [salt.state       :300 ][INFO    ][5635] No changes needed to be made
2019-05-18 06:14:31,871 [salt.state       :1951][INFO    ][5635] Completed state [/etc/maas/rackd.conf] at time 06:14:31.871672 duration_in_ms=1.158
2019-05-18 06:14:31,871 [salt.state       :1780][INFO    ][5635] Running state [/etc/maas/rackd.conf] at time 06:14:31.871852
2019-05-18 06:14:31,872 [salt.state       :1813][INFO    ][5635] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-18 06:14:31,872 [salt.loaded.int.states.file:2298][WARNING ][5635] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-18 06:14:31,872 [salt.state       :300 ][INFO    ][5635] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-18 06:14:31,872 [salt.state       :1951][INFO    ][5635] Completed state [/etc/maas/rackd.conf] at time 06:14:31.872806 duration_in_ms=0.955
2019-05-18 06:14:31,873 [salt.state       :1780][INFO    ][5635] Running state [maas-rackd] at time 06:14:31.873538
2019-05-18 06:14:31,873 [salt.state       :1813][INFO    ][5635] Executing state service.running for [maas-rackd]
2019-05-18 06:14:31,874 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5635] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:31,909 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5635] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-18 06:14:31,926 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5635] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-18 06:14:31,943 [salt.state       :300 ][INFO    ][5635] The service maas-rackd is already running
2019-05-18 06:14:31,944 [salt.state       :1951][INFO    ][5635] Completed state [maas-rackd] at time 06:14:31.944007 duration_in_ms=70.462
2019-05-18 06:14:31,946 [salt.minion      :1711][INFO    ][5635] Returning information for job: 20190518061430348633
2019-05-18 06:14:32,489 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518061432476896
2019-05-18 06:14:32,511 [salt.minion      :1432][INFO    ][5658] Starting a new job with PID 5658
2019-05-18 06:14:33,239 [salt.state       :915 ][INFO    ][5658] Loading fresh modules for state activity
2019-05-18 06:14:33,930 [salt.state       :1780][INFO    ][5658] Running state [maas-region-controller] at time 06:14:33.930798
2019-05-18 06:14:33,931 [salt.state       :1813][INFO    ][5658] Executing state pkg.installed for [maas-region-controller]
2019-05-18 06:14:33,931 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:14:34,027 [salt.state       :300 ][INFO    ][5658] All specified packages are already installed
2019-05-18 06:14:34,027 [salt.state       :1951][INFO    ][5658] Completed state [maas-region-controller] at time 06:14:34.027440 duration_in_ms=96.641
2019-05-18 06:14:34,027 [salt.state       :1780][INFO    ][5658] Running state [python-oauth] at time 06:14:34.027815
2019-05-18 06:14:34,028 [salt.state       :1813][INFO    ][5658] Executing state pkg.installed for [python-oauth]
2019-05-18 06:14:34,034 [salt.state       :300 ][INFO    ][5658] All specified packages are already installed
2019-05-18 06:14:34,034 [salt.state       :1951][INFO    ][5658] Completed state [python-oauth] at time 06:14:34.034762 duration_in_ms=6.947
2019-05-18 06:14:34,038 [salt.state       :1780][INFO    ][5658] Running state [/etc/maas/regiond.conf] at time 06:14:34.038000
2019-05-18 06:14:34,038 [salt.state       :1813][INFO    ][5658] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-18 06:14:34,104 [salt.state       :300 ][INFO    ][5658] No changes needed to be made
2019-05-18 06:14:34,105 [salt.state       :1951][INFO    ][5658] Completed state [/etc/maas/regiond.conf] at time 06:14:34.105024 duration_in_ms=67.023
2019-05-18 06:14:34,105 [salt.state       :1780][INFO    ][5658] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:14:34.105778
2019-05-18 06:14:34,106 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-18 06:14:34,175 [salt.state       :300 ][INFO    ][5658] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-18 06:14:34,175 [salt.state       :1951][INFO    ][5658] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:14:34.175756 duration_in_ms=69.977
2019-05-18 06:14:34,176 [salt.state       :1780][INFO    ][5658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:34.176369
2019-05-18 06:14:34,176 [salt.state       :1813][INFO    ][5658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-18 06:14:34,195 [salt.state       :300 ][INFO    ][5658] No changes needed to be made
2019-05-18 06:14:34,195 [salt.state       :1951][INFO    ][5658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:34.195508 duration_in_ms=19.138
2019-05-18 06:14:34,196 [salt.state       :1780][INFO    ][5658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:34.196095
2019-05-18 06:14:34,196 [salt.state       :1813][INFO    ][5658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-18 06:14:34,267 [salt.state       :300 ][INFO    ][5658] No changes needed to be made
2019-05-18 06:14:34,268 [salt.state       :1951][INFO    ][5658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:14:34.268248 duration_in_ms=72.152
2019-05-18 06:14:34,269 [salt.state       :1780][INFO    ][5658] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:14:34.269076
2019-05-18 06:14:34,269 [salt.state       :1813][INFO    ][5658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-18 06:14:34,305 [salt.state       :300 ][INFO    ][5658] No changes needed to be made
2019-05-18 06:14:34,306 [salt.state       :1951][INFO    ][5658] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:14:34.306095 duration_in_ms=37.019
2019-05-18 06:14:34,306 [salt.state       :1780][INFO    ][5658] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:14:34.306802
2019-05-18 06:14:34,307 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-18 06:14:34,319 [salt.state       :300 ][INFO    ][5658] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-18 06:14:34,320 [salt.state       :1951][INFO    ][5658] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:14:34.320234 duration_in_ms=13.432
2019-05-18 06:14:34,321 [salt.state       :1780][INFO    ][5658] Running state [a2enmod headers] at time 06:14:34.321863
2019-05-18 06:14:34,322 [salt.state       :1813][INFO    ][5658] Executing state cmd.run for [a2enmod headers]
2019-05-18 06:14:34,323 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command 'a2enmod headers' in directory '/root'
2019-05-18 06:14:34,395 [salt.state       :300 ][INFO    ][5658] {'pid': 5677, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-18 06:14:34,396 [salt.state       :1951][INFO    ][5658] Completed state [a2enmod headers] at time 06:14:34.396074 duration_in_ms=74.209
2019-05-18 06:14:34,399 [salt.state       :1780][INFO    ][5658] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:14:34.399194
2019-05-18 06:14:34,401 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-18 06:14:34,423 [salt.state       :300 ][INFO    ][5658] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-18 06:14:34,424 [salt.state       :1951][INFO    ][5658] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:14:34.423936 duration_in_ms=24.752
2019-05-18 06:14:34,425 [salt.state       :1780][INFO    ][5658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:14:34.424937
2019-05-18 06:14:34,425 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-18 06:14:34,523 [salt.state       :300 ][INFO    ][5658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-18 06:14:34,523 [salt.state       :1951][INFO    ][5658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:14:34.523696 duration_in_ms=98.758
2019-05-18 06:14:34,524 [salt.state       :1780][INFO    ][5658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:14:34.524539
2019-05-18 06:14:34,525 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-18 06:14:34,600 [salt.state       :300 ][INFO    ][5658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-18 06:14:34,601 [salt.state       :1951][INFO    ][5658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:14:34.601257 duration_in_ms=76.719
2019-05-18 06:14:34,601 [salt.state       :1780][INFO    ][5658] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:14:34.601883
2019-05-18 06:14:34,602 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-18 06:14:34,666 [salt.state       :300 ][INFO    ][5658] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-18 06:14:34,667 [salt.state       :1951][INFO    ][5658] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:14:34.667132 duration_in_ms=65.249
2019-05-18 06:14:34,667 [salt.state       :1780][INFO    ][5658] Running state [/root/.pgpass] at time 06:14:34.667444
2019-05-18 06:14:34,667 [salt.state       :1813][INFO    ][5658] Executing state file.managed for [/root/.pgpass]
2019-05-18 06:14:34,720 [salt.state       :300 ][INFO    ][5658] File /root/.pgpass is in the correct state
2019-05-18 06:14:34,721 [salt.state       :1951][INFO    ][5658] Completed state [/root/.pgpass] at time 06:14:34.720955 duration_in_ms=53.511
2019-05-18 06:14:34,726 [salt.state       :1780][INFO    ][5658] Running state [maas-region syncdb --noinput] at time 06:14:34.726801
2019-05-18 06:14:34,727 [salt.state       :1813][INFO    ][5658] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-18 06:14:34,727 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-18 06:14:36,764 [salt.state       :300 ][INFO    ][5658] {'pid': 5690, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sites, contenttypes, sessions, auth, piston3, maasserver, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-18 06:14:36,765 [salt.state       :1951][INFO    ][5658] Completed state [maas-region syncdb --noinput] at time 06:14:36.765232 duration_in_ms=2038.431
2019-05-18 06:14:36,765 [salt.state       :2022][WARNING ][5658] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-18 06:14:36,766 [salt.state       :1780][INFO    ][5658] Running state [maas-regiond] at time 06:14:36.766503
2019-05-18 06:14:36,766 [salt.state       :1813][INFO    ][5658] Executing state service.running for [maas-regiond]
2019-05-18 06:14:36,767 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:36,800 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-18 06:14:36,816 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-18 06:14:36,831 [salt.state       :300 ][INFO    ][5658] The service maas-regiond is already running
2019-05-18 06:14:36,831 [salt.state       :1951][INFO    ][5658] Completed state [maas-regiond] at time 06:14:36.831722 duration_in_ms=65.219
2019-05-18 06:14:36,832 [salt.state       :1780][INFO    ][5658] Running state [bind9] at time 06:14:36.832794
2019-05-18 06:14:36,833 [salt.state       :1813][INFO    ][5658] Executing state service.running for [bind9]
2019-05-18 06:14:36,833 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:36,849 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-18 06:14:36,864 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-18 06:14:36,879 [salt.state       :300 ][INFO    ][5658] The service bind9 is already running
2019-05-18 06:14:36,879 [salt.state       :1951][INFO    ][5658] Completed state [bind9] at time 06:14:36.879257 duration_in_ms=46.463
2019-05-18 06:14:36,880 [salt.state       :1780][INFO    ][5658] Running state [apache2] at time 06:14:36.880323
2019-05-18 06:14:36,880 [salt.state       :1813][INFO    ][5658] Executing state service.running for [apache2]
2019-05-18 06:14:36,881 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-18 06:14:36,896 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-18 06:14:36,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-18 06:14:36,929 [salt.state       :300 ][INFO    ][5658] The service apache2 is already running
2019-05-18 06:14:36,929 [salt.state       :1951][INFO    ][5658] Completed state [apache2] at time 06:14:36.929724 duration_in_ms=49.401
2019-05-18 06:14:36,930 [salt.state       :1780][INFO    ][5658] Running state [maasng.wait_for_http_code] at time 06:14:36.930758
2019-05-18 06:14:36,931 [salt.state       :1813][INFO    ][5658] Executing state module.run for [maasng.wait_for_http_code]
2019-05-18 06:14:36,931 [salt.utils.decorators:613 ][WARNING ][5658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:14:37,063 [salt.state       :300 ][INFO    ][5658] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-18 06:14:37,063 [salt.state       :1951][INFO    ][5658] Completed state [maasng.wait_for_http_code] at time 06:14:37.063811 duration_in_ms=133.052
2019-05-18 06:14:37,064 [salt.state       :1780][INFO    ][5658] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:14:37.064833
2019-05-18 06:14:37,065 [salt.state       :1813][INFO    ][5658] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-18 06:14:37,065 [salt.state       :300 ][INFO    ][5658] /var/lib/maas/.setup_admin exists
2019-05-18 06:14:37,066 [salt.state       :1951][INFO    ][5658] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:14:37.066060 duration_in_ms=1.227
2019-05-18 06:14:37,066 [salt.state       :1780][INFO    ][5658] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:37.066880
2019-05-18 06:14:37,067 [salt.state       :1813][INFO    ][5658] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:14:37,068 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5658] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:14:38,497 [salt.state       :300 ][INFO    ][5658] {'pid': 5711, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:14:38,498 [salt.state       :1951][INFO    ][5658] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:38.498318 duration_in_ms=1431.438
2019-05-18 06:14:38,501 [salt.state       :1780][INFO    ][5658] Running state [maas_region_boot_source_resources_mirror] at time 06:14:38.501864
2019-05-18 06:14:38,502 [salt.state       :1813][INFO    ][5658] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-18 06:14:38,609 [salt.state       :300 ][INFO    ][5658] {'changes': {}}
2019-05-18 06:14:38,609 [salt.state       :1951][INFO    ][5658] Completed state [maas_region_boot_source_resources_mirror] at time 06:14:38.609862 duration_in_ms=107.997
2019-05-18 06:14:38,611 [salt.state       :1780][INFO    ][5658] Running state [maasng.boot_resources_import] at time 06:14:38.610980
2019-05-18 06:14:38,611 [salt.state       :1813][INFO    ][5658] Executing state module.run for [maasng.boot_resources_import]
2019-05-18 06:14:38,612 [salt.utils.decorators:613 ][WARNING ][5658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:14:41,681 [salt.loaded.ext.module.maasng:1600][INFO    ][5658] Waiting boot-resources import done
sleep for:5s Left:897.0/900s
2019-05-18 06:14:46,774 [salt.loaded.ext.module.maasng:1600][INFO    ][5658] Waiting boot-resources import done
sleep for:5s Left:892.0/900s
2019-05-18 06:14:47,517 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061447504222
2019-05-18 06:14:47,539 [salt.minion      :1432][INFO    ][5744] Starting a new job with PID 5744
2019-05-18 06:14:47,563 [salt.minion      :1711][INFO    ][5744] Returning information for job: 20190518061447504222
2019-05-18 06:14:51,888 [salt.state       :300 ][INFO    ][5658] {'ret': True}
2019-05-18 06:14:51,889 [salt.state       :1951][INFO    ][5658] Completed state [maasng.boot_resources_import] at time 06:14:51.889008 duration_in_ms=13278.027
2019-05-18 06:14:51,890 [salt.state       :1780][INFO    ][5658] Running state [maas_region_boot_sources_selection_xenial] at time 06:14:51.890236
2019-05-18 06:14:51,890 [salt.state       :1813][INFO    ][5658] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-18 06:14:52,092 [salt.state       :300 ][INFO    ][5658] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-18 06:14:52,092 [salt.state       :1951][INFO    ][5658] Completed state [maas_region_boot_sources_selection_xenial] at time 06:14:52.092527 duration_in_ms=202.291
2019-05-18 06:14:52,093 [salt.state       :1780][INFO    ][5658] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:14:52.093826
2019-05-18 06:14:52,094 [salt.state       :1813][INFO    ][5658] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-18 06:14:52,094 [salt.utils.decorators:613 ][WARNING ][5658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:14:52,095 [salt.loaded.ext.module.maasng:1771][INFO    ][5658] boot-sources sync initiated for ALL Rack's
2019-05-18 06:14:53,085 [salt.state       :300 ][INFO    ][5658] {'ret': True}
2019-05-18 06:14:53,086 [salt.state       :1951][INFO    ][5658] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:14:53.086373 duration_in_ms=992.547
2019-05-18 06:14:53,088 [salt.state       :1780][INFO    ][5658] Running state [maas.process_maas_config] at time 06:14:53.088398
2019-05-18 06:14:53,088 [salt.state       :1813][INFO    ][5658] Executing state module.run for [maas.process_maas_config]
2019-05-18 06:14:53,089 [salt.utils.decorators:613 ][WARNING ][5658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:14:53,090 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=enable_http_proxy value=True
2019-05-18 06:14:53,141 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=upstream_dns value=8.8.8.8
2019-05-18 06:14:53,236 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=commissioning_distro_series value=xenial
2019-05-18 06:14:53,307 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=default_osystem value=ubuntu
2019-05-18 06:14:53,373 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=active_discovery_interval value=600
2019-05-18 06:14:53,434 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=dnssec_validation value=no
2019-05-18 06:14:53,502 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=maas_name value=mas01
2019-05-18 06:14:53,567 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=network_discovery value=enabled
2019-05-18 06:14:53,685 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=enable_third_party_drivers value=True
2019-05-18 06:14:56,173 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=default_storage_layout value=lvm
2019-05-18 06:14:56,229 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=ntp_external_only value=True
2019-05-18 06:14:56,280 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-18 06:14:56,338 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=default_distro_series value=xenial
2019-05-18 06:14:56,397 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-18 06:14:56,536 [salt.state       :300 ][INFO    ][5658] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-18 06:14:56,537 [salt.state       :1951][INFO    ][5658] Completed state [maas.process_maas_config] at time 06:14:56.536962 duration_in_ms=3448.562
2019-05-18 06:14:56,538 [salt.state       :1780][INFO    ][5658] Running state [pxe_admin] at time 06:14:56.538057
2019-05-18 06:14:56,538 [salt.state       :1813][INFO    ][5658] Executing state maasng.fabric_present for [pxe_admin]
2019-05-18 06:14:56,607 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', 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-05-18 06:14:56,675 [salt.loaded.ext.module.maasng:1008][WARNING ][5658] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-18 06:14:56,675 [salt.loaded.ext.module.maasng:1011][WARNING ][5658] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-18 06:14:56,753 [salt.state       :300 ][INFO    ][5658] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-18 06:14:56,754 [salt.state       :1951][INFO    ][5658] Completed state [pxe_admin] at time 06:14:56.754073 duration_in_ms=216.015
2019-05-18 06:14:56,754 [salt.state       :1780][INFO    ][5658] Running state [vlan 0] at time 06:14:56.754690
2019-05-18 06:14:56,755 [salt.state       :1813][INFO    ][5658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-18 06:14:56,831 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-18 06:14:56,962 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-05-18 06:14:57,206 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:14:57,284 [salt.state       :300 ][INFO    ][5658] {'new': 'Vlan untagged was updated'}
2019-05-18 06:14:57,284 [salt.state       :1951][INFO    ][5658] Completed state [vlan 0] at time 06:14:57.284771 duration_in_ms=530.079
2019-05-18 06:14:57,286 [salt.state       :1780][INFO    ][5658] Running state [192.168.11.0/24] at time 06:14:57.286263
2019-05-18 06:14:57,286 [salt.state       :1813][INFO    ][5658] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-18 06:14:57,538 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-18 06:14:57,539 [salt.loaded.ext.module.maasng:1235][WARNING ][5658] Ignoring parameter vlan:0
2019-05-18 06:14:57,627 [salt.state       :300 ][INFO    ][5658] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-18 06:14:57,627 [salt.state       :1951][INFO    ][5658] Completed state [192.168.11.0/24] at time 06:14:57.627731 duration_in_ms=341.468
2019-05-18 06:14:57,628 [salt.state       :1780][INFO    ][5658] Running state [maas_create_iprange_1] at time 06:14:57.628393
2019-05-18 06:14:57,628 [salt.state       :1813][INFO    ][5658] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-18 06:14:57,687 [salt.state       :300 ][INFO    ][5658] Iprange maas_create_iprange_1 already exist.
2019-05-18 06:14:57,687 [salt.state       :1951][INFO    ][5658] Completed state [maas_create_iprange_1] at time 06:14:57.687400 duration_in_ms=59.005
2019-05-18 06:14:57,688 [salt.state       :1780][INFO    ][5658] Running state [vlan 0] at time 06:14:57.687936
2019-05-18 06:14:57,688 [salt.state       :1813][INFO    ][5658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-18 06:14:57,753 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', 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-05-18 06:14:57,876 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', 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-05-18 06:14:58,147 [salt.loaded.ext.module.maasng:945 ][INFO    ][5658] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:14:58,238 [salt.state       :300 ][INFO    ][5658] {'new': 'Vlan untagged was updated'}
2019-05-18 06:14:58,239 [salt.state       :1951][INFO    ][5658] Completed state [vlan 0] at time 06:14:58.238935 duration_in_ms=550.999
2019-05-18 06:14:58,239 [salt.state       :1780][INFO    ][5658] Running state [opnfv] at time 06:14:58.239669
2019-05-18 06:14:58,240 [salt.state       :1813][INFO    ][5658] Executing state maasng.sshkey_present for [opnfv]
2019-05-18 06:14:58,285 [salt.loaded.ext.module.maasng:1903][INFO    ][5658] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-18 06:14:58,286 [salt.state       :300 ][INFO    ][5658] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-18 06:14:58,286 [salt.state       :1951][INFO    ][5658] Completed state [opnfv] at time 06:14:58.286787 duration_in_ms=47.117
2019-05-18 06:14:58,287 [salt.state       :1780][INFO    ][5658] Running state [maas.process_tags] at time 06:14:58.287647
2019-05-18 06:14:58,288 [salt.state       :1813][INFO    ][5658] Executing state module.run for [maas.process_tags]
2019-05-18 06:14:58,288 [salt.utils.decorators:613 ][WARNING ][5658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:14:58,334 [salt.loaded.ext.module.maas:92  ][INFO    ][5658] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-18 06:14:58,394 [salt.state       :300 ][INFO    ][5658] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-18 06:14:58,395 [salt.state       :1951][INFO    ][5658] Completed state [maas.process_tags] at time 06:14:58.395215 duration_in_ms=107.567
2019-05-18 06:14:58,399 [salt.minion      :1711][INFO    ][5658] Returning information for job: 20190518061432476896
2019-05-18 06:14:58,957 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518061458945816
2019-05-18 06:14:58,976 [salt.minion      :1432][INFO    ][6105] Starting a new job with PID 6105
2019-05-18 06:15:02,582 [salt.state       :915 ][INFO    ][6105] Loading fresh modules for state activity
2019-05-18 06:15:02,671 [salt.state       :1780][INFO    ][6105] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:02.671688
2019-05-18 06:15:02,672 [salt.state       :1813][INFO    ][6105] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:15:02,673 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6105] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:15:04,070 [salt.state       :300 ][INFO    ][6105] {'pid': 6134, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:15:04,070 [salt.state       :1951][INFO    ][6105] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:04.070790 duration_in_ms=1399.103
2019-05-18 06:15:04,072 [salt.state       :1780][INFO    ][6105] Running state [maas.process_machines] at time 06:15:04.071995
2019-05-18 06:15:04,072 [salt.state       :1813][INFO    ][6105] Executing state module.run for [maas.process_machines]
2019-05-18 06:15:04,072 [salt.utils.decorators:613 ][WARNING ][6105] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:15:04,812 [salt.loaded.ext.module.maas:412 ][WARNING ][6105] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:15:04,813 [salt.loaded.ext.module.maas:92  ][INFO    ][6105] 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=btabyy architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:15:06,072 [salt.loaded.ext.module.maas:412 ][WARNING ][6105] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:15:06,072 [salt.loaded.ext.module.maas:92  ][INFO    ][6105] 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=efwn6b architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:15:07,414 [salt.loaded.ext.module.maas:412 ][WARNING ][6105] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:15:07,415 [salt.loaded.ext.module.maas:92  ][INFO    ][6105] 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=6ry76x architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:15:08,742 [salt.loaded.ext.module.maas:412 ][WARNING ][6105] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:15:08,743 [salt.loaded.ext.module.maas:92  ][INFO    ][6105] 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=ah8g3b architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:15:10,104 [salt.loaded.ext.module.maas:412 ][WARNING ][6105] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:15:10,105 [salt.loaded.ext.module.maas:92  ][INFO    ][6105] 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=fss87y architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:15:11,354 [salt.state       :300 ][INFO    ][6105] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-18 06:15:11,354 [salt.state       :1951][INFO    ][6105] Completed state [maas.process_machines] at time 06:15:11.354474 duration_in_ms=7282.477
2019-05-18 06:15:11,357 [salt.minion      :1711][INFO    ][6105] Returning information for job: 20190518061458945816
2019-05-18 06:15:42,419 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518061542407066
2019-05-18 06:15:42,442 [salt.minion      :1432][INFO    ][6619] Starting a new job with PID 6619
2019-05-18 06:15:45,964 [salt.state       :915 ][INFO    ][6619] Loading fresh modules for state activity
2019-05-18 06:15:46,060 [salt.state       :1780][INFO    ][6619] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:46.060723
2019-05-18 06:15:46,061 [salt.state       :1813][INFO    ][6619] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:15:46,062 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6619] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:15:47,338 [salt.state       :300 ][INFO    ][6619] {'pid': 6636, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:15:47,339 [salt.state       :1951][INFO    ][6619] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:15:47.339350 duration_in_ms=1278.626
2019-05-18 06:15:47,342 [salt.state       :1780][INFO    ][6619] Running state [maas.wait_for_machine_status] at time 06:15:47.342613
2019-05-18 06:15:47,343 [salt.state       :1813][INFO    ][6619] Executing state module.run for [maas.wait_for_machine_status]
2019-05-18 06:15:47,343 [salt.utils.decorators:613 ][WARNING ][6619] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:15:50,816 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1496.53757691s left)
2019-05-18 06:15:57,475 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061557461941
2019-05-18 06:15:57,497 [salt.minion      :1432][INFO    ][6673] Starting a new job with PID 6673
2019-05-18 06:15:57,520 [salt.minion      :1711][INFO    ][6673] Returning information for job: 20190518061557461941
2019-05-18 06:16:24,128 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1463.225595s left)
2019-05-18 06:16:27,585 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061627573960
2019-05-18 06:16:27,605 [salt.minion      :1432][INFO    ][6924] Starting a new job with PID 6924
2019-05-18 06:16:27,628 [salt.minion      :1711][INFO    ][6924] Returning information for job: 20190518061627573960
2019-05-18 06:16:57,697 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061657685595
2019-05-18 06:16:57,719 [salt.minion      :1432][INFO    ][7022] Starting a new job with PID 7022
2019-05-18 06:16:57,742 [salt.minion      :1711][INFO    ][7022] Returning information for job: 20190518061657685595
2019-05-18 06:16:57,832 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1429.52142692s left)
2019-05-18 06:17:27,794 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061727782126
2019-05-18 06:17:27,817 [salt.minion      :1432][INFO    ][7480] Starting a new job with PID 7480
2019-05-18 06:17:27,843 [salt.minion      :1711][INFO    ][7480] Returning information for job: 20190518061727782126
2019-05-18 06:17:31,079 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1396.27434587s left)
2019-05-18 06:17:57,851 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061757837149
2019-05-18 06:17:57,873 [salt.minion      :1432][INFO    ][7523] Starting a new job with PID 7523
2019-05-18 06:17:57,897 [salt.minion      :1711][INFO    ][7523] Returning information for job: 20190518061757837149
2019-05-18 06:18:04,053 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1363.30088496s left)
2019-05-18 06:18:27,910 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061827898397
2019-05-18 06:18:27,933 [salt.minion      :1432][INFO    ][7599] Starting a new job with PID 7599
2019-05-18 06:18:27,956 [salt.minion      :1711][INFO    ][7599] Returning information for job: 20190518061827898397
2019-05-18 06:18:37,247 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1330.10678697s left)
2019-05-18 06:18:57,965 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061857952781
2019-05-18 06:18:57,989 [salt.minion      :1432][INFO    ][7628] Starting a new job with PID 7628
2019-05-18 06:18:58,012 [salt.minion      :1711][INFO    ][7628] Returning information for job: 20190518061857952781
2019-05-18 06:19:10,514 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1296.839504s left)
2019-05-18 06:19:28,033 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061928020319
2019-05-18 06:19:28,056 [salt.minion      :1432][INFO    ][7686] Starting a new job with PID 7686
2019-05-18 06:19:28,080 [salt.minion      :1711][INFO    ][7686] Returning information for job: 20190518061928020319
2019-05-18 06:19:44,320 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1263.03357291s left)
2019-05-18 06:19:58,088 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518061958076101
2019-05-18 06:19:58,111 [salt.minion      :1432][INFO    ][7706] Starting a new job with PID 7706
2019-05-18 06:19:58,134 [salt.minion      :1711][INFO    ][7706] Returning information for job: 20190518061958076101
2019-05-18 06:20:17,698 [salt.loaded.ext.module.maas:1023][INFO    ][6619] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1229.65526605s left)
2019-05-18 06:20:28,161 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062028148711
2019-05-18 06:20:28,184 [salt.minion      :1432][INFO    ][7766] Starting a new job with PID 7766
2019-05-18 06:20:28,209 [salt.minion      :1711][INFO    ][7766] Returning information for job: 20190518062028148711
2019-05-18 06:20:51,171 [salt.loaded.ext.module.maas:993 ][INFO    ][6619] Machine fss87y mark broken
2019-05-18 06:20:51,923 [salt.loaded.ext.module.maas:996 ][INFO    ][6619] Machine fss87y mark fixed
2019-05-18 06:20:53,164 [salt.loaded.ext.module.maas:684 ][INFO    ][6619] deploymachines hwe_kernel=hwe-16.04 system_id=fss87y distro_series=xenial
2019-05-18 06:20:56,011 [salt.loaded.ext.module.maas:160 ][ERROR   ][6619] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-05-18 06:20:56,012 [salt.state       :302 ][ERROR   ][6619] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-05-18 06:20:56,013 [salt.state       :1951][INFO    ][6619] Completed state [maas.wait_for_machine_status] at time 06:20:56.013083 duration_in_ms=308670.467
2019-05-18 06:20:56,017 [salt.minion      :1711][INFO    ][6619] Returning information for job: 20190518061542407066
2019-05-18 06:21:06,779 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command pillar.get with jid 20190518062106767660
2019-05-18 06:21:06,800 [salt.minion      :1432][INFO    ][7870] Starting a new job with PID 7870
2019-05-18 06:21:06,808 [salt.minion      :1711][INFO    ][7870] Returning information for job: 20190518062106767660
2019-05-18 06:21:07,305 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command service.status with jid 20190518062107292589
2019-05-18 06:21:07,326 [salt.minion      :1432][INFO    ][7875] Starting a new job with PID 7875
2019-05-18 06:21:07,717 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7875] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:07,751 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7875] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-18 06:21:07,766 [salt.minion      :1711][INFO    ][7875] Returning information for job: 20190518062107292589
2019-05-18 06:21:08,362 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518062108349229
2019-05-18 06:21:08,384 [salt.minion      :1432][INFO    ][7886] Starting a new job with PID 7886
2019-05-18 06:21:11,991 [salt.state       :915 ][INFO    ][7886] Loading fresh modules for state activity
2019-05-18 06:21:12,402 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:21:12,772 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:21:13,625 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:21:13,977 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'salt-minion --version' in directory '/root'
2019-05-18 06:21:15,285 [salt.state       :1780][INFO    ][7886] Running state [salt-minion] at time 06:21:15.285785
2019-05-18 06:21:15,286 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [salt-minion]
2019-05-18 06:21:15,286 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:21:15,381 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,381 [salt.state       :1951][INFO    ][7886] Completed state [salt-minion] at time 06:21:15.381653 duration_in_ms=95.867
2019-05-18 06:21:15,382 [salt.state       :1780][INFO    ][7886] Running state [salt_minion_dependency_packages] at time 06:21:15.382048
2019-05-18 06:21:15,382 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-18 06:21:15,390 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,390 [salt.state       :1951][INFO    ][7886] Completed state [salt_minion_dependency_packages] at time 06:21:15.390554 duration_in_ms=8.506
2019-05-18 06:21:15,394 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/minion.d/minion.conf] at time 06:21:15.394166
2019-05-18 06:21:15,394 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-18 06:21:15,637 [salt.state       :300 ][INFO    ][7886] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-18 06:21:15,637 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/minion.d/minion.conf] at time 06:21:15.637569 duration_in_ms=243.404
2019-05-18 06:21:15,637 [salt.state       :1780][INFO    ][7886] Running state [python-netaddr] at time 06:21:15.637762
2019-05-18 06:21:15,638 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [python-netaddr]
2019-05-18 06:21:15,645 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,645 [salt.state       :1951][INFO    ][7886] Completed state [python-netaddr] at time 06:21:15.645768 duration_in_ms=8.006
2019-05-18 06:21:15,649 [salt.state       :1780][INFO    ][7886] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:21:15.649085
2019-05-18 06:21:15,649 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-18 06:21:15,660 [salt.state       :300 ][INFO    ][7886] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-18 06:21:15,660 [salt.state       :1951][INFO    ][7886] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:21:15.660337 duration_in_ms=11.252
2019-05-18 06:21:15,661 [salt.state       :1780][INFO    ][7886] Running state [salt-minion] at time 06:21:15.661226
2019-05-18 06:21:15,661 [salt.state       :1813][INFO    ][7886] Executing state service.running for [salt-minion]
2019-05-18 06:21:15,662 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:15,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-18 06:21:15,715 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-18 06:21:15,731 [salt.state       :300 ][INFO    ][7886] The service salt-minion is already running
2019-05-18 06:21:15,732 [salt.state       :1951][INFO    ][7886] Completed state [salt-minion] at time 06:21:15.732037 duration_in_ms=70.811
2019-05-18 06:21:15,733 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains.d] at time 06:21:15.733355
2019-05-18 06:21:15,733 [salt.state       :1813][INFO    ][7886] Executing state file.directory for [/etc/salt/grains.d]
2019-05-18 06:21:15,734 [salt.state       :300 ][INFO    ][7886] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-18 06:21:15,734 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains.d] at time 06:21:15.734764 duration_in_ms=1.409
2019-05-18 06:21:15,735 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains] at time 06:21:15.735347
2019-05-18 06:21:15,735 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/grains]
2019-05-18 06:21:15,736 [salt.state       :300 ][INFO    ][7886] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-18 06:21:15,736 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains] at time 06:21:15.736346 duration_in_ms=0.999
2019-05-18 06:21:15,736 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains.d/placeholder] at time 06:21:15.736775
2019-05-18 06:21:15,737 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-18 06:21:15,737 [salt.state       :300 ][INFO    ][7886] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-18 06:21:15,737 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains.d/placeholder] at time 06:21:15.737731 duration_in_ms=0.956
2019-05-18 06:21:15,738 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains.d/sphinx] at time 06:21:15.738144
2019-05-18 06:21:15,738 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-18 06:21:15,751 [salt.state       :300 ][INFO    ][7886] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-18 06:21:15,751 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains.d/sphinx] at time 06:21:15.751392 duration_in_ms=13.248
2019-05-18 06:21:15,753 [salt.state       :1780][INFO    ][7886] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.753353
2019-05-18 06:21:15,753 [salt.state       :1813][INFO    ][7886] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:21:15,753 [salt.state       :300 ][INFO    ][7886] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:21:15,754 [salt.state       :1951][INFO    ][7886] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.754148 duration_in_ms=0.796
2019-05-18 06:21:15,754 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains.d/dns_records] at time 06:21:15.754569
2019-05-18 06:21:15,754 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-18 06:21:15,769 [salt.state       :300 ][INFO    ][7886] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-18 06:21:15,769 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains.d/dns_records] at time 06:21:15.769337 duration_in_ms=14.768
2019-05-18 06:21:15,770 [salt.state       :1780][INFO    ][7886] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.770154
2019-05-18 06:21:15,770 [salt.state       :1813][INFO    ][7886] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:21:15,770 [salt.state       :300 ][INFO    ][7886] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:21:15,770 [salt.state       :1951][INFO    ][7886] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.770919 duration_in_ms=0.765
2019-05-18 06:21:15,771 [salt.state       :1780][INFO    ][7886] Running state [/etc/salt/grains.d/salt] at time 06:21:15.771327
2019-05-18 06:21:15,771 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-18 06:21:15,787 [salt.state       :300 ][INFO    ][7886] File /etc/salt/grains.d/salt is in the correct state
2019-05-18 06:21:15,787 [salt.state       :1951][INFO    ][7886] Completed state [/etc/salt/grains.d/salt] at time 06:21:15.787294 duration_in_ms=15.966
2019-05-18 06:21:15,788 [salt.state       :1780][INFO    ][7886] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.788047
2019-05-18 06:21:15,788 [salt.state       :1813][INFO    ][7886] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-18 06:21:15,788 [salt.state       :300 ][INFO    ][7886] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-18 06:21:15,788 [salt.state       :1951][INFO    ][7886] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:21:15.788823 duration_in_ms=0.776
2019-05-18 06:21:15,790 [salt.state       :1780][INFO    ][7886] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:21:15.790395
2019-05-18 06:21:15,790 [salt.state       :1813][INFO    ][7886] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-18 06:21:15,791 [salt.state       :300 ][INFO    ][7886] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-18 06:21:15,791 [salt.state       :1951][INFO    ][7886] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:21:15.791168 duration_in_ms=0.774
2019-05-18 06:21:15,791 [salt.state       :1780][INFO    ][7886] Running state [mine.update] at time 06:21:15.791754
2019-05-18 06:21:15,792 [salt.state       :1813][INFO    ][7886] Executing state module.wait for [mine.update]
2019-05-18 06:21:15,792 [salt.state       :300 ][INFO    ][7886] No changes made for mine.update
2019-05-18 06:21:15,792 [salt.state       :1951][INFO    ][7886] Completed state [mine.update] at time 06:21:15.792460 duration_in_ms=0.706
2019-05-18 06:21:15,792 [salt.state       :1780][INFO    ][7886] Running state [ca-certificates] at time 06:21:15.792697
2019-05-18 06:21:15,792 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [ca-certificates]
2019-05-18 06:21:15,799 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,799 [salt.state       :1951][INFO    ][7886] Completed state [ca-certificates] at time 06:21:15.799448 duration_in_ms=6.751
2019-05-18 06:21:15,800 [salt.state       :1780][INFO    ][7886] Running state [update-ca-certificates] at time 06:21:15.800081
2019-05-18 06:21:15,800 [salt.state       :1813][INFO    ][7886] Executing state cmd.wait for [update-ca-certificates]
2019-05-18 06:21:15,800 [salt.state       :300 ][INFO    ][7886] No changes made for update-ca-certificates
2019-05-18 06:21:15,800 [salt.state       :1951][INFO    ][7886] Completed state [update-ca-certificates] at time 06:21:15.800791 duration_in_ms=0.71
2019-05-18 06:21:15,801 [salt.state       :1780][INFO    ][7886] Running state [iptables] at time 06:21:15.801000
2019-05-18 06:21:15,801 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [iptables]
2019-05-18 06:21:15,806 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,807 [salt.state       :1951][INFO    ][7886] Completed state [iptables] at time 06:21:15.807099 duration_in_ms=6.099
2019-05-18 06:21:15,807 [salt.state       :1780][INFO    ][7886] Running state [iptables-persistent] at time 06:21:15.807316
2019-05-18 06:21:15,807 [salt.state       :1813][INFO    ][7886] Executing state pkg.installed for [iptables-persistent]
2019-05-18 06:21:15,813 [salt.state       :300 ][INFO    ][7886] All specified packages are already installed
2019-05-18 06:21:15,813 [salt.state       :1951][INFO    ][7886] Completed state [iptables-persistent] at time 06:21:15.813287 duration_in_ms=5.971
2019-05-18 06:21:15,814 [salt.state       :1780][INFO    ][7886] Running state [iptables_modules_v4_load] at time 06:21:15.814128
2019-05-18 06:21:15,814 [salt.state       :1813][INFO    ][7886] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-18 06:21:15,814 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'lsmod' in directory '/root'
2019-05-18 06:21:15,836 [salt.state       :300 ][INFO    ][7886] Kernel modules iptable_filter, ip_tables are already present
2019-05-18 06:21:15,836 [salt.state       :1951][INFO    ][7886] Completed state [iptables_modules_v4_load] at time 06:21:15.836869 duration_in_ms=22.741
2019-05-18 06:21:15,837 [salt.state       :1780][INFO    ][7886] Running state [/etc/iptables/rules.v4] at time 06:21:15.837413
2019-05-18 06:21:15,837 [salt.state       :1813][INFO    ][7886] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-18 06:21:15,919 [salt.state       :300 ][INFO    ][7886] File /etc/iptables/rules.v4 is in the correct state
2019-05-18 06:21:15,919 [salt.state       :1951][INFO    ][7886] Completed state [/etc/iptables/rules.v4] at time 06:21:15.919319 duration_in_ms=81.905
2019-05-18 06:21:15,920 [salt.state       :1780][INFO    ][7886] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:21:15.920080
2019-05-18 06:21:15,920 [salt.state       :1813][INFO    ][7886] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-18 06:21:15,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-18 06:21:15,939 [salt.state       :300 ][INFO    ][7886] onlyif execution failed
2019-05-18 06:21:15,940 [salt.state       :1951][INFO    ][7886] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:21:15.940144 duration_in_ms=20.065
2019-05-18 06:21:15,940 [salt.state       :1780][INFO    ][7886] Running state [netfilter-persistent] at time 06:21:15.940873
2019-05-18 06:21:15,941 [salt.state       :1813][INFO    ][7886] Executing state service.running for [netfilter-persistent]
2019-05-18 06:21:15,941 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:15,959 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-18 06:21:15,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-18 06:21:15,990 [salt.state       :300 ][INFO    ][7886] The service netfilter-persistent is already running
2019-05-18 06:21:15,990 [salt.state       :1951][INFO    ][7886] Completed state [netfilter-persistent] at time 06:21:15.990494 duration_in_ms=49.621
2019-05-18 06:21:15,991 [salt.state       :1780][INFO    ][7886] Running state [iptables_extra.remove_stale_tables] at time 06:21:15.991120
2019-05-18 06:21:15,991 [salt.state       :1813][INFO    ][7886] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-18 06:21:15,991 [salt.state       :300 ][INFO    ][7886] No changes made for iptables_extra.remove_stale_tables
2019-05-18 06:21:15,991 [salt.state       :1951][INFO    ][7886] Completed state [iptables_extra.remove_stale_tables] at time 06:21:15.991851 duration_in_ms=0.731
2019-05-18 06:21:15,992 [salt.state       :1780][INFO    ][7886] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:21:15.992052
2019-05-18 06:21:15,992 [salt.state       :1813][INFO    ][7886] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-18 06:21:15,992 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7886] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-18 06:21:16,006 [salt.state       :300 ][INFO    ][7886] onlyif execution failed
2019-05-18 06:21:16,006 [salt.state       :1951][INFO    ][7886] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:21:16.006249 duration_in_ms=14.196
2019-05-18 06:21:16,007 [salt.state       :1780][INFO    ][7886] Running state [/etc/iptables/rules.v6] at time 06:21:16.006997
2019-05-18 06:21:16,007 [salt.state       :1813][INFO    ][7886] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-18 06:21:16,007 [salt.state       :300 ][INFO    ][7886] File /etc/iptables/rules.v6 is not present
2019-05-18 06:21:16,007 [salt.state       :1951][INFO    ][7886] Completed state [/etc/iptables/rules.v6] at time 06:21:16.007826 duration_in_ms=0.829
2019-05-18 06:21:16,008 [salt.state       :1780][INFO    ][7886] Running state [iptables_extra.flush_all] at time 06:21:16.008335
2019-05-18 06:21:16,008 [salt.state       :1813][INFO    ][7886] Executing state module.wait for [iptables_extra.flush_all]
2019-05-18 06:21:16,008 [salt.state       :300 ][INFO    ][7886] No changes made for iptables_extra.flush_all
2019-05-18 06:21:16,009 [salt.state       :1951][INFO    ][7886] Completed state [iptables_extra.flush_all] at time 06:21:16.008988 duration_in_ms=0.653
2019-05-18 06:21:16,011 [salt.minion      :1711][INFO    ][7886] Returning information for job: 20190518062108349229
2019-05-18 06:21:16,652 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518062116639380
2019-05-18 06:21:16,674 [salt.minion      :1432][INFO    ][7977] Starting a new job with PID 7977
2019-05-18 06:21:17,253 [salt.state       :915 ][INFO    ][7977] Loading fresh modules for state activity
2019-05-18 06:21:17,796 [salt.state       :1780][INFO    ][7977] Running state [maas-rack-controller] at time 06:21:17.796053
2019-05-18 06:21:17,796 [salt.state       :1813][INFO    ][7977] Executing state pkg.installed for [maas-rack-controller]
2019-05-18 06:21:17,796 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7977] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:21:17,876 [salt.state       :300 ][INFO    ][7977] All specified packages are already installed
2019-05-18 06:21:17,877 [salt.state       :1951][INFO    ][7977] Completed state [maas-rack-controller] at time 06:21:17.877181 duration_in_ms=81.128
2019-05-18 06:21:17,877 [salt.state       :1780][INFO    ][7977] Running state [ipmitool] at time 06:21:17.877417
2019-05-18 06:21:17,877 [salt.state       :1813][INFO    ][7977] Executing state pkg.installed for [ipmitool]
2019-05-18 06:21:17,882 [salt.state       :300 ][INFO    ][7977] All specified packages are already installed
2019-05-18 06:21:17,882 [salt.state       :1951][INFO    ][7977] Completed state [ipmitool] at time 06:21:17.882391 duration_in_ms=4.973
2019-05-18 06:21:17,884 [salt.state       :1780][INFO    ][7977] Running state [/etc/maas/rackd.conf] at time 06:21:17.884666
2019-05-18 06:21:17,884 [salt.state       :1813][INFO    ][7977] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-18 06:21:17,885 [salt.state       :300 ][INFO    ][7977] No changes needed to be made
2019-05-18 06:21:17,885 [salt.state       :1951][INFO    ][7977] Completed state [/etc/maas/rackd.conf] at time 06:21:17.885792 duration_in_ms=1.127
2019-05-18 06:21:17,885 [salt.state       :1780][INFO    ][7977] Running state [/etc/maas/rackd.conf] at time 06:21:17.885953
2019-05-18 06:21:17,886 [salt.state       :1813][INFO    ][7977] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-18 06:21:17,886 [salt.loaded.int.states.file:2298][WARNING ][7977] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-18 06:21:17,886 [salt.state       :300 ][INFO    ][7977] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-18 06:21:17,886 [salt.state       :1951][INFO    ][7977] Completed state [/etc/maas/rackd.conf] at time 06:21:17.886839 duration_in_ms=0.885
2019-05-18 06:21:17,887 [salt.state       :1780][INFO    ][7977] Running state [maas-rackd] at time 06:21:17.887540
2019-05-18 06:21:17,887 [salt.state       :1813][INFO    ][7977] Executing state service.running for [maas-rackd]
2019-05-18 06:21:17,888 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7977] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:17,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7977] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-18 06:21:17,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7977] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-18 06:21:17,950 [salt.state       :300 ][INFO    ][7977] The service maas-rackd is already running
2019-05-18 06:21:17,951 [salt.state       :1951][INFO    ][7977] Completed state [maas-rackd] at time 06:21:17.951015 duration_in_ms=63.475
2019-05-18 06:21:17,952 [salt.minion      :1711][INFO    ][7977] Returning information for job: 20190518062116639380
2019-05-18 06:21:18,562 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518062118549163
2019-05-18 06:21:18,585 [salt.minion      :1432][INFO    ][8000] Starting a new job with PID 8000
2019-05-18 06:21:19,335 [salt.state       :915 ][INFO    ][8000] Loading fresh modules for state activity
2019-05-18 06:21:20,023 [salt.state       :1780][INFO    ][8000] Running state [maas-region-controller] at time 06:21:20.022955
2019-05-18 06:21:20,023 [salt.state       :1813][INFO    ][8000] Executing state pkg.installed for [maas-region-controller]
2019-05-18 06:21:20,023 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-18 06:21:20,100 [salt.state       :300 ][INFO    ][8000] All specified packages are already installed
2019-05-18 06:21:20,101 [salt.state       :1951][INFO    ][8000] Completed state [maas-region-controller] at time 06:21:20.101105 duration_in_ms=78.151
2019-05-18 06:21:20,101 [salt.state       :1780][INFO    ][8000] Running state [python-oauth] at time 06:21:20.101362
2019-05-18 06:21:20,101 [salt.state       :1813][INFO    ][8000] Executing state pkg.installed for [python-oauth]
2019-05-18 06:21:20,106 [salt.state       :300 ][INFO    ][8000] All specified packages are already installed
2019-05-18 06:21:20,106 [salt.state       :1951][INFO    ][8000] Completed state [python-oauth] at time 06:21:20.106796 duration_in_ms=5.433
2019-05-18 06:21:20,109 [salt.state       :1780][INFO    ][8000] Running state [/etc/maas/regiond.conf] at time 06:21:20.109286
2019-05-18 06:21:20,109 [salt.state       :1813][INFO    ][8000] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-18 06:21:20,159 [salt.state       :300 ][INFO    ][8000] No changes needed to be made
2019-05-18 06:21:20,159 [salt.state       :1951][INFO    ][8000] Completed state [/etc/maas/regiond.conf] at time 06:21:20.159862 duration_in_ms=50.576
2019-05-18 06:21:20,160 [salt.state       :1780][INFO    ][8000] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:21:20.160283
2019-05-18 06:21:20,160 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-18 06:21:20,225 [salt.state       :300 ][INFO    ][8000] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-18 06:21:20,225 [salt.state       :1951][INFO    ][8000] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:21:20.225333 duration_in_ms=65.049
2019-05-18 06:21:20,225 [salt.state       :1780][INFO    ][8000] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:21:20.225888
2019-05-18 06:21:20,226 [salt.state       :1813][INFO    ][8000] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-18 06:21:20,250 [salt.state       :300 ][INFO    ][8000] No changes needed to be made
2019-05-18 06:21:20,250 [salt.state       :1951][INFO    ][8000] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:21:20.250369 duration_in_ms=24.481
2019-05-18 06:21:20,250 [salt.state       :1780][INFO    ][8000] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:21:20.250861
2019-05-18 06:21:20,251 [salt.state       :1813][INFO    ][8000] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-18 06:21:20,281 [salt.state       :300 ][INFO    ][8000] No changes needed to be made
2019-05-18 06:21:20,282 [salt.state       :1951][INFO    ][8000] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:21:20.282342 duration_in_ms=31.479
2019-05-18 06:21:20,283 [salt.state       :1780][INFO    ][8000] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:21:20.283183
2019-05-18 06:21:20,283 [salt.state       :1813][INFO    ][8000] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-18 06:21:20,318 [salt.state       :300 ][INFO    ][8000] No changes needed to be made
2019-05-18 06:21:20,318 [salt.state       :1951][INFO    ][8000] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:21:20.318426 duration_in_ms=35.242
2019-05-18 06:21:20,319 [salt.state       :1780][INFO    ][8000] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:21:20.319130
2019-05-18 06:21:20,319 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-18 06:21:20,332 [salt.state       :300 ][INFO    ][8000] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-18 06:21:20,332 [salt.state       :1951][INFO    ][8000] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:21:20.332390 duration_in_ms=13.26
2019-05-18 06:21:20,334 [salt.state       :1780][INFO    ][8000] Running state [a2enmod headers] at time 06:21:20.334066
2019-05-18 06:21:20,334 [salt.state       :1813][INFO    ][8000] Executing state cmd.run for [a2enmod headers]
2019-05-18 06:21:20,335 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command 'a2enmod headers' in directory '/root'
2019-05-18 06:21:20,392 [salt.state       :300 ][INFO    ][8000] {'pid': 8031, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-18 06:21:20,392 [salt.state       :1951][INFO    ][8000] Completed state [a2enmod headers] at time 06:21:20.392816 duration_in_ms=58.75
2019-05-18 06:21:20,393 [salt.state       :1780][INFO    ][8000] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:21:20.393347
2019-05-18 06:21:20,393 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-18 06:21:20,411 [salt.state       :300 ][INFO    ][8000] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-18 06:21:20,412 [salt.state       :1951][INFO    ][8000] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:21:20.412220 duration_in_ms=18.872
2019-05-18 06:21:20,413 [salt.state       :1780][INFO    ][8000] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:21:20.413084
2019-05-18 06:21:20,416 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-18 06:21:20,519 [salt.state       :300 ][INFO    ][8000] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-18 06:21:20,519 [salt.state       :1951][INFO    ][8000] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:21:20.519742 duration_in_ms=106.657
2019-05-18 06:21:20,520 [salt.state       :1780][INFO    ][8000] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:21:20.520843
2019-05-18 06:21:20,521 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-18 06:21:20,596 [salt.state       :300 ][INFO    ][8000] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-18 06:21:20,597 [salt.state       :1951][INFO    ][8000] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:21:20.597095 duration_in_ms=76.251
2019-05-18 06:21:20,597 [salt.state       :1780][INFO    ][8000] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:21:20.597829
2019-05-18 06:21:20,598 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-18 06:21:20,680 [salt.state       :300 ][INFO    ][8000] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-18 06:21:20,680 [salt.state       :1951][INFO    ][8000] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:21:20.680893 duration_in_ms=83.064
2019-05-18 06:21:20,681 [salt.state       :1780][INFO    ][8000] Running state [/root/.pgpass] at time 06:21:20.681237
2019-05-18 06:21:20,681 [salt.state       :1813][INFO    ][8000] Executing state file.managed for [/root/.pgpass]
2019-05-18 06:21:20,746 [salt.state       :300 ][INFO    ][8000] File /root/.pgpass is in the correct state
2019-05-18 06:21:20,746 [salt.state       :1951][INFO    ][8000] Completed state [/root/.pgpass] at time 06:21:20.746888 duration_in_ms=65.65
2019-05-18 06:21:20,755 [salt.state       :1780][INFO    ][8000] Running state [maas-region syncdb --noinput] at time 06:21:20.755547
2019-05-18 06:21:20,756 [salt.state       :1813][INFO    ][8000] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-18 06:21:20,757 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-18 06:21:22,763 [salt.state       :300 ][INFO    ][8000] {'pid': 8055, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, sessions, auth, sites, metadataserver, piston3, contenttypes\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-18 06:21:22,763 [salt.state       :1951][INFO    ][8000] Completed state [maas-region syncdb --noinput] at time 06:21:22.763739 duration_in_ms=2008.192
2019-05-18 06:21:22,764 [salt.state       :2022][WARNING ][8000] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-18 06:21:22,767 [salt.state       :1780][INFO    ][8000] Running state [maas-regiond] at time 06:21:22.767111
2019-05-18 06:21:22,767 [salt.state       :1813][INFO    ][8000] Executing state service.running for [maas-regiond]
2019-05-18 06:21:22,769 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:22,808 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-18 06:21:22,827 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-18 06:21:22,844 [salt.state       :300 ][INFO    ][8000] The service maas-regiond is already running
2019-05-18 06:21:22,845 [salt.state       :1951][INFO    ][8000] Completed state [maas-regiond] at time 06:21:22.845236 duration_in_ms=78.125
2019-05-18 06:21:22,847 [salt.state       :1780][INFO    ][8000] Running state [bind9] at time 06:21:22.847643
2019-05-18 06:21:22,848 [salt.state       :1813][INFO    ][8000] Executing state service.running for [bind9]
2019-05-18 06:21:22,849 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:22,868 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-18 06:21:22,886 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-18 06:21:22,903 [salt.state       :300 ][INFO    ][8000] The service bind9 is already running
2019-05-18 06:21:22,904 [salt.state       :1951][INFO    ][8000] Completed state [bind9] at time 06:21:22.903944 duration_in_ms=56.301
2019-05-18 06:21:22,906 [salt.state       :1780][INFO    ][8000] Running state [apache2] at time 06:21:22.906270
2019-05-18 06:21:22,906 [salt.state       :1813][INFO    ][8000] Executing state service.running for [apache2]
2019-05-18 06:21:22,907 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-18 06:21:22,926 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-18 06:21:22,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-18 06:21:22,965 [salt.state       :300 ][INFO    ][8000] The service apache2 is already running
2019-05-18 06:21:22,965 [salt.state       :1951][INFO    ][8000] Completed state [apache2] at time 06:21:22.965653 duration_in_ms=59.382
2019-05-18 06:21:22,968 [salt.state       :1780][INFO    ][8000] Running state [maasng.wait_for_http_code] at time 06:21:22.968510
2019-05-18 06:21:22,969 [salt.state       :1813][INFO    ][8000] Executing state module.run for [maasng.wait_for_http_code]
2019-05-18 06:21:22,969 [salt.utils.decorators:613 ][WARNING ][8000] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:23,102 [salt.state       :300 ][INFO    ][8000] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-18 06:21:23,102 [salt.state       :1951][INFO    ][8000] Completed state [maasng.wait_for_http_code] at time 06:21:23.102854 duration_in_ms=134.344
2019-05-18 06:21:23,104 [salt.state       :1780][INFO    ][8000] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:21:23.104199
2019-05-18 06:21:23,104 [salt.state       :1813][INFO    ][8000] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-18 06:21:23,105 [salt.state       :300 ][INFO    ][8000] /var/lib/maas/.setup_admin exists
2019-05-18 06:21:23,105 [salt.state       :1951][INFO    ][8000] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:21:23.105755 duration_in_ms=1.556
2019-05-18 06:21:23,106 [salt.state       :1780][INFO    ][8000] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:23.106844
2019-05-18 06:21:23,107 [salt.state       :1813][INFO    ][8000] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:21:23,108 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8000] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:21:24,550 [salt.state       :300 ][INFO    ][8000] {'pid': 8080, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:21:24,551 [salt.state       :1951][INFO    ][8000] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:24.551035 duration_in_ms=1444.191
2019-05-18 06:21:24,554 [salt.state       :1780][INFO    ][8000] Running state [maas_region_boot_source_resources_mirror] at time 06:21:24.554664
2019-05-18 06:21:24,554 [salt.state       :1813][INFO    ][8000] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-18 06:21:24,644 [salt.state       :300 ][INFO    ][8000] {'changes': {}}
2019-05-18 06:21:24,645 [salt.state       :1951][INFO    ][8000] Completed state [maas_region_boot_source_resources_mirror] at time 06:21:24.644959 duration_in_ms=90.294
2019-05-18 06:21:24,645 [salt.state       :1780][INFO    ][8000] Running state [maasng.boot_resources_import] at time 06:21:24.645917
2019-05-18 06:21:24,646 [salt.state       :1813][INFO    ][8000] Executing state module.run for [maasng.boot_resources_import]
2019-05-18 06:21:24,646 [salt.utils.decorators:613 ][WARNING ][8000] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:24,735 [salt.loaded.ext.module.maasng:1600][INFO    ][8000] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-18 06:21:29,800 [salt.loaded.ext.module.maasng:1600][INFO    ][8000] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-18 06:21:33,611 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062133598163
2019-05-18 06:21:33,634 [salt.minion      :1432][INFO    ][8106] Starting a new job with PID 8106
2019-05-18 06:21:33,658 [salt.minion      :1711][INFO    ][8106] Returning information for job: 20190518062133598163
2019-05-18 06:21:34,870 [salt.loaded.ext.module.maasng:1600][INFO    ][8000] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-18 06:21:39,984 [salt.state       :300 ][INFO    ][8000] {'ret': True}
2019-05-18 06:21:39,984 [salt.state       :1951][INFO    ][8000] Completed state [maasng.boot_resources_import] at time 06:21:39.984482 duration_in_ms=15338.564
2019-05-18 06:21:39,985 [salt.state       :1780][INFO    ][8000] Running state [maas_region_boot_sources_selection_xenial] at time 06:21:39.985702
2019-05-18 06:21:39,986 [salt.state       :1813][INFO    ][8000] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-18 06:21:40,217 [salt.state       :300 ][INFO    ][8000] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-18 06:21:40,217 [salt.state       :1951][INFO    ][8000] Completed state [maas_region_boot_sources_selection_xenial] at time 06:21:40.217409 duration_in_ms=231.707
2019-05-18 06:21:40,218 [salt.state       :1780][INFO    ][8000] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:21:40.218836
2019-05-18 06:21:40,219 [salt.state       :1813][INFO    ][8000] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-18 06:21:40,219 [salt.utils.decorators:613 ][WARNING ][8000] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:40,220 [salt.loaded.ext.module.maasng:1771][INFO    ][8000] boot-sources sync initiated for ALL Rack's
2019-05-18 06:21:41,261 [salt.state       :300 ][INFO    ][8000] {'ret': True}
2019-05-18 06:21:41,261 [salt.state       :1951][INFO    ][8000] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:21:41.261553 duration_in_ms=1042.716
2019-05-18 06:21:41,263 [salt.state       :1780][INFO    ][8000] Running state [maas.process_maas_config] at time 06:21:41.263817
2019-05-18 06:21:41,264 [salt.state       :1813][INFO    ][8000] Executing state module.run for [maas.process_maas_config]
2019-05-18 06:21:41,264 [salt.utils.decorators:613 ][WARNING ][8000] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:41,265 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=enable_http_proxy value=True
2019-05-18 06:21:41,322 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=upstream_dns value=8.8.8.8
2019-05-18 06:21:44,319 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=commissioning_distro_series value=xenial
2019-05-18 06:21:44,387 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=default_osystem value=ubuntu
2019-05-18 06:21:44,466 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=active_discovery_interval value=600
2019-05-18 06:21:44,517 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=dnssec_validation value=no
2019-05-18 06:21:44,570 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=maas_name value=mas01
2019-05-18 06:21:44,618 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=network_discovery value=enabled
2019-05-18 06:21:44,727 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=enable_third_party_drivers value=True
2019-05-18 06:21:44,783 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=default_storage_layout value=lvm
2019-05-18 06:21:44,836 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=ntp_external_only value=True
2019-05-18 06:21:44,884 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-18 06:21:44,934 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=default_distro_series value=xenial
2019-05-18 06:21:44,986 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-18 06:21:45,070 [salt.state       :300 ][INFO    ][8000] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-18 06:21:45,070 [salt.state       :1951][INFO    ][8000] Completed state [maas.process_maas_config] at time 06:21:45.070693 duration_in_ms=3806.877
2019-05-18 06:21:45,071 [salt.state       :1780][INFO    ][8000] Running state [pxe_admin] at time 06:21:45.071325
2019-05-18 06:21:45,071 [salt.state       :1813][INFO    ][8000] Executing state maasng.fabric_present for [pxe_admin]
2019-05-18 06:21:45,121 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:21:45,183 [salt.loaded.ext.module.maasng:1008][WARNING ][8000] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-18 06:21:45,184 [salt.loaded.ext.module.maasng:1011][WARNING ][8000] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-18 06:21:45,254 [salt.state       :300 ][INFO    ][8000] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-18 06:21:45,254 [salt.state       :1951][INFO    ][8000] Completed state [pxe_admin] at time 06:21:45.254782 duration_in_ms=183.457
2019-05-18 06:21:45,255 [salt.state       :1780][INFO    ][8000] Running state [vlan 0] at time 06:21:45.255025
2019-05-18 06:21:45,255 [salt.state       :1813][INFO    ][8000] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-18 06:21:45,288 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:21:45,379 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:21:45,651 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fneaqm', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-18 06:21:45,767 [salt.state       :300 ][INFO    ][8000] {'new': 'Vlan untagged was updated'}
2019-05-18 06:21:45,768 [salt.state       :1951][INFO    ][8000] Completed state [vlan 0] at time 06:21:45.768315 duration_in_ms=513.289
2019-05-18 06:21:45,770 [salt.state       :1780][INFO    ][8000] Running state [192.168.11.0/24] at time 06:21:45.769956
2019-05-18 06:21:45,770 [salt.state       :1813][INFO    ][8000] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-18 06:21:46,038 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:21:46,039 [salt.loaded.ext.module.maasng:1235][WARNING ][8000] Ignoring parameter vlan:0
2019-05-18 06:21:46,086 [salt.state       :300 ][INFO    ][8000] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-18 06:21:46,086 [salt.state       :1951][INFO    ][8000] Completed state [192.168.11.0/24] at time 06:21:46.086670 duration_in_ms=316.714
2019-05-18 06:21:46,087 [salt.state       :1780][INFO    ][8000] Running state [maas_create_iprange_1] at time 06:21:46.087838
2019-05-18 06:21:46,088 [salt.state       :1813][INFO    ][8000] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-18 06:21:46,140 [salt.state       :300 ][INFO    ][8000] Iprange maas_create_iprange_1 already exist.
2019-05-18 06:21:46,140 [salt.state       :1951][INFO    ][8000] Completed state [maas_create_iprange_1] at time 06:21:46.140504 duration_in_ms=52.666
2019-05-18 06:21:46,140 [salt.state       :1780][INFO    ][8000] Running state [vlan 0] at time 06:21:46.140894
2019-05-18 06:21:46,141 [salt.state       :1813][INFO    ][8000] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-18 06:21:46,177 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', 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-05-18 06:21:46,280 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-18 06:21:46,469 [salt.loaded.ext.module.maasng:945 ][INFO    ][8000] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fneaqm', 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-05-18 06:21:46,572 [salt.state       :300 ][INFO    ][8000] {'new': 'Vlan untagged was updated'}
2019-05-18 06:21:46,572 [salt.state       :1951][INFO    ][8000] Completed state [vlan 0] at time 06:21:46.572522 duration_in_ms=431.627
2019-05-18 06:21:46,573 [salt.state       :1780][INFO    ][8000] Running state [opnfv] at time 06:21:46.573789
2019-05-18 06:21:46,574 [salt.state       :1813][INFO    ][8000] Executing state maasng.sshkey_present for [opnfv]
2019-05-18 06:21:46,619 [salt.loaded.ext.module.maasng:1903][INFO    ][8000] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-18 06:21:46,620 [salt.state       :300 ][INFO    ][8000] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-18 06:21:46,620 [salt.state       :1951][INFO    ][8000] Completed state [opnfv] at time 06:21:46.620250 duration_in_ms=46.461
2019-05-18 06:21:46,621 [salt.state       :1780][INFO    ][8000] Running state [maas.process_tags] at time 06:21:46.621041
2019-05-18 06:21:46,621 [salt.state       :1813][INFO    ][8000] Executing state module.run for [maas.process_tags]
2019-05-18 06:21:46,621 [salt.utils.decorators:613 ][WARNING ][8000] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:46,655 [salt.loaded.ext.module.maas:92  ][INFO    ][8000] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-18 06:21:46,704 [salt.state       :300 ][INFO    ][8000] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-18 06:21:46,705 [salt.state       :1951][INFO    ][8000] Completed state [maas.process_tags] at time 06:21:46.705097 duration_in_ms=84.055
2019-05-18 06:21:46,709 [salt.minion      :1711][INFO    ][8000] Returning information for job: 20190518062118549163
2019-05-18 06:21:47,246 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518062147233337
2019-05-18 06:21:47,265 [salt.minion      :1432][INFO    ][8472] Starting a new job with PID 8472
2019-05-18 06:21:50,849 [salt.state       :915 ][INFO    ][8472] Loading fresh modules for state activity
2019-05-18 06:21:50,945 [salt.state       :1780][INFO    ][8472] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:50.945794
2019-05-18 06:21:50,946 [salt.state       :1813][INFO    ][8472] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:21:50,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8472] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:21:52,383 [salt.state       :300 ][INFO    ][8472] {'pid': 8502, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:21:52,384 [salt.state       :1951][INFO    ][8472] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:21:52.384264 duration_in_ms=1438.47
2019-05-18 06:21:52,387 [salt.state       :1780][INFO    ][8472] Running state [maas.process_machines] at time 06:21:52.386949
2019-05-18 06:21:52,387 [salt.state       :1813][INFO    ][8472] Executing state module.run for [maas.process_machines]
2019-05-18 06:21:52,388 [salt.utils.decorators:613 ][WARNING ][8472] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:21:52,999 [salt.loaded.ext.module.maas:412 ][WARNING ][8472] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:21:53,000 [salt.loaded.ext.module.maas:92  ][INFO    ][8472] 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=btabyy architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:21:53,999 [salt.loaded.ext.module.maas:412 ][WARNING ][8472] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:21:54,000 [salt.loaded.ext.module.maas:92  ][INFO    ][8472] 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=efwn6b architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:21:55,256 [salt.loaded.ext.module.maas:412 ][WARNING ][8472] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:21:55,257 [salt.loaded.ext.module.maas:92  ][INFO    ][8472] 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=6ry76x architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:21:56,455 [salt.loaded.ext.module.maas:412 ][WARNING ][8472] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:21:56,456 [salt.loaded.ext.module.maas:92  ][INFO    ][8472] 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=ah8g3b architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:21:57,743 [salt.loaded.ext.module.maas:412 ][WARNING ][8472] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-18 06:21:57,744 [salt.loaded.ext.module.maas:92  ][INFO    ][8472] 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=fss87y architecture=amd64/generic power_parameters_power_user=admin
2019-05-18 06:21:58,940 [salt.state       :300 ][INFO    ][8472] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-18 06:21:58,940 [salt.state       :1951][INFO    ][8472] Completed state [maas.process_machines] at time 06:21:58.940716 duration_in_ms=6553.766
2019-05-18 06:21:58,944 [salt.minion      :1711][INFO    ][8472] Returning information for job: 20190518062147233337
2019-05-18 06:22:32,252 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518062232239542
2019-05-18 06:22:32,274 [salt.minion      :1432][INFO    ][8768] Starting a new job with PID 8768
2019-05-18 06:22:35,972 [salt.state       :915 ][INFO    ][8768] Loading fresh modules for state activity
2019-05-18 06:22:36,063 [salt.state       :1780][INFO    ][8768] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:22:36.063174
2019-05-18 06:22:36,063 [salt.state       :1813][INFO    ][8768] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:22:36,065 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8768] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:22:37,507 [salt.state       :300 ][INFO    ][8768] {'pid': 8775, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:22:37,507 [salt.state       :1951][INFO    ][8768] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:22:37.507620 duration_in_ms=1444.448
2019-05-18 06:22:37,508 [salt.state       :1780][INFO    ][8768] Running state [maas.wait_for_machine_status] at time 06:22:37.508829
2019-05-18 06:22:37,509 [salt.state       :1813][INFO    ][8768] Executing state module.run for [maas.wait_for_machine_status]
2019-05-18 06:22:37,509 [salt.utils.decorators:613 ][WARNING ][8768] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:22:41,071 [salt.loaded.ext.module.maas:993 ][INFO    ][8768] Machine fss87y mark broken
2019-05-18 06:22:41,721 [salt.loaded.ext.module.maas:996 ][INFO    ][8768] Machine fss87y mark fixed
2019-05-18 06:22:42,947 [salt.loaded.ext.module.maas:684 ][INFO    ][8768] deploymachines hwe_kernel=hwe-16.04 system_id=fss87y distro_series=xenial
2019-05-18 06:22:45,578 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1491.93542814s left)
2019-05-18 06:22:47,366 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062247353793
2019-05-18 06:22:47,390 [salt.minion      :1432][INFO    ][8847] Starting a new job with PID 8847
2019-05-18 06:22:47,415 [salt.minion      :1711][INFO    ][8847] Returning information for job: 20190518062247353793
2019-05-18 06:23:17,578 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062317526526
2019-05-18 06:23:17,599 [salt.minion      :1432][INFO    ][8884] Starting a new job with PID 8884
2019-05-18 06:23:17,623 [salt.minion      :1711][INFO    ][8884] Returning information for job: 20190518062317526526
2019-05-18 06:23:19,118 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1458.39608502s left)
2019-05-18 06:23:47,647 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062347634372
2019-05-18 06:23:47,670 [salt.minion      :1432][INFO    ][8932] Starting a new job with PID 8932
2019-05-18 06:23:47,698 [salt.minion      :1711][INFO    ][8932] Returning information for job: 20190518062347634372
2019-05-18 06:23:52,731 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1424.78279305s left)
2019-05-18 06:24:17,702 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062417688974
2019-05-18 06:24:17,724 [salt.minion      :1432][INFO    ][8959] Starting a new job with PID 8959
2019-05-18 06:24:17,750 [salt.minion      :1711][INFO    ][8959] Returning information for job: 20190518062417688974
2019-05-18 06:24:25,732 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1391.78183699s left)
2019-05-18 06:24:47,774 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062447761040
2019-05-18 06:24:47,796 [salt.minion      :1432][INFO    ][9058] Starting a new job with PID 9058
2019-05-18 06:24:47,824 [salt.minion      :1711][INFO    ][9058] Returning information for job: 20190518062447761040
2019-05-18 06:24:59,115 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1358.39890909s left)
2019-05-18 06:25:17,825 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062517812600
2019-05-18 06:25:17,848 [salt.minion      :1432][INFO    ][9169] Starting a new job with PID 9169
2019-05-18 06:25:17,874 [salt.minion      :1711][INFO    ][9169] Returning information for job: 20190518062517812600
2019-05-18 06:25:32,743 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1324.77039003s left)
2019-05-18 06:25:47,890 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062547876230
2019-05-18 06:25:47,913 [salt.minion      :1432][INFO    ][9364] Starting a new job with PID 9364
2019-05-18 06:25:47,939 [salt.minion      :1711][INFO    ][9364] Returning information for job: 20190518062547876230
2019-05-18 06:26:05,922 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1291.5918901s left)
2019-05-18 06:26:17,952 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062617939720
2019-05-18 06:26:17,974 [salt.minion      :1432][INFO    ][9394] Starting a new job with PID 9394
2019-05-18 06:26:17,999 [salt.minion      :1711][INFO    ][9394] Returning information for job: 20190518062617939720
2019-05-18 06:26:39,509 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1258.00445008s left)
2019-05-18 06:26:48,022 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062648008651
2019-05-18 06:26:48,045 [salt.minion      :1432][INFO    ][9469] Starting a new job with PID 9469
2019-05-18 06:26:48,071 [salt.minion      :1711][INFO    ][9469] Returning information for job: 20190518062648008651
2019-05-18 06:27:12,534 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1224.97926998s left)
2019-05-18 06:27:18,094 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062718079422
2019-05-18 06:27:18,120 [salt.minion      :1432][INFO    ][9499] Starting a new job with PID 9499
2019-05-18 06:27:18,150 [salt.minion      :1711][INFO    ][9499] Returning information for job: 20190518062718079422
2019-05-18 06:27:45,752 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.76222897s left)
2019-05-18 06:27:48,178 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062748165767
2019-05-18 06:27:48,201 [salt.minion      :1432][INFO    ][9656] Starting a new job with PID 9656
2019-05-18 06:27:48,232 [salt.minion      :1711][INFO    ][9656] Returning information for job: 20190518062748165767
2019-05-18 06:28:18,260 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062818248189
2019-05-18 06:28:18,280 [salt.minion      :1432][INFO    ][9698] Starting a new job with PID 9698
2019-05-18 06:28:18,309 [salt.minion      :1711][INFO    ][9698] Returning information for job: 20190518062818248189
2019-05-18 06:28:19,403 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1158.11059809s left)
2019-05-18 06:28:48,347 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062848333601
2019-05-18 06:28:48,370 [salt.minion      :1432][INFO    ][9830] Starting a new job with PID 9830
2019-05-18 06:28:48,398 [salt.minion      :1711][INFO    ][9830] Returning information for job: 20190518062848333601
2019-05-18 06:28:53,093 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.42066503s left)
2019-05-18 06:29:18,443 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062918431098
2019-05-18 06:29:18,462 [salt.minion      :1432][INFO    ][9863] Starting a new job with PID 9863
2019-05-18 06:29:18,489 [salt.minion      :1711][INFO    ][9863] Returning information for job: 20190518062918431098
2019-05-18 06:29:26,919 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1090.59492707s left)
2019-05-18 06:29:48,538 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518062948526155
2019-05-18 06:29:48,561 [salt.minion      :1432][INFO    ][9916] Starting a new job with PID 9916
2019-05-18 06:29:48,590 [salt.minion      :1711][INFO    ][9916] Returning information for job: 20190518062948526155
2019-05-18 06:30:00,135 [salt.loaded.ext.module.maas:1023][INFO    ][8768] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1057.37920094s left)
2019-05-18 06:30:18,639 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command saltutil.find_job with jid 20190518063018626368
2019-05-18 06:30:18,662 [salt.minion      :1432][INFO    ][9982] Starting a new job with PID 9982
2019-05-18 06:30:18,691 [salt.minion      :1711][INFO    ][9982] Returning information for job: 20190518063018626368
2019-05-18 06:30:33,907 [salt.state       :300 ][INFO    ][8768] {'ret': True}
2019-05-18 06:30:33,908 [salt.state       :1951][INFO    ][8768] Completed state [maas.wait_for_machine_status] at time 06:30:33.908053 duration_in_ms=476399.222
2019-05-18 06:30:33,912 [salt.minion      :1711][INFO    ][8768] Returning information for job: 20190518062232239542
2019-05-18 06:30:34,528 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518063034514769
2019-05-18 06:30:34,549 [salt.minion      :1432][INFO    ][10090] Starting a new job with PID 10090
2019-05-18 06:30:38,062 [salt.state       :915 ][INFO    ][10090] Loading fresh modules for state activity
2019-05-18 06:30:38,205 [salt.state       :1780][INFO    ][10090] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:38.205523
2019-05-18 06:30:38,205 [salt.state       :1813][INFO    ][10090] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:30:38,207 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10090] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:30:39,675 [salt.state       :300 ][INFO    ][10090] {'pid': 10097, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:30:39,676 [salt.state       :1951][INFO    ][10090] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:39.676107 duration_in_ms=1470.583
2019-05-18 06:30:39,679 [salt.state       :1780][INFO    ][10090] Running state [maas_machines_storage_cmp002_lvm] at time 06:30:39.679464
2019-05-18 06:30:39,680 [salt.state       :1813][INFO    ][10090] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-18 06:30:40,413 [salt.state       :300 ][INFO    ][10090] Machine cmp002 is not in Ready state.
2019-05-18 06:30:40,413 [salt.state       :1951][INFO    ][10090] Completed state [maas_machines_storage_cmp002_lvm] at time 06:30:40.413535 duration_in_ms=734.07
2019-05-18 06:30:40,414 [salt.state       :1780][INFO    ][10090] Running state [maas_machines_storage_cmp001_lvm] at time 06:30:40.414089
2019-05-18 06:30:40,414 [salt.state       :1813][INFO    ][10090] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-18 06:30:41,020 [salt.state       :300 ][INFO    ][10090] Machine cmp001 is not in Ready state.
2019-05-18 06:30:41,021 [salt.state       :1951][INFO    ][10090] Completed state [maas_machines_storage_cmp001_lvm] at time 06:30:41.021251 duration_in_ms=607.162
2019-05-18 06:30:41,025 [salt.minion      :1711][INFO    ][10090] Returning information for job: 20190518063034514769
2019-05-18 06:30:41,649 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518063041636269
2019-05-18 06:30:41,671 [salt.minion      :1432][INFO    ][10107] Starting a new job with PID 10107
2019-05-18 06:30:42,492 [salt.state       :915 ][INFO    ][10107] Loading fresh modules for state activity
2019-05-18 06:30:42,583 [salt.state       :1780][INFO    ][10107] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:42.583329
2019-05-18 06:30:42,583 [salt.state       :1813][INFO    ][10107] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:30:42,586 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10107] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:30:44,203 [salt.state       :300 ][INFO    ][10107] {'pid': 10114, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:30:44,204 [salt.state       :1951][INFO    ][10107] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:44.204204 duration_in_ms=1620.875
2019-05-18 06:30:44,206 [salt.state       :1780][INFO    ][10107] Running state [maas.deploy_machines] at time 06:30:44.206904
2019-05-18 06:30:44,207 [salt.state       :1813][INFO    ][10107] Executing state module.run for [maas.deploy_machines]
2019-05-18 06:30:44,208 [salt.utils.decorators:613 ][WARNING ][10107] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:30:44,850 [salt.state       :300 ][INFO    ][10107] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-18 06:30:44,851 [salt.state       :1951][INFO    ][10107] Completed state [maas.deploy_machines] at time 06:30:44.851193 duration_in_ms=644.288
2019-05-18 06:30:44,854 [salt.minion      :1711][INFO    ][10107] Returning information for job: 20190518063041636269
2019-05-18 06:30:45,486 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command state.apply with jid 20190518063045472296
2019-05-18 06:30:45,510 [salt.minion      :1432][INFO    ][10131] Starting a new job with PID 10131
2019-05-18 06:30:46,299 [salt.state       :915 ][INFO    ][10131] Loading fresh modules for state activity
2019-05-18 06:30:46,389 [salt.state       :1780][INFO    ][10131] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:46.388966
2019-05-18 06:30:46,389 [salt.state       :1813][INFO    ][10131] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-18 06:30:46,391 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10131] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-18 06:30:47,824 [salt.state       :300 ][INFO    ][10131] {'pid': 10138, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-18 06:30:47,825 [salt.state       :1951][INFO    ][10131] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:30:47.825257 duration_in_ms=1436.292
2019-05-18 06:30:47,826 [salt.state       :1780][INFO    ][10131] Running state [maas.wait_for_machine_status] at time 06:30:47.826869
2019-05-18 06:30:47,827 [salt.state       :1813][INFO    ][10131] Executing state module.run for [maas.wait_for_machine_status]
2019-05-18 06:30:47,827 [salt.utils.decorators:613 ][WARNING ][10131] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-18 06:30:51,260 [salt.state       :300 ][INFO    ][10131] {'ret': True}
2019-05-18 06:30:51,260 [salt.state       :1951][INFO    ][10131] Completed state [maas.wait_for_machine_status] at time 06:30:51.260857 duration_in_ms=3433.986
2019-05-18 06:30:51,265 [salt.minion      :1711][INFO    ][10131] Returning information for job: 20190518063045472296
2019-05-18 07:00:39,055 [salt.utils.schedule:1377][INFO    ][650] Running scheduled job: __mine_interval
2019-05-18 07:56:23,438 [salt.minion      :1308][INFO    ][650] User sudo_ubuntu Executing command cp.push_dir with jid 20190518075623432083
2019-05-18 07:56:23,454 [salt.minion      :1432][INFO    ][16068] Starting a new job with PID 16068
