2019-11-06 20:09:20,713 [salt.utils.decorators:613 ][WARNING ][2060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:09:21,252 [salt.utils.decorators:613 ][WARNING ][2060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:09:23,455 [salt.loaded.int.states.file:2298][WARNING ][2354] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-11-06 20:09:50,626 [salt.state       :2022][WARNING ][3036] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-06 20:09:53,124 [salt.utils.decorators:613 ][WARNING ][3036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:10:44,831 [salt.utils.decorators:613 ][WARNING ][3036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:11:21,754 [salt.utils.decorators:613 ][WARNING ][3036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:11:22,736 [salt.utils.decorators:613 ][WARNING ][3036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:11:26,593 [salt.loaded.ext.module.maasng:1008][WARNING ][3036] Detected cidr:192.168.11.0/24 in fabric:fabric-4
2019-11-06 20:11:26,593 [salt.loaded.ext.module.maasng:1011][WARNING ][3036] Guessing, that fabric with current name:fabric-4
 should be renamed to:pxe_admin
2019-11-06 20:11:27,340 [salt.loaded.ext.module.maasng:1235][WARNING ][3036] Ignoring parameter vlan:0
2019-11-06 20:11:28,368 [salt.utils.decorators:613 ][WARNING ][3036] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:11:37,772 [salt.utils.decorators:613 ][WARNING ][6868] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:11:37,840 [salt.loaded.ext.module.maas:412 ][WARNING ][6868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:11:39,153 [salt.loaded.ext.module.maas:412 ][WARNING ][6868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:11:40,445 [salt.loaded.ext.module.maas:412 ][WARNING ][6868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:11:41,553 [salt.loaded.ext.module.maas:412 ][WARNING ][6868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:11:45,213 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7435] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-06 20:11:45,244 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7435] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-06 20:11:45,269 [salt.utils.parsers:1051][WARNING ][317] Minion received a SIGTERM. Exiting.
2019-11-06 20:11:46,266 [salt.cli.daemons :293 ][INFO    ][7502] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-11-06 20:11:46,348 [salt.cli.daemons :82  ][INFO    ][7502] Starting up the Salt Minion
2019-11-06 20:11:46,348 [salt.utils.event :1017][INFO    ][7502] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-11-06 20:11:47,199 [salt.minion      :976 ][INFO    ][7502] Creating minion process manager
2019-11-06 20:11:48,522 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7502] Executing command ['date', '+%z'] in directory '/root'
2019-11-06 20:11:48,541 [salt.utils.schedule:568 ][INFO    ][7502] Updating job settings for scheduled job: __mine_interval
2019-11-06 20:11:48,542 [salt.minion      :1108][INFO    ][7502] Added mine.update to scheduler
2019-11-06 20:11:48,546 [salt.minion      :1975][INFO    ][7502] Minion is starting as user 'root'
2019-11-06 20:11:48,558 [salt.minion      :2336][INFO    ][7502] Minion is ready to receive requests!
2019-11-06 20:12:13,843 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106201213831943
2019-11-06 20:12:13,863 [salt.minion      :1432][INFO    ][7604] Starting a new job with PID 7604
2019-11-06 20:12:17,392 [salt.state       :915 ][INFO    ][7604] Loading fresh modules for state activity
2019-11-06 20:12:17,448 [salt.fileclient  :1219][INFO    ][7604] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-06 20:12:17,488 [salt.state       :1780][INFO    ][7604] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:12:17.488200
2019-11-06 20:12:17,488 [salt.state       :1813][INFO    ][7604] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:12:17,490 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7604] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:12:18,928 [salt.state       :300 ][INFO    ][7604] {'pid': 7616, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:12:18,929 [salt.state       :1951][INFO    ][7604] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:12:18.929288 duration_in_ms=1441.089
2019-11-06 20:12:18,930 [salt.state       :1780][INFO    ][7604] Running state [maas.wait_for_machine_status] at time 20:12:18.930429
2019-11-06 20:12:18,930 [salt.state       :1813][INFO    ][7604] Executing state module.run for [maas.wait_for_machine_status]
2019-11-06 20:12:18,930 [salt.utils.decorators:613 ][WARNING ][7604] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:12:19,643 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.29236197s left)
2019-11-06 20:12:28,898 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201228885254
2019-11-06 20:12:28,921 [salt.minion      :1432][INFO    ][7643] Starting a new job with PID 7643
2019-11-06 20:12:28,945 [salt.minion      :1711][INFO    ][7643] Returning information for job: 20191106201228885254
2019-11-06 20:12:50,375 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.56044388s left)
2019-11-06 20:12:58,955 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201258941934
2019-11-06 20:12:58,975 [salt.minion      :1432][INFO    ][7679] Starting a new job with PID 7679
2019-11-06 20:12:58,993 [salt.minion      :1711][INFO    ][7679] Returning information for job: 20191106201258941934
2019-11-06 20:13:21,188 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1437.74786186s left)
2019-11-06 20:13:29,014 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201329006267
2019-11-06 20:13:29,033 [salt.minion      :1432][INFO    ][7806] Starting a new job with PID 7806
2019-11-06 20:13:29,055 [salt.minion      :1711][INFO    ][7806] Returning information for job: 20191106201329006267
2019-11-06 20:13:52,038 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1406.89750195s left)
2019-11-06 20:13:59,061 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201359048025
2019-11-06 20:13:59,084 [salt.minion      :1432][INFO    ][8061] Starting a new job with PID 8061
2019-11-06 20:13:59,107 [salt.minion      :1711][INFO    ][8061] Returning information for job: 20191106201359048025
2019-11-06 20:14:23,036 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1375.8995409s left)
2019-11-06 20:14:29,123 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201429110332
2019-11-06 20:14:29,146 [salt.minion      :1432][INFO    ][8372] Starting a new job with PID 8372
2019-11-06 20:14:29,170 [salt.minion      :1711][INFO    ][8372] Returning information for job: 20191106201429110332
2019-11-06 20:14:54,294 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1344.64130688s left)
2019-11-06 20:14:59,187 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201459173791
2019-11-06 20:14:59,209 [salt.minion      :1432][INFO    ][8523] Starting a new job with PID 8523
2019-11-06 20:14:59,232 [salt.minion      :1711][INFO    ][8523] Returning information for job: 20191106201459173791
2019-11-06 20:15:26,458 [salt.loaded.ext.module.maas:1023][INFO    ][7604] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1312.47760987s left)
2019-11-06 20:15:29,253 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201529237873
2019-11-06 20:15:29,276 [salt.minion      :1432][INFO    ][8714] Starting a new job with PID 8714
2019-11-06 20:15:29,300 [salt.minion      :1711][INFO    ][8714] Returning information for job: 20191106201529237873
2019-11-06 20:15:58,778 [salt.state       :300 ][INFO    ][7604] {'ret': True}
2019-11-06 20:15:58,779 [salt.state       :1951][INFO    ][7604] Completed state [maas.wait_for_machine_status] at time 20:15:58.778911 duration_in_ms=219848.48
2019-11-06 20:15:58,782 [salt.minion      :1711][INFO    ][7604] Returning information for job: 20191106201213831943
2019-11-06 20:15:59,427 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106201559411563
2019-11-06 20:15:59,449 [salt.minion      :1432][INFO    ][8790] Starting a new job with PID 8790
2019-11-06 20:16:03,190 [salt.state       :915 ][INFO    ][8790] Loading fresh modules for state activity
2019-11-06 20:16:03,242 [salt.fileclient  :1219][INFO    ][8790] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-06 20:16:03,331 [salt.state       :1780][INFO    ][8790] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:03.331203
2019-11-06 20:16:03,331 [salt.state       :1813][INFO    ][8790] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:16:03,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8790] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:16:04,783 [salt.state       :300 ][INFO    ][8790] {'pid': 8803, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:16:04,784 [salt.state       :1951][INFO    ][8790] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:04.784345 duration_in_ms=1453.143
2019-11-06 20:16:04,785 [salt.state       :1780][INFO    ][8790] Running state [maas_machines_storage_cmp002_lvm] at time 20:16:04.785822
2019-11-06 20:16:04,786 [salt.state       :1813][INFO    ][8790] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-06 20:16:05,993 [salt.loaded.ext.module.maasng:610 ][INFO    ][8790] gn3kwy
2019-11-06 20:16:05,993 [salt.loaded.ext.module.maasng:626 ][INFO    ][8790] sda
2019-11-06 20:16:06,407 [salt.loaded.ext.module.maasng:361 ][INFO    ][8790] gn3kwy
2019-11-06 20:16:06,523 [salt.loaded.ext.module.maasng:367 ][INFO    ][8790] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'438edd72-20c2-4c08-a158-3d20be9e520b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gn3kwy', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'aae4631d-dd9b-4322-aa8e-6287af03923f', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/partition/5', u'type': u'partition', u'id': 5, u'device_id': 4}], u'filesystem': None, u'name': u'sda', u'system_id': u'gn3kwy', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/', u'type': u'physical', u'id': 4, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'uuid': u'5a4c596f-7f7a-44c3-965f-5ac8317e20ad', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'876d3df7-63a0-4600-8715-189572604228', u'fstype': u'ext4', u'label': u'root'}, u'name': u'vgroot-lvroot', u'system_id': u'gn3kwy', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/9/', u'type': u'virtual', u'id': 9, u'size': 2397988454400}]
2019-11-06 20:16:06,524 [salt.loaded.ext.module.maasng:632 ][INFO    ][8790] vgroot
2019-11-06 20:16:06,524 [salt.loaded.ext.module.maasng:635 ][INFO    ][8790] lvroot
2019-11-06 20:16:06,525 [salt.loaded.ext.module.maasng:639 ][INFO    ][8790] 107374182400
2019-11-06 20:16:07,231 [salt.loaded.ext.module.maasng:645 ][INFO    ][8790] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'disable_ipv4': False, u'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'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 35}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'system_id': u'gn3kwy', u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/interfaces/5/'}, u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'gn3kwy', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'2dff2607-fec8-4e04-95d8-183e86ea06e3', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gn3kwy', u'filesystem': {u'mount_options': None, u'uuid': u'f2f2eb86-9bfb-48e0-89c1-295c3bf523f2', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 4, u'size': 2397998940160}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/gn3kwy/', u'current_commissioning_result_id': 4, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'gn3kwy', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'gn3kwy', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'2dff2607-fec8-4e04-95d8-183e86ea06e3', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gn3kwy', u'filesystem': {u'mount_options': None, u'uuid': u'f2f2eb86-9bfb-48e0-89c1-295c3bf523f2', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 4, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'73dad55e-49d5-4d20-8884-a209f42c8cb1', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'uuid': u'addaa926-1a47-4a07-a36b-ee168f5c8507', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'gn3kwy', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'gn3kwy', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'2dff2607-fec8-4e04-95d8-183e86ea06e3', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/4/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'gn3kwy', u'filesystem': {u'mount_options': None, u'uuid': u'f2f2eb86-9bfb-48e0-89c1-295c3bf523f2', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 4, u'size': 2397998940160}], u'ip_addresses': [u'192.168.11.41'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'gn3kwy', u'id': 8}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'73dad55e-49d5-4d20-8884-a209f42c8cb1', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'uuid': u'addaa926-1a47-4a07-a36b-ee168f5c8507', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'gn3kwy', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'size': 107374182400}], 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'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 35}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'system_id': u'gn3kwy', u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 36}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'gn3kwy', u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/interfaces/15/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 37}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'gn3kwy', u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/interfaces/17/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 38}], u'tags': [], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'gn3kwy', u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/gn3kwy/interfaces/19/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-06 20:16:07,233 [salt.state       :300 ][INFO    ][8790] {'new': {'storage_layout': 'lvm'}}
2019-11-06 20:16:07,233 [salt.state       :1951][INFO    ][8790] Completed state [maas_machines_storage_cmp002_lvm] at time 20:16:07.233732 duration_in_ms=2447.907
2019-11-06 20:16:07,234 [salt.state       :1780][INFO    ][8790] Running state [maas_machines_storage_cmp001_lvm] at time 20:16:07.234196
2019-11-06 20:16:07,234 [salt.state       :1813][INFO    ][8790] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-06 20:16:08,499 [salt.loaded.ext.module.maasng:610 ][INFO    ][8790] wh737w
2019-11-06 20:16:08,500 [salt.loaded.ext.module.maasng:626 ][INFO    ][8790] sda
2019-11-06 20:16:09,080 [salt.loaded.ext.module.maasng:361 ][INFO    ][8790] wh737w
2019-11-06 20:16:09,207 [salt.loaded.ext.module.maasng:367 ][INFO    ][8790] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'wh737w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'd9ba3cd3-300e-4ae5-b8c8-62e8a0be4961', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wh737w', u'filesystem': {u'mount_options': None, u'uuid': u'1faad3ca-185d-429e-8561-45cc4edf8b68', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'type': u'physical', u'id': 3, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/10/', u'used_size': 2397988454400, u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'29b0e568-daaa-4bfc-b783-c806cb187ef5', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'uuid': u'8571dd59-c253-473e-99a4-de8ddfc70dcb', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'wh737w', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 10, u'size': 2397988454400}]
2019-11-06 20:16:09,208 [salt.loaded.ext.module.maasng:632 ][INFO    ][8790] vgroot
2019-11-06 20:16:09,208 [salt.loaded.ext.module.maasng:635 ][INFO    ][8790] lvroot
2019-11-06 20:16:09,209 [salt.loaded.ext.module.maasng:639 ][INFO    ][8790] 107374182400
2019-11-06 20:16:09,927 [salt.loaded.ext.module.maasng:645 ][INFO    ][8790] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 39}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'wh737w', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/interfaces/6/'}, u'fqdn': u'cmp001.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'34f444e1-6f51-4708-aa9c-2e3c5c822111', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wh737w', u'filesystem': {u'uuid': u'fd100bdb-b00e-42f5-83ca-3ad4dd9860b0', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'filesystem': None, u'name': u'sda', u'system_id': u'wh737w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/'}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'owner_data': {}, u'system_id': u'wh737w', u'power_state': u'off', 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'ip_addresses': [u'192.168.11.39'], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'34f444e1-6f51-4708-aa9c-2e3c5c822111', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wh737w', u'filesystem': {u'uuid': u'fd100bdb-b00e-42f5-83ca-3ad4dd9860b0', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'filesystem': None, u'name': u'sda', u'system_id': u'wh737w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/'}, {u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'7f0aa5ff-a714-4c77-b9f6-3facbd7804ec', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'9b1c847b-44d7-462a-a6b4-c939ce73c315', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'wh737w', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/13/'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'34f444e1-6f51-4708-aa9c-2e3c5c822111', u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wh737w', u'filesystem': {u'uuid': u'fd100bdb-b00e-42f5-83ca-3ad4dd9860b0', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'filesystem': None, u'name': u'sda', u'system_id': u'wh737w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/3/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'wh737w', u'id': 9}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 39}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}, 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': 6, u'resource_uri': u'/MAAS/api/2.0/subnets/6/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'wh737w', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/interfaces/6/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 40}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'system_id': u'wh737w', u'type': u'physical', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/interfaces/8/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 42}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'system_id': u'wh737w', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/interfaces/10/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 44}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'system_id': u'wh737w', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/interfaces/12/'}], u'current_testing_result_id': 7, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'7f0aa5ff-a714-4c77-b9f6-3facbd7804ec', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'9b1c847b-44d7-462a-a6b4-c939ce73c315', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'wh737w', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/wh737w/blockdevices/13/'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'current_commissioning_result_id': 6, u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/wh737w/'}
2019-11-06 20:16:09,930 [salt.state       :300 ][INFO    ][8790] {'new': {'storage_layout': 'lvm'}}
2019-11-06 20:16:09,930 [salt.state       :1951][INFO    ][8790] Completed state [maas_machines_storage_cmp001_lvm] at time 20:16:09.930704 duration_in_ms=2696.506
2019-11-06 20:16:09,935 [salt.minion      :1711][INFO    ][8790] Returning information for job: 20191106201559411563
2019-11-06 20:16:10,565 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106201610552967
2019-11-06 20:16:10,586 [salt.minion      :1432][INFO    ][8821] Starting a new job with PID 8821
2019-11-06 20:16:11,331 [salt.state       :915 ][INFO    ][8821] Loading fresh modules for state activity
2019-11-06 20:16:11,384 [salt.fileclient  :1219][INFO    ][8821] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-06 20:16:11,429 [salt.state       :1780][INFO    ][8821] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:11.429422
2019-11-06 20:16:11,429 [salt.state       :1813][INFO    ][8821] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:16:11,431 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8821] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:16:12,663 [salt.state       :300 ][INFO    ][8821] {'pid': 8828, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:16:12,663 [salt.state       :1951][INFO    ][8821] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:12.663471 duration_in_ms=1234.05
2019-11-06 20:16:12,664 [salt.state       :1780][INFO    ][8821] Running state [maas.deploy_machines] at time 20:16:12.664558
2019-11-06 20:16:12,664 [salt.state       :1813][INFO    ][8821] Executing state module.run for [maas.deploy_machines]
2019-11-06 20:16:12,665 [salt.utils.decorators:613 ][WARNING ][8821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:16:13,147 [salt.loaded.ext.module.maas:684 ][INFO    ][8821] deploymachines hwe_kernel=hwe-16.04 system_id=dmstyg distro_series=xenial
2019-11-06 20:16:15,563 [salt.loaded.ext.module.maas:684 ][INFO    ][8821] deploymachines hwe_kernel=hwe-16.04 system_id=gn3kwy distro_series=xenial
2019-11-06 20:16:18,370 [salt.loaded.ext.module.maas:684 ][INFO    ][8821] deploymachines hwe_kernel=hwe-16.04 system_id=wh737w distro_series=xenial
2019-11-06 20:16:20,617 [salt.loaded.ext.module.maas:684 ][INFO    ][8821] deploymachines hwe_kernel=hwe-16.04 system_id=pbntg8 distro_series=xenial
2019-11-06 20:16:23,188 [salt.state       :300 ][INFO    ][8821] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-11-06 20:16:23,188 [salt.state       :1951][INFO    ][8821] Completed state [maas.deploy_machines] at time 20:16:23.188649 duration_in_ms=10524.089
2019-11-06 20:16:23,195 [salt.minion      :1711][INFO    ][8821] Returning information for job: 20191106201610552967
2019-11-06 20:16:23,764 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106201623752056
2019-11-06 20:16:23,785 [salt.minion      :1432][INFO    ][9067] Starting a new job with PID 9067
2019-11-06 20:16:27,374 [salt.state       :915 ][INFO    ][9067] Loading fresh modules for state activity
2019-11-06 20:16:27,427 [salt.fileclient  :1219][INFO    ][9067] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-06 20:16:27,471 [salt.state       :1780][INFO    ][9067] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:27.471204
2019-11-06 20:16:27,471 [salt.state       :1813][INFO    ][9067] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:16:27,473 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9067] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:16:28,899 [salt.state       :300 ][INFO    ][9067] {'pid': 9079, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:16:28,900 [salt.state       :1951][INFO    ][9067] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:16:28.900085 duration_in_ms=1428.883
2019-11-06 20:16:28,901 [salt.state       :1780][INFO    ][9067] Running state [maas.wait_for_machine_status] at time 20:16:28.901264
2019-11-06 20:16:28,901 [salt.state       :1813][INFO    ][9067] Executing state module.run for [maas.wait_for_machine_status]
2019-11-06 20:16:28,901 [salt.utils.decorators:613 ][WARNING ][9067] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:16:31,345 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2247.56140399s left)
2019-11-06 20:16:38,887 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201638872821
2019-11-06 20:16:38,911 [salt.minion      :1432][INFO    ][9092] Starting a new job with PID 9092
2019-11-06 20:16:38,934 [salt.minion      :1711][INFO    ][9092] Returning information for job: 20191106201638872821
2019-11-06 20:17:03,625 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2215.28167701s left)
2019-11-06 20:17:08,937 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201708921815
2019-11-06 20:17:08,959 [salt.minion      :1432][INFO    ][9130] Starting a new job with PID 9130
2019-11-06 20:17:08,982 [salt.minion      :1711][INFO    ][9130] Returning information for job: 20191106201708921815
2019-11-06 20:17:35,984 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2182.92268205s left)
2019-11-06 20:17:39,052 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201739036578
2019-11-06 20:17:39,075 [salt.minion      :1432][INFO    ][9162] Starting a new job with PID 9162
2019-11-06 20:17:39,097 [salt.minion      :1711][INFO    ][9162] Returning information for job: 20191106201739036578
2019-11-06 20:18:08,145 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2150.7611711s left)
2019-11-06 20:18:09,097 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201809086626
2019-11-06 20:18:09,115 [salt.minion      :1432][INFO    ][9284] Starting a new job with PID 9284
2019-11-06 20:18:09,127 [salt.minion      :1711][INFO    ][9284] Returning information for job: 20191106201809086626
2019-11-06 20:18:39,127 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201839114661
2019-11-06 20:18:39,149 [salt.minion      :1432][INFO    ][9434] Starting a new job with PID 9434
2019-11-06 20:18:39,174 [salt.minion      :1711][INFO    ][9434] Returning information for job: 20191106201839114661
2019-11-06 20:18:40,633 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2118.273242s left)
2019-11-06 20:19:09,189 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201909175018
2019-11-06 20:19:09,211 [salt.minion      :1432][INFO    ][9940] Starting a new job with PID 9940
2019-11-06 20:19:09,232 [salt.minion      :1711][INFO    ][9940] Returning information for job: 20191106201909175018
2019-11-06 20:19:12,873 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2086.03296494s left)
2019-11-06 20:19:39,246 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106201939232986
2019-11-06 20:19:39,269 [salt.minion      :1432][INFO    ][10091] Starting a new job with PID 10091
2019-11-06 20:19:39,293 [salt.minion      :1711][INFO    ][10091] Returning information for job: 20191106201939232986
2019-11-06 20:19:45,377 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2053.52952909s left)
2019-11-06 20:20:09,308 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202009295145
2019-11-06 20:20:09,330 [salt.minion      :1432][INFO    ][10210] Starting a new job with PID 10210
2019-11-06 20:20:09,354 [salt.minion      :1711][INFO    ][10210] Returning information for job: 20191106202009295145
2019-11-06 20:20:17,774 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2021.13277912s left)
2019-11-06 20:20:39,368 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202039356416
2019-11-06 20:20:39,391 [salt.minion      :1432][INFO    ][10280] Starting a new job with PID 10280
2019-11-06 20:20:39,416 [salt.minion      :1711][INFO    ][10280] Returning information for job: 20191106202039356416
2019-11-06 20:20:50,174 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1988.73210096s left)
2019-11-06 20:21:09,453 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202109437582
2019-11-06 20:21:09,476 [salt.minion      :1432][INFO    ][10632] Starting a new job with PID 10632
2019-11-06 20:21:09,499 [salt.minion      :1711][INFO    ][10632] Returning information for job: 20191106202109437582
2019-11-06 20:21:22,505 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1956.40094113s left)
2019-11-06 20:21:39,528 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202139516422
2019-11-06 20:21:39,551 [salt.minion      :1432][INFO    ][10714] Starting a new job with PID 10714
2019-11-06 20:21:39,575 [salt.minion      :1711][INFO    ][10714] Returning information for job: 20191106202139516422
2019-11-06 20:21:55,012 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1923.89435506s left)
2019-11-06 20:22:09,611 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202209598753
2019-11-06 20:22:09,634 [salt.minion      :1432][INFO    ][10991] Starting a new job with PID 10991
2019-11-06 20:22:09,658 [salt.minion      :1711][INFO    ][10991] Returning information for job: 20191106202209598753
2019-11-06 20:22:27,393 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1891.51328397s left)
2019-11-06 20:22:39,693 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202239681207
2019-11-06 20:22:39,712 [salt.minion      :1432][INFO    ][11081] Starting a new job with PID 11081
2019-11-06 20:22:39,734 [salt.minion      :1711][INFO    ][11081] Returning information for job: 20191106202239681207
2019-11-06 20:22:59,808 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1859.09845495s left)
2019-11-06 20:23:09,775 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202309761564
2019-11-06 20:23:09,798 [salt.minion      :1432][INFO    ][11122] Starting a new job with PID 11122
2019-11-06 20:23:09,822 [salt.minion      :1711][INFO    ][11122] Returning information for job: 20191106202309761564
2019-11-06 20:23:32,197 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1826.70941901s left)
2019-11-06 20:23:39,889 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202339873059
2019-11-06 20:23:39,912 [salt.minion      :1432][INFO    ][11246] Starting a new job with PID 11246
2019-11-06 20:23:39,937 [salt.minion      :1711][INFO    ][11246] Returning information for job: 20191106202339873059
2019-11-06 20:24:04,438 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1794.46850395s left)
2019-11-06 20:24:09,960 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202409947359
2019-11-06 20:24:09,982 [salt.minion      :1432][INFO    ][11503] Starting a new job with PID 11503
2019-11-06 20:24:10,006 [salt.minion      :1711][INFO    ][11503] Returning information for job: 20191106202409947359
2019-11-06 20:24:36,875 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1762.03183699s left)
2019-11-06 20:24:40,074 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202440062021
2019-11-06 20:24:40,096 [salt.minion      :1432][INFO    ][11557] Starting a new job with PID 11557
2019-11-06 20:24:40,121 [salt.minion      :1711][INFO    ][11557] Returning information for job: 20191106202440062021
2019-11-06 20:25:09,397 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1729.50979996s left)
2019-11-06 20:25:10,192 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202510180101
2019-11-06 20:25:10,215 [salt.minion      :1432][INFO    ][11756] Starting a new job with PID 11756
2019-11-06 20:25:10,239 [salt.minion      :1711][INFO    ][11756] Returning information for job: 20191106202510180101
2019-11-06 20:25:40,309 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202540297034
2019-11-06 20:25:40,331 [salt.minion      :1432][INFO    ][11788] Starting a new job with PID 11788
2019-11-06 20:25:40,354 [salt.minion      :1711][INFO    ][11788] Returning information for job: 20191106202540297034
2019-11-06 20:25:41,839 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1697.06702495s left)
2019-11-06 20:26:10,434 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202610421834
2019-11-06 20:26:10,457 [salt.minion      :1432][INFO    ][11825] Starting a new job with PID 11825
2019-11-06 20:26:10,481 [salt.minion      :1711][INFO    ][11825] Returning information for job: 20191106202610421834
2019-11-06 20:26:14,211 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1664.69574213s left)
2019-11-06 20:26:40,568 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202640556399
2019-11-06 20:26:40,590 [salt.minion      :1432][INFO    ][11857] Starting a new job with PID 11857
2019-11-06 20:26:40,615 [salt.minion      :1711][INFO    ][11857] Returning information for job: 20191106202640556399
2019-11-06 20:26:46,456 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1632.45005512s left)
2019-11-06 20:27:10,720 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202710706568
2019-11-06 20:27:10,743 [salt.minion      :1432][INFO    ][11895] Starting a new job with PID 11895
2019-11-06 20:27:10,768 [salt.minion      :1711][INFO    ][11895] Returning information for job: 20191106202710706568
2019-11-06 20:27:19,037 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1599.86900711s left)
2019-11-06 20:27:40,872 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202740859991
2019-11-06 20:27:40,894 [salt.minion      :1432][INFO    ][11931] Starting a new job with PID 11931
2019-11-06 20:27:40,917 [salt.minion      :1711][INFO    ][11931] Returning information for job: 20191106202740859991
2019-11-06 20:27:51,343 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1567.56352615s left)
2019-11-06 20:28:11,026 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202811014114
2019-11-06 20:28:11,048 [salt.minion      :1432][INFO    ][11976] Starting a new job with PID 11976
2019-11-06 20:28:11,073 [salt.minion      :1711][INFO    ][11976] Returning information for job: 20191106202811014114
2019-11-06 20:28:23,786 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1535.11993194s left)
2019-11-06 20:28:41,195 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202841181957
2019-11-06 20:28:41,217 [salt.minion      :1432][INFO    ][12014] Starting a new job with PID 12014
2019-11-06 20:28:41,241 [salt.minion      :1711][INFO    ][12014] Returning information for job: 20191106202841181957
2019-11-06 20:28:56,146 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1502.76020002s left)
2019-11-06 20:29:11,374 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202911361481
2019-11-06 20:29:11,397 [salt.minion      :1432][INFO    ][12054] Starting a new job with PID 12054
2019-11-06 20:29:11,422 [salt.minion      :1711][INFO    ][12054] Returning information for job: 20191106202911361481
2019-11-06 20:29:28,686 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1470.220438s left)
2019-11-06 20:29:41,563 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106202941550910
2019-11-06 20:29:41,586 [salt.minion      :1432][INFO    ][12090] Starting a new job with PID 12090
2019-11-06 20:29:41,610 [salt.minion      :1711][INFO    ][12090] Returning information for job: 20191106202941550910
2019-11-06 20:30:00,756 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1438.15075898s left)
2019-11-06 20:30:11,760 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203011748361
2019-11-06 20:30:11,783 [salt.minion      :1432][INFO    ][12280] Starting a new job with PID 12280
2019-11-06 20:30:11,808 [salt.minion      :1711][INFO    ][12280] Returning information for job: 20191106203011748361
2019-11-06 20:30:33,228 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1405.67816401s left)
2019-11-06 20:30:41,975 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203041961941
2019-11-06 20:30:41,997 [salt.minion      :1432][INFO    ][12318] Starting a new job with PID 12318
2019-11-06 20:30:42,021 [salt.minion      :1711][INFO    ][12318] Returning information for job: 20191106203041961941
2019-11-06 20:31:05,516 [salt.loaded.ext.module.maas:1023][INFO    ][9067] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1373.39022398s left)
2019-11-06 20:31:12,190 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203112177912
2019-11-06 20:31:12,207 [salt.minion      :1432][INFO    ][12362] Starting a new job with PID 12362
2019-11-06 20:31:12,230 [salt.minion      :1711][INFO    ][12362] Returning information for job: 20191106203112177912
2019-11-06 20:31:36,248 [salt.loaded.ext.module.maas:993 ][INFO    ][9067] Machine dmstyg mark broken
2019-11-06 20:31:37,054 [salt.loaded.ext.module.maas:996 ][INFO    ][9067] Machine dmstyg mark fixed
2019-11-06 20:31:37,875 [salt.loaded.ext.module.maas:684 ][INFO    ][9067] deploymachines hwe_kernel=hwe-16.04 system_id=dmstyg distro_series=xenial
2019-11-06 20:31:40,614 [salt.loaded.ext.module.maas:160 ][ERROR   ][9067] Failed for object gtw01 reason Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node.
2019-11-06 20:31:40,616 [salt.state       :302 ][ERROR   ][9067] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'ctl01'], 'errors': {'gtw01': "Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node."}, 'success': []}
2019-11-06 20:31:40,616 [salt.state       :1951][INFO    ][9067] Completed state [maas.wait_for_machine_status] at time 20:31:40.616492 duration_in_ms=911715.207
2019-11-06 20:31:40,622 [salt.minion      :1711][INFO    ][9067] Returning information for job: 20191106201623752056
2019-11-06 20:31:51,426 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command pillar.get with jid 20191106203151413675
2019-11-06 20:31:51,448 [salt.minion      :1432][INFO    ][12482] Starting a new job with PID 12482
2019-11-06 20:31:51,456 [salt.minion      :1711][INFO    ][12482] Returning information for job: 20191106203151413675
2019-11-06 20:31:51,964 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command service.status with jid 20191106203151951475
2019-11-06 20:31:51,985 [salt.minion      :1432][INFO    ][12487] Starting a new job with PID 12487
2019-11-06 20:31:52,373 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12487] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-06 20:31:52,407 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12487] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-06 20:31:52,423 [salt.minion      :1711][INFO    ][12487] Returning information for job: 20191106203151951475
2019-11-06 20:31:52,968 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106203152956081
2019-11-06 20:31:52,987 [salt.minion      :1432][INFO    ][12501] Starting a new job with PID 12501
2019-11-06 20:31:56,408 [salt.state       :915 ][INFO    ][12501] Loading fresh modules for state activity
2019-11-06 20:31:56,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'salt-minion --version' in directory '/root'
2019-11-06 20:31:57,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'salt-minion --version' in directory '/root'
2019-11-06 20:31:57,938 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'salt-minion --version' in directory '/root'
2019-11-06 20:31:58,301 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'salt-minion --version' in directory '/root'
2019-11-06 20:31:59,658 [salt.state       :1780][INFO    ][12501] Running state [salt-minion] at time 20:31:59.658297
2019-11-06 20:31:59,658 [salt.state       :1813][INFO    ][12501] Executing state pkg.installed for [salt-minion]
2019-11-06 20:31:59,659 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-06 20:31:59,750 [salt.state       :300 ][INFO    ][12501] All specified packages are already installed
2019-11-06 20:31:59,751 [salt.state       :1951][INFO    ][12501] Completed state [salt-minion] at time 20:31:59.750937 duration_in_ms=92.639
2019-11-06 20:31:59,751 [salt.state       :1780][INFO    ][12501] Running state [salt_minion_dependency_packages] at time 20:31:59.751270
2019-11-06 20:31:59,751 [salt.state       :1813][INFO    ][12501] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-06 20:31:59,758 [salt.state       :300 ][INFO    ][12501] All specified packages are already installed
2019-11-06 20:31:59,758 [salt.state       :1951][INFO    ][12501] Completed state [salt_minion_dependency_packages] at time 20:31:59.758397 duration_in_ms=7.127
2019-11-06 20:31:59,761 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/minion.d/minion.conf] at time 20:31:59.761563
2019-11-06 20:31:59,761 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-06 20:31:59,957 [salt.state       :300 ][INFO    ][12501] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-06 20:31:59,957 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/minion.d/minion.conf] at time 20:31:59.957855 duration_in_ms=196.292
2019-11-06 20:31:59,959 [salt.state       :1780][INFO    ][12501] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:31:59.959893
2019-11-06 20:31:59,960 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-06 20:31:59,969 [salt.state       :300 ][INFO    ][12501] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-06 20:31:59,969 [salt.state       :1951][INFO    ][12501] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:31:59.969868 duration_in_ms=9.975
2019-11-06 20:31:59,970 [salt.state       :1780][INFO    ][12501] Running state [salt-minion] at time 20:31:59.970482
2019-11-06 20:31:59,970 [salt.state       :1813][INFO    ][12501] Executing state service.running for [salt-minion]
2019-11-06 20:31:59,971 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:00,006 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-06 20:32:00,023 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-06 20:32:00,039 [salt.state       :300 ][INFO    ][12501] The service salt-minion is already running
2019-11-06 20:32:00,039 [salt.state       :1951][INFO    ][12501] Completed state [salt-minion] at time 20:32:00.039563 duration_in_ms=69.081
2019-11-06 20:32:00,040 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains.d] at time 20:32:00.040874
2019-11-06 20:32:00,041 [salt.state       :1813][INFO    ][12501] Executing state file.directory for [/etc/salt/grains.d]
2019-11-06 20:32:00,042 [salt.state       :300 ][INFO    ][12501] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-06 20:32:00,042 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains.d] at time 20:32:00.042197 duration_in_ms=1.324
2019-11-06 20:32:00,042 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains] at time 20:32:00.042782
2019-11-06 20:32:00,043 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/grains]
2019-11-06 20:32:00,043 [salt.state       :300 ][INFO    ][12501] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-06 20:32:00,043 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains] at time 20:32:00.043717 duration_in_ms=0.935
2019-11-06 20:32:00,044 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains.d/placeholder] at time 20:32:00.044105
2019-11-06 20:32:00,044 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-06 20:32:00,044 [salt.state       :300 ][INFO    ][12501] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-06 20:32:00,045 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains.d/placeholder] at time 20:32:00.045008 duration_in_ms=0.903
2019-11-06 20:32:00,045 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains.d/sphinx] at time 20:32:00.045395
2019-11-06 20:32:00,045 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-06 20:32:00,053 [salt.state       :300 ][INFO    ][12501] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-06 20:32:00,053 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains.d/sphinx] at time 20:32:00.053534 duration_in_ms=8.139
2019-11-06 20:32:00,055 [salt.state       :1780][INFO    ][12501] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.055403
2019-11-06 20:32:00,055 [salt.state       :1813][INFO    ][12501] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-06 20:32:00,055 [salt.state       :300 ][INFO    ][12501] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-06 20:32:00,056 [salt.state       :1951][INFO    ][12501] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.056138 duration_in_ms=0.736
2019-11-06 20:32:00,056 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains.d/dns_records] at time 20:32:00.056530
2019-11-06 20:32:00,056 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-06 20:32:00,065 [salt.state       :300 ][INFO    ][12501] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-06 20:32:00,065 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains.d/dns_records] at time 20:32:00.065387 duration_in_ms=8.856
2019-11-06 20:32:00,066 [salt.state       :1780][INFO    ][12501] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.066146
2019-11-06 20:32:00,066 [salt.state       :1813][INFO    ][12501] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-06 20:32:00,066 [salt.state       :300 ][INFO    ][12501] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-06 20:32:00,066 [salt.state       :1951][INFO    ][12501] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.066852 duration_in_ms=0.706
2019-11-06 20:32:00,067 [salt.state       :1780][INFO    ][12501] Running state [/etc/salt/grains.d/salt] at time 20:32:00.067224
2019-11-06 20:32:00,067 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-06 20:32:00,077 [salt.state       :300 ][INFO    ][12501] File /etc/salt/grains.d/salt is in the correct state
2019-11-06 20:32:00,077 [salt.state       :1951][INFO    ][12501] Completed state [/etc/salt/grains.d/salt] at time 20:32:00.077524 duration_in_ms=10.3
2019-11-06 20:32:00,078 [salt.state       :1780][INFO    ][12501] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.078217
2019-11-06 20:32:00,078 [salt.state       :1813][INFO    ][12501] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-06 20:32:00,078 [salt.state       :300 ][INFO    ][12501] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-06 20:32:00,078 [salt.state       :1951][INFO    ][12501] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:32:00.078927 duration_in_ms=0.71
2019-11-06 20:32:00,080 [salt.state       :1780][INFO    ][12501] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:32:00.080412
2019-11-06 20:32:00,080 [salt.state       :1813][INFO    ][12501] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-06 20:32:00,080 [salt.state       :300 ][INFO    ][12501] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-06 20:32:00,081 [salt.state       :1951][INFO    ][12501] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:32:00.081137 duration_in_ms=0.725
2019-11-06 20:32:00,081 [salt.state       :1780][INFO    ][12501] Running state [mine.update] at time 20:32:00.081686
2019-11-06 20:32:00,081 [salt.state       :1813][INFO    ][12501] Executing state module.wait for [mine.update]
2019-11-06 20:32:00,082 [salt.state       :300 ][INFO    ][12501] No changes made for mine.update
2019-11-06 20:32:00,082 [salt.state       :1951][INFO    ][12501] Completed state [mine.update] at time 20:32:00.082339 duration_in_ms=0.653
2019-11-06 20:32:00,082 [salt.state       :1780][INFO    ][12501] Running state [ca-certificates] at time 20:32:00.082561
2019-11-06 20:32:00,082 [salt.state       :1813][INFO    ][12501] Executing state pkg.installed for [ca-certificates]
2019-11-06 20:32:00,088 [salt.state       :300 ][INFO    ][12501] All specified packages are already installed
2019-11-06 20:32:00,088 [salt.state       :1951][INFO    ][12501] Completed state [ca-certificates] at time 20:32:00.088934 duration_in_ms=6.373
2019-11-06 20:32:00,089 [salt.state       :1780][INFO    ][12501] Running state [update-ca-certificates] at time 20:32:00.089749
2019-11-06 20:32:00,090 [salt.state       :1813][INFO    ][12501] Executing state cmd.wait for [update-ca-certificates]
2019-11-06 20:32:00,090 [salt.state       :300 ][INFO    ][12501] No changes made for update-ca-certificates
2019-11-06 20:32:00,090 [salt.state       :1951][INFO    ][12501] Completed state [update-ca-certificates] at time 20:32:00.090417 duration_in_ms=0.668
2019-11-06 20:32:00,090 [salt.state       :1780][INFO    ][12501] Running state [iptables] at time 20:32:00.090642
2019-11-06 20:32:00,090 [salt.state       :1813][INFO    ][12501] Executing state pkg.installed for [iptables]
2019-11-06 20:32:00,096 [salt.state       :300 ][INFO    ][12501] All specified packages are already installed
2019-11-06 20:32:00,096 [salt.state       :1951][INFO    ][12501] Completed state [iptables] at time 20:32:00.096216 duration_in_ms=5.574
2019-11-06 20:32:00,096 [salt.state       :1780][INFO    ][12501] Running state [iptables-persistent] at time 20:32:00.096416
2019-11-06 20:32:00,096 [salt.state       :1813][INFO    ][12501] Executing state pkg.installed for [iptables-persistent]
2019-11-06 20:32:00,101 [salt.state       :300 ][INFO    ][12501] All specified packages are already installed
2019-11-06 20:32:00,102 [salt.state       :1951][INFO    ][12501] Completed state [iptables-persistent] at time 20:32:00.102074 duration_in_ms=5.658
2019-11-06 20:32:00,102 [salt.state       :1780][INFO    ][12501] Running state [iptables_modules_v4_load] at time 20:32:00.102855
2019-11-06 20:32:00,103 [salt.state       :1813][INFO    ][12501] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-06 20:32:00,103 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'lsmod' in directory '/root'
2019-11-06 20:32:00,126 [salt.state       :300 ][INFO    ][12501] Kernel modules iptable_filter, ip_tables are already present
2019-11-06 20:32:00,126 [salt.state       :1951][INFO    ][12501] Completed state [iptables_modules_v4_load] at time 20:32:00.126289 duration_in_ms=23.434
2019-11-06 20:32:00,126 [salt.state       :1780][INFO    ][12501] Running state [/etc/iptables/rules.v4] at time 20:32:00.126796
2019-11-06 20:32:00,127 [salt.state       :1813][INFO    ][12501] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-06 20:32:00,203 [salt.state       :300 ][INFO    ][12501] File /etc/iptables/rules.v4 is in the correct state
2019-11-06 20:32:00,203 [salt.state       :1951][INFO    ][12501] Completed state [/etc/iptables/rules.v4] at time 20:32:00.203358 duration_in_ms=76.563
2019-11-06 20:32:00,204 [salt.state       :1780][INFO    ][12501] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:32:00.204114
2019-11-06 20:32:00,204 [salt.state       :1813][INFO    ][12501] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-06 20:32:00,204 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-06 20:32:00,222 [salt.state       :300 ][INFO    ][12501] onlyif execution failed
2019-11-06 20:32:00,222 [salt.state       :1951][INFO    ][12501] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:32:00.222458 duration_in_ms=18.345
2019-11-06 20:32:00,223 [salt.state       :1780][INFO    ][12501] Running state [netfilter-persistent] at time 20:32:00.223165
2019-11-06 20:32:00,223 [salt.state       :1813][INFO    ][12501] Executing state service.running for [netfilter-persistent]
2019-11-06 20:32:00,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:00,241 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-06 20:32:00,257 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-06 20:32:00,273 [salt.state       :300 ][INFO    ][12501] The service netfilter-persistent is already running
2019-11-06 20:32:00,274 [salt.state       :1951][INFO    ][12501] Completed state [netfilter-persistent] at time 20:32:00.274060 duration_in_ms=50.895
2019-11-06 20:32:00,274 [salt.state       :1780][INFO    ][12501] Running state [iptables_extra.remove_stale_tables] at time 20:32:00.274688
2019-11-06 20:32:00,274 [salt.state       :1813][INFO    ][12501] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-06 20:32:00,275 [salt.state       :300 ][INFO    ][12501] No changes made for iptables_extra.remove_stale_tables
2019-11-06 20:32:00,275 [salt.state       :1951][INFO    ][12501] Completed state [iptables_extra.remove_stale_tables] at time 20:32:00.275411 duration_in_ms=0.723
2019-11-06 20:32:00,275 [salt.state       :1780][INFO    ][12501] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:32:00.275633
2019-11-06 20:32:00,275 [salt.state       :1813][INFO    ][12501] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-06 20:32:00,276 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12501] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-06 20:32:00,289 [salt.state       :300 ][INFO    ][12501] onlyif execution failed
2019-11-06 20:32:00,290 [salt.state       :1951][INFO    ][12501] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:32:00.290084 duration_in_ms=14.451
2019-11-06 20:32:00,290 [salt.state       :1780][INFO    ][12501] Running state [/etc/iptables/rules.v6] at time 20:32:00.290834
2019-11-06 20:32:00,291 [salt.state       :1813][INFO    ][12501] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-06 20:32:00,291 [salt.state       :300 ][INFO    ][12501] File /etc/iptables/rules.v6 is not present
2019-11-06 20:32:00,291 [salt.state       :1951][INFO    ][12501] Completed state [/etc/iptables/rules.v6] at time 20:32:00.291671 duration_in_ms=0.837
2019-11-06 20:32:00,292 [salt.state       :1780][INFO    ][12501] Running state [iptables_extra.flush_all] at time 20:32:00.292188
2019-11-06 20:32:00,292 [salt.state       :1813][INFO    ][12501] Executing state module.wait for [iptables_extra.flush_all]
2019-11-06 20:32:00,292 [salt.state       :300 ][INFO    ][12501] No changes made for iptables_extra.flush_all
2019-11-06 20:32:00,292 [salt.state       :1951][INFO    ][12501] Completed state [iptables_extra.flush_all] at time 20:32:00.292847 duration_in_ms=0.659
2019-11-06 20:32:00,304 [salt.minion      :1711][INFO    ][12501] Returning information for job: 20191106203152956081
2019-11-06 20:32:00,935 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106203200922900
2019-11-06 20:32:00,957 [salt.minion      :1432][INFO    ][12586] Starting a new job with PID 12586
2019-11-06 20:32:01,701 [salt.state       :915 ][INFO    ][12586] Loading fresh modules for state activity
2019-11-06 20:32:02,347 [salt.state       :1780][INFO    ][12586] Running state [maas-rack-controller] at time 20:32:02.347268
2019-11-06 20:32:02,347 [salt.state       :1813][INFO    ][12586] Executing state pkg.installed for [maas-rack-controller]
2019-11-06 20:32:02,348 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12586] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-06 20:32:02,453 [salt.state       :300 ][INFO    ][12586] All specified packages are already installed
2019-11-06 20:32:02,453 [salt.state       :1951][INFO    ][12586] Completed state [maas-rack-controller] at time 20:32:02.453653 duration_in_ms=106.385
2019-11-06 20:32:02,454 [salt.state       :1780][INFO    ][12586] Running state [ipmitool] at time 20:32:02.454073
2019-11-06 20:32:02,454 [salt.state       :1813][INFO    ][12586] Executing state pkg.installed for [ipmitool]
2019-11-06 20:32:02,462 [salt.state       :300 ][INFO    ][12586] All specified packages are already installed
2019-11-06 20:32:02,462 [salt.state       :1951][INFO    ][12586] Completed state [ipmitool] at time 20:32:02.462780 duration_in_ms=8.706
2019-11-06 20:32:02,466 [salt.state       :1780][INFO    ][12586] Running state [/etc/maas/rackd.conf] at time 20:32:02.466623
2019-11-06 20:32:02,466 [salt.state       :1813][INFO    ][12586] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-06 20:32:02,468 [salt.state       :300 ][INFO    ][12586] No changes needed to be made
2019-11-06 20:32:02,468 [salt.state       :1951][INFO    ][12586] Completed state [/etc/maas/rackd.conf] at time 20:32:02.468462 duration_in_ms=1.838
2019-11-06 20:32:02,468 [salt.state       :1780][INFO    ][12586] Running state [/etc/maas/rackd.conf] at time 20:32:02.468760
2019-11-06 20:32:02,469 [salt.state       :1813][INFO    ][12586] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-06 20:32:02,469 [salt.loaded.int.states.file:2298][WARNING ][12586] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-11-06 20:32:02,470 [salt.state       :300 ][INFO    ][12586] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-06 20:32:02,470 [salt.state       :1951][INFO    ][12586] Completed state [/etc/maas/rackd.conf] at time 20:32:02.470663 duration_in_ms=1.903
2019-11-06 20:32:02,471 [salt.state       :1780][INFO    ][12586] Running state [maas-rackd] at time 20:32:02.471857
2019-11-06 20:32:02,472 [salt.state       :1813][INFO    ][12586] Executing state service.running for [maas-rackd]
2019-11-06 20:32:02,472 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12586] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:02,507 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12586] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-06 20:32:02,524 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12586] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-06 20:32:02,541 [salt.state       :300 ][INFO    ][12586] The service maas-rackd is already running
2019-11-06 20:32:02,541 [salt.state       :1951][INFO    ][12586] Completed state [maas-rackd] at time 20:32:02.541643 duration_in_ms=69.786
2019-11-06 20:32:02,543 [salt.minion      :1711][INFO    ][12586] Returning information for job: 20191106203200922900
2019-11-06 20:32:03,160 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106203203148293
2019-11-06 20:32:03,181 [salt.minion      :1432][INFO    ][12613] Starting a new job with PID 12613
2019-11-06 20:32:03,927 [salt.state       :915 ][INFO    ][12613] Loading fresh modules for state activity
2019-11-06 20:32:04,695 [salt.state       :1780][INFO    ][12613] Running state [maas-region-controller] at time 20:32:04.695131
2019-11-06 20:32:04,695 [salt.state       :1813][INFO    ][12613] Executing state pkg.installed for [maas-region-controller]
2019-11-06 20:32:04,695 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-06 20:32:04,780 [salt.state       :300 ][INFO    ][12613] All specified packages are already installed
2019-11-06 20:32:04,781 [salt.state       :1951][INFO    ][12613] Completed state [maas-region-controller] at time 20:32:04.781160 duration_in_ms=86.03
2019-11-06 20:32:04,781 [salt.state       :1780][INFO    ][12613] Running state [python-oauth] at time 20:32:04.781459
2019-11-06 20:32:04,781 [salt.state       :1813][INFO    ][12613] Executing state pkg.installed for [python-oauth]
2019-11-06 20:32:04,787 [salt.state       :300 ][INFO    ][12613] All specified packages are already installed
2019-11-06 20:32:04,787 [salt.state       :1951][INFO    ][12613] Completed state [python-oauth] at time 20:32:04.787778 duration_in_ms=6.319
2019-11-06 20:32:04,790 [salt.state       :1780][INFO    ][12613] Running state [/etc/maas/regiond.conf] at time 20:32:04.790598
2019-11-06 20:32:04,790 [salt.state       :1813][INFO    ][12613] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-06 20:32:04,818 [salt.state       :300 ][INFO    ][12613] No changes needed to be made
2019-11-06 20:32:04,819 [salt.state       :1951][INFO    ][12613] Completed state [/etc/maas/regiond.conf] at time 20:32:04.819055 duration_in_ms=28.456
2019-11-06 20:32:04,819 [salt.state       :1780][INFO    ][12613] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:32:04.819733
2019-11-06 20:32:04,820 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-06 20:32:04,903 [salt.state       :300 ][INFO    ][12613] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-06 20:32:04,904 [salt.state       :1951][INFO    ][12613] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:32:04.903972 duration_in_ms=84.237
2019-11-06 20:32:04,905 [salt.state       :1780][INFO    ][12613] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:32:04.905011
2019-11-06 20:32:04,905 [salt.state       :1813][INFO    ][12613] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-06 20:32:04,922 [salt.state       :300 ][INFO    ][12613] No changes needed to be made
2019-11-06 20:32:04,923 [salt.state       :1951][INFO    ][12613] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:32:04.922954 duration_in_ms=17.943
2019-11-06 20:32:04,923 [salt.state       :1780][INFO    ][12613] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:32:04.923672
2019-11-06 20:32:04,924 [salt.state       :1813][INFO    ][12613] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-06 20:32:04,988 [salt.state       :300 ][INFO    ][12613] No changes needed to be made
2019-11-06 20:32:04,989 [salt.state       :1951][INFO    ][12613] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:32:04.989144 duration_in_ms=65.471
2019-11-06 20:32:04,990 [salt.state       :1780][INFO    ][12613] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:32:04.989979
2019-11-06 20:32:04,990 [salt.state       :1813][INFO    ][12613] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-06 20:32:05,029 [salt.state       :300 ][INFO    ][12613] No changes needed to be made
2019-11-06 20:32:05,029 [salt.state       :1951][INFO    ][12613] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:32:05.029712 duration_in_ms=39.733
2019-11-06 20:32:05,030 [salt.state       :1780][INFO    ][12613] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:32:05.030374
2019-11-06 20:32:05,030 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-06 20:32:05,045 [salt.state       :300 ][INFO    ][12613] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-06 20:32:05,045 [salt.state       :1951][INFO    ][12613] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:32:05.045907 duration_in_ms=15.533
2019-11-06 20:32:05,048 [salt.state       :1780][INFO    ][12613] Running state [a2enmod headers] at time 20:32:05.048459
2019-11-06 20:32:05,048 [salt.state       :1813][INFO    ][12613] Executing state cmd.run for [a2enmod headers]
2019-11-06 20:32:05,049 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command 'a2enmod headers' in directory '/root'
2019-11-06 20:32:05,125 [salt.state       :300 ][INFO    ][12613] {'pid': 12632, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-06 20:32:05,126 [salt.state       :1951][INFO    ][12613] Completed state [a2enmod headers] at time 20:32:05.125974 duration_in_ms=77.513
2019-11-06 20:32:05,126 [salt.state       :1780][INFO    ][12613] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:32:05.126757
2019-11-06 20:32:05,127 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-06 20:32:05,147 [salt.state       :300 ][INFO    ][12613] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-06 20:32:05,148 [salt.state       :1951][INFO    ][12613] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:32:05.147923 duration_in_ms=21.166
2019-11-06 20:32:05,149 [salt.state       :1780][INFO    ][12613] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:32:05.149091
2019-11-06 20:32:05,149 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-06 20:32:05,231 [salt.state       :300 ][INFO    ][12613] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-06 20:32:05,232 [salt.state       :1951][INFO    ][12613] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:32:05.232402 duration_in_ms=83.309
2019-11-06 20:32:05,233 [salt.state       :1780][INFO    ][12613] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:32:05.233618
2019-11-06 20:32:05,234 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-06 20:32:05,309 [salt.state       :300 ][INFO    ][12613] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-06 20:32:05,310 [salt.state       :1951][INFO    ][12613] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:32:05.310166 duration_in_ms=76.547
2019-11-06 20:32:05,311 [salt.state       :1780][INFO    ][12613] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:32:05.311087
2019-11-06 20:32:05,311 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-06 20:32:05,381 [salt.state       :300 ][INFO    ][12613] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-06 20:32:05,382 [salt.state       :1951][INFO    ][12613] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:32:05.382096 duration_in_ms=71.008
2019-11-06 20:32:05,382 [salt.state       :1780][INFO    ][12613] Running state [/root/.pgpass] at time 20:32:05.382657
2019-11-06 20:32:05,383 [salt.state       :1813][INFO    ][12613] Executing state file.managed for [/root/.pgpass]
2019-11-06 20:32:05,435 [salt.state       :300 ][INFO    ][12613] File /root/.pgpass is in the correct state
2019-11-06 20:32:05,436 [salt.state       :1951][INFO    ][12613] Completed state [/root/.pgpass] at time 20:32:05.436083 duration_in_ms=53.427
2019-11-06 20:32:05,441 [salt.state       :1780][INFO    ][12613] Running state [maas-region syncdb --noinput] at time 20:32:05.441921
2019-11-06 20:32:05,442 [salt.state       :1813][INFO    ][12613] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-06 20:32:05,443 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-06 20:32:07,475 [salt.state       :300 ][INFO    ][12613] {'pid': 12645, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: auth, sessions, maasserver, metadataserver, contenttypes, piston3, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-06 20:32:07,476 [salt.state       :1951][INFO    ][12613] Completed state [maas-region syncdb --noinput] at time 20:32:07.476345 duration_in_ms=2034.422
2019-11-06 20:32:07,476 [salt.state       :2022][WARNING ][12613] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-06 20:32:07,479 [salt.state       :1780][INFO    ][12613] Running state [maas-regiond] at time 20:32:07.479459
2019-11-06 20:32:07,480 [salt.state       :1813][INFO    ][12613] Executing state service.running for [maas-regiond]
2019-11-06 20:32:07,481 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:07,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-06 20:32:07,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-06 20:32:07,556 [salt.state       :300 ][INFO    ][12613] The service maas-regiond is already running
2019-11-06 20:32:07,557 [salt.state       :1951][INFO    ][12613] Completed state [maas-regiond] at time 20:32:07.557335 duration_in_ms=77.876
2019-11-06 20:32:07,559 [salt.state       :1780][INFO    ][12613] Running state [bind9] at time 20:32:07.559876
2019-11-06 20:32:07,560 [salt.state       :1813][INFO    ][12613] Executing state service.running for [bind9]
2019-11-06 20:32:07,561 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:07,581 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-06 20:32:07,598 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-06 20:32:07,616 [salt.state       :300 ][INFO    ][12613] The service bind9 is already running
2019-11-06 20:32:07,616 [salt.state       :1951][INFO    ][12613] Completed state [bind9] at time 20:32:07.616693 duration_in_ms=56.817
2019-11-06 20:32:07,619 [salt.state       :1780][INFO    ][12613] Running state [apache2] at time 20:32:07.619052
2019-11-06 20:32:07,619 [salt.state       :1813][INFO    ][12613] Executing state service.running for [apache2]
2019-11-06 20:32:07,620 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-06 20:32:07,639 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-06 20:32:07,656 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-06 20:32:07,678 [salt.state       :300 ][INFO    ][12613] The service apache2 is already running
2019-11-06 20:32:07,679 [salt.state       :1951][INFO    ][12613] Completed state [apache2] at time 20:32:07.678897 duration_in_ms=59.844
2019-11-06 20:32:07,681 [salt.state       :1780][INFO    ][12613] Running state [maasng.wait_for_http_code] at time 20:32:07.680937
2019-11-06 20:32:07,681 [salt.state       :1813][INFO    ][12613] Executing state module.run for [maasng.wait_for_http_code]
2019-11-06 20:32:07,682 [salt.utils.decorators:613 ][WARNING ][12613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:07,692 [salt.state       :300 ][INFO    ][12613] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-06 20:32:07,692 [salt.state       :1951][INFO    ][12613] Completed state [maasng.wait_for_http_code] at time 20:32:07.692456 duration_in_ms=11.518
2019-11-06 20:32:07,693 [salt.state       :1780][INFO    ][12613] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:32:07.693883
2019-11-06 20:32:07,694 [salt.state       :1813][INFO    ][12613] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-06 20:32:07,695 [salt.state       :300 ][INFO    ][12613] /var/lib/maas/.setup_admin exists
2019-11-06 20:32:07,695 [salt.state       :1951][INFO    ][12613] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:32:07.695518 duration_in_ms=1.635
2019-11-06 20:32:07,696 [salt.state       :1780][INFO    ][12613] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:32:07.696703
2019-11-06 20:32:07,697 [salt.state       :1813][INFO    ][12613] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:32:07,698 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12613] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:32:09,154 [salt.state       :300 ][INFO    ][12613] {'pid': 12664, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:32:09,155 [salt.state       :1951][INFO    ][12613] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:32:09.155395 duration_in_ms=1458.691
2019-11-06 20:32:09,163 [salt.state       :1780][INFO    ][12613] Running state [maas_region_boot_source_resources_mirror] at time 20:32:09.163835
2019-11-06 20:32:09,164 [salt.state       :1813][INFO    ][12613] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-06 20:32:09,279 [salt.state       :300 ][INFO    ][12613] {'changes': {}}
2019-11-06 20:32:09,280 [salt.state       :1951][INFO    ][12613] Completed state [maas_region_boot_source_resources_mirror] at time 20:32:09.280148 duration_in_ms=116.311
2019-11-06 20:32:09,281 [salt.state       :1780][INFO    ][12613] Running state [maasng.boot_resources_import] at time 20:32:09.281519
2019-11-06 20:32:09,282 [salt.state       :1813][INFO    ][12613] Executing state module.run for [maasng.boot_resources_import]
2019-11-06 20:32:09,282 [salt.utils.decorators:613 ][WARNING ][12613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:09,387 [salt.loaded.ext.module.maasng:1600][INFO    ][12613] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-06 20:32:14,438 [salt.loaded.ext.module.maasng:1600][INFO    ][12613] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-06 20:32:18,194 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203218181312
2019-11-06 20:32:18,217 [salt.minion      :1432][INFO    ][12695] Starting a new job with PID 12695
2019-11-06 20:32:18,241 [salt.minion      :1711][INFO    ][12695] Returning information for job: 20191106203218181312
2019-11-06 20:32:19,504 [salt.loaded.ext.module.maasng:1600][INFO    ][12613] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-06 20:32:24,623 [salt.state       :300 ][INFO    ][12613] {'ret': True}
2019-11-06 20:32:24,624 [salt.state       :1951][INFO    ][12613] Completed state [maasng.boot_resources_import] at time 20:32:24.623953 duration_in_ms=15342.434
2019-11-06 20:32:24,625 [salt.state       :1780][INFO    ][12613] Running state [maas_region_boot_sources_selection_xenial] at time 20:32:24.624959
2019-11-06 20:32:24,625 [salt.state       :1813][INFO    ][12613] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-11-06 20:32:24,838 [salt.state       :300 ][INFO    ][12613] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-06 20:32:24,839 [salt.state       :1951][INFO    ][12613] Completed state [maas_region_boot_sources_selection_xenial] at time 20:32:24.839052 duration_in_ms=214.092
2019-11-06 20:32:24,840 [salt.state       :1780][INFO    ][12613] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:32:24.840284
2019-11-06 20:32:24,840 [salt.state       :1813][INFO    ][12613] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-06 20:32:24,841 [salt.utils.decorators:613 ][WARNING ][12613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:24,841 [salt.loaded.ext.module.maasng:1771][INFO    ][12613] boot-sources sync initiated for ALL Rack's
2019-11-06 20:32:26,024 [salt.state       :300 ][INFO    ][12613] {'ret': True}
2019-11-06 20:32:26,024 [salt.state       :1951][INFO    ][12613] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:32:26.024648 duration_in_ms=1184.363
2019-11-06 20:32:26,026 [salt.state       :1780][INFO    ][12613] Running state [maas.process_maas_config] at time 20:32:26.026685
2019-11-06 20:32:26,027 [salt.state       :1813][INFO    ][12613] Executing state module.run for [maas.process_maas_config]
2019-11-06 20:32:26,027 [salt.utils.decorators:613 ][WARNING ][12613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:26,028 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=enable_http_proxy value=True
2019-11-06 20:32:26,091 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=upstream_dns value=8.8.8.8
2019-11-06 20:32:26,156 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=commissioning_distro_series value=xenial
2019-11-06 20:32:26,222 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=default_osystem value=ubuntu
2019-11-06 20:32:26,282 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=active_discovery_interval value=600
2019-11-06 20:32:29,189 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=dnssec_validation value=no
2019-11-06 20:32:29,236 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=maas_name value=mas01
2019-11-06 20:32:29,296 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=network_discovery value=enabled
2019-11-06 20:32:29,416 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=enable_third_party_drivers value=True
2019-11-06 20:32:29,470 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=default_storage_layout value=lvm
2019-11-06 20:32:29,540 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=ntp_external_only value=True
2019-11-06 20:32:29,597 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-06 20:32:29,653 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=default_distro_series value=xenial
2019-11-06 20:32:29,719 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-11-06 20:32:29,845 [salt.state       :300 ][INFO    ][12613] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-11-06 20:32:29,845 [salt.state       :1951][INFO    ][12613] Completed state [maas.process_maas_config] at time 20:32:29.845907 duration_in_ms=3819.221
2019-11-06 20:32:29,846 [salt.state       :1780][INFO    ][12613] Running state [pxe_admin] at time 20:32:29.846819
2019-11-06 20:32:29,847 [salt.state       :1813][INFO    ][12613] Executing state maasng.fabric_present for [pxe_admin]
2019-11-06 20:32:29,923 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'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'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'id': 3, u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'id': 4, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/'}]
2019-11-06 20:32:30,002 [salt.loaded.ext.module.maasng:1008][WARNING ][12613] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-06 20:32:30,002 [salt.loaded.ext.module.maasng:1011][WARNING ][12613] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-06 20:32:30,067 [salt.state       :300 ][INFO    ][12613] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-06 20:32:30,067 [salt.state       :1951][INFO    ][12613] Completed state [pxe_admin] at time 20:32:30.067635 duration_in_ms=220.816
2019-11-06 20:32:30,068 [salt.state       :1780][INFO    ][12613] Running state [vlan 0] at time 20:32:30.068114
2019-11-06 20:32:30,068 [salt.state       :1813][INFO    ][12613] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-06 20:32:30,120 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}]
2019-11-06 20:32:30,247 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}]
2019-11-06 20:32:30,524 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'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'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'id': 3, u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'id': 4, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/'}]
2019-11-06 20:32:30,617 [salt.state       :300 ][INFO    ][12613] {'new': 'Vlan untagged was updated'}
2019-11-06 20:32:30,618 [salt.state       :1951][INFO    ][12613] Completed state [vlan 0] at time 20:32:30.618220 duration_in_ms=550.106
2019-11-06 20:32:30,619 [salt.state       :1780][INFO    ][12613] Running state [192.168.11.0/24] at time 20:32:30.619758
2019-11-06 20:32:30,620 [salt.state       :1813][INFO    ][12613] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-06 20:32:30,896 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'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'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'id': 3, u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'id': 4, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/'}]
2019-11-06 20:32:30,897 [salt.loaded.ext.module.maasng:1235][WARNING ][12613] Ignoring parameter vlan:0
2019-11-06 20:32:30,973 [salt.state       :300 ][INFO    ][12613] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-06 20:32:30,973 [salt.state       :1951][INFO    ][12613] Completed state [192.168.11.0/24] at time 20:32:30.973652 duration_in_ms=353.894
2019-11-06 20:32:30,974 [salt.state       :1780][INFO    ][12613] Running state [maas_create_iprange_1] at time 20:32:30.974887
2019-11-06 20:32:30,975 [salt.state       :1813][INFO    ][12613] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-06 20:32:31,026 [salt.state       :300 ][INFO    ][12613] Iprange maas_create_iprange_1 already exist.
2019-11-06 20:32:31,027 [salt.state       :1951][INFO    ][12613] Completed state [maas_create_iprange_1] at time 20:32:31.027103 duration_in_ms=52.216
2019-11-06 20:32:31,027 [salt.state       :1780][INFO    ][12613] Running state [vlan 0] at time 20:32:31.027506
2019-11-06 20:32:31,027 [salt.state       :1813][INFO    ][12613] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-06 20:32:31,086 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'primary_rack': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'id': 3, u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ymfw3c', u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'id': 4, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/'}]
2019-11-06 20:32:31,186 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 3, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'primary_rack': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'class_type': None, u'name': u'fabric-3', u'id': 3}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ymfw3c', u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 4}]
2019-11-06 20:32:31,437 [salt.loaded.ext.module.maasng:945 ][INFO    ][12613] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 3, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-3', u'relay_vlan': None, u'external_dhcp': None, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'name': u'fabric-3', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 4, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'ymfw3c', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}]
2019-11-06 20:32:31,534 [salt.state       :300 ][INFO    ][12613] {'new': 'Vlan untagged was updated'}
2019-11-06 20:32:31,535 [salt.state       :1951][INFO    ][12613] Completed state [vlan 0] at time 20:32:31.535194 duration_in_ms=507.687
2019-11-06 20:32:31,536 [salt.state       :1780][INFO    ][12613] Running state [opnfv] at time 20:32:31.536164
2019-11-06 20:32:31,536 [salt.state       :1813][INFO    ][12613] Executing state maasng.sshkey_present for [opnfv]
2019-11-06 20:32:31,582 [salt.loaded.ext.module.maasng:1903][INFO    ][12613] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-11-06 20:32:31,582 [salt.state       :300 ][INFO    ][12613] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-06 20:32:31,583 [salt.state       :1951][INFO    ][12613] Completed state [opnfv] at time 20:32:31.582939 duration_in_ms=46.776
2019-11-06 20:32:31,583 [salt.state       :1780][INFO    ][12613] Running state [maas.process_tags] at time 20:32:31.583728
2019-11-06 20:32:31,584 [salt.state       :1813][INFO    ][12613] Executing state module.run for [maas.process_tags]
2019-11-06 20:32:31,584 [salt.utils.decorators:613 ][WARNING ][12613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:31,642 [salt.loaded.ext.module.maas:92  ][INFO    ][12613] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-11-06 20:32:31,704 [salt.state       :300 ][INFO    ][12613] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-11-06 20:32:31,704 [salt.state       :1951][INFO    ][12613] Completed state [maas.process_tags] at time 20:32:31.704638 duration_in_ms=120.909
2019-11-06 20:32:31,710 [salt.minion      :1711][INFO    ][12613] Returning information for job: 20191106203203148293
2019-11-06 20:32:32,196 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106203232189633
2019-11-06 20:32:32,216 [salt.minion      :1432][INFO    ][13074] Starting a new job with PID 13074
2019-11-06 20:32:35,808 [salt.state       :915 ][INFO    ][13074] Loading fresh modules for state activity
2019-11-06 20:32:35,905 [salt.state       :1780][INFO    ][13074] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:32:35.905822
2019-11-06 20:32:35,906 [salt.state       :1813][INFO    ][13074] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:32:35,908 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13074] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:32:37,410 [salt.state       :300 ][INFO    ][13074] {'pid': 13099, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:32:37,410 [salt.state       :1951][INFO    ][13074] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:32:37.410441 duration_in_ms=1504.62
2019-11-06 20:32:37,411 [salt.state       :1780][INFO    ][13074] Running state [maas.process_machines] at time 20:32:37.411639
2019-11-06 20:32:37,411 [salt.state       :1813][INFO    ][13074] Executing state module.run for [maas.process_machines]
2019-11-06 20:32:37,412 [salt.utils.decorators:613 ][WARNING ][13074] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:32:37,923 [salt.loaded.ext.module.maas:412 ][WARNING ][13074] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:32:37,924 [salt.loaded.ext.module.maas:92  ][INFO    ][13074] machine hostname=gtw01 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=dmstyg architecture=amd64/generic power_parameters_power_user=admin
2019-11-06 20:32:39,190 [salt.loaded.ext.module.maas:412 ][WARNING ][13074] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:32:39,190 [salt.loaded.ext.module.maas:92  ][INFO    ][13074] 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=gn3kwy architecture=amd64/generic power_parameters_power_user=admin
2019-11-06 20:32:40,363 [salt.loaded.ext.module.maas:412 ][WARNING ][13074] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:32:40,364 [salt.loaded.ext.module.maas:92  ][INFO    ][13074] 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=wh737w architecture=amd64/generic power_parameters_power_user=admin
2019-11-06 20:32:41,291 [salt.loaded.ext.module.maas:412 ][WARNING ][13074] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-06 20:32:41,292 [salt.loaded.ext.module.maas:92  ][INFO    ][13074] machine hostname=ctl01 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=pbntg8 architecture=amd64/generic power_parameters_power_user=admin
2019-11-06 20:32:42,220 [salt.state       :300 ][INFO    ][13074] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-11-06 20:32:42,221 [salt.state       :1951][INFO    ][13074] Completed state [maas.process_machines] at time 20:32:42.220991 duration_in_ms=4809.349
2019-11-06 20:32:42,224 [salt.minion      :1711][INFO    ][13074] Returning information for job: 20191106203232189633
2019-11-06 20:33:14,940 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106203314928103
2019-11-06 20:33:14,963 [salt.minion      :1432][INFO    ][13310] Starting a new job with PID 13310
2019-11-06 20:33:18,579 [salt.state       :915 ][INFO    ][13310] Loading fresh modules for state activity
2019-11-06 20:33:18,660 [salt.state       :1780][INFO    ][13310] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:18.660349
2019-11-06 20:33:18,661 [salt.state       :1813][INFO    ][13310] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:33:18,664 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13310] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:33:19,945 [salt.state       :300 ][INFO    ][13310] {'pid': 13318, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:33:19,945 [salt.state       :1951][INFO    ][13310] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:33:19.945789 duration_in_ms=1285.44
2019-11-06 20:33:19,947 [salt.state       :1780][INFO    ][13310] Running state [maas.wait_for_machine_status] at time 20:33:19.947227
2019-11-06 20:33:19,947 [salt.state       :1813][INFO    ][13310] Executing state module.run for [maas.wait_for_machine_status]
2019-11-06 20:33:19,947 [salt.utils.decorators:613 ][WARNING ][13310] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:33:20,540 [salt.loaded.ext.module.maas:993 ][INFO    ][13310] Machine dmstyg mark broken
2019-11-06 20:33:20,902 [salt.loaded.ext.module.maas:996 ][INFO    ][13310] Machine dmstyg mark fixed
2019-11-06 20:33:22,068 [salt.loaded.ext.module.maas:684 ][INFO    ][13310] deploymachines hwe_kernel=hwe-16.04 system_id=dmstyg distro_series=xenial
2019-11-06 20:33:26,367 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1493.584131s left)
2019-11-06 20:33:30,090 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203330037963
2019-11-06 20:33:30,111 [salt.minion      :1432][INFO    ][13406] Starting a new job with PID 13406
2019-11-06 20:33:30,135 [salt.minion      :1711][INFO    ][13406] Returning information for job: 20191106203330037963
2019-11-06 20:33:58,817 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1461.13476205s left)
2019-11-06 20:34:00,141 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203400128323
2019-11-06 20:34:00,163 [salt.minion      :1432][INFO    ][13445] Starting a new job with PID 13445
2019-11-06 20:34:00,190 [salt.minion      :1711][INFO    ][13445] Returning information for job: 20191106203400128323
2019-11-06 20:34:30,232 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203430219288
2019-11-06 20:34:30,254 [salt.minion      :1432][INFO    ][13484] Starting a new job with PID 13484
2019-11-06 20:34:30,279 [salt.minion      :1711][INFO    ][13484] Returning information for job: 20191106203430219288
2019-11-06 20:34:31,236 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1428.71562505s left)
2019-11-06 20:35:00,278 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203500266477
2019-11-06 20:35:00,297 [salt.minion      :1432][INFO    ][13534] Starting a new job with PID 13534
2019-11-06 20:35:00,323 [salt.minion      :1711][INFO    ][13534] Returning information for job: 20191106203500266477
2019-11-06 20:35:03,674 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1396.27699804s left)
2019-11-06 20:35:30,329 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203530315950
2019-11-06 20:35:30,352 [salt.minion      :1432][INFO    ][13604] Starting a new job with PID 13604
2019-11-06 20:35:30,377 [salt.minion      :1711][INFO    ][13604] Returning information for job: 20191106203530315950
2019-11-06 20:35:36,134 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1363.81704712s left)
2019-11-06 20:36:00,384 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203600371891
2019-11-06 20:36:00,407 [salt.minion      :1432][INFO    ][13706] Starting a new job with PID 13706
2019-11-06 20:36:00,435 [salt.minion      :1711][INFO    ][13706] Returning information for job: 20191106203600371891
2019-11-06 20:36:08,768 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1331.18374515s left)
2019-11-06 20:36:30,446 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203630434204
2019-11-06 20:36:30,465 [salt.minion      :1432][INFO    ][13831] Starting a new job with PID 13831
2019-11-06 20:36:30,491 [salt.minion      :1711][INFO    ][13831] Returning information for job: 20191106203630434204
2019-11-06 20:36:41,257 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1298.69445205s left)
2019-11-06 20:37:00,505 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203700490876
2019-11-06 20:37:00,528 [salt.minion      :1432][INFO    ][13884] Starting a new job with PID 13884
2019-11-06 20:37:00,555 [salt.minion      :1711][INFO    ][13884] Returning information for job: 20191106203700490876
2019-11-06 20:37:13,855 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1266.0963881s left)
2019-11-06 20:37:30,578 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203730565271
2019-11-06 20:37:30,601 [salt.minion      :1432][INFO    ][13935] Starting a new job with PID 13935
2019-11-06 20:37:30,629 [salt.minion      :1711][INFO    ][13935] Returning information for job: 20191106203730565271
2019-11-06 20:37:46,256 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1233.69516611s left)
2019-11-06 20:38:00,651 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203800638344
2019-11-06 20:38:00,674 [salt.minion      :1432][INFO    ][14019] Starting a new job with PID 14019
2019-11-06 20:38:00,700 [salt.minion      :1711][INFO    ][14019] Returning information for job: 20191106203800638344
2019-11-06 20:38:18,792 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1201.1591711s left)
2019-11-06 20:38:30,728 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203830714968
2019-11-06 20:38:30,750 [salt.minion      :1432][INFO    ][14108] Starting a new job with PID 14108
2019-11-06 20:38:30,777 [salt.minion      :1711][INFO    ][14108] Returning information for job: 20191106203830714968
2019-11-06 20:38:51,179 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1168.77224398s left)
2019-11-06 20:39:00,809 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203900797371
2019-11-06 20:39:00,831 [salt.minion      :1432][INFO    ][14200] Starting a new job with PID 14200
2019-11-06 20:39:00,857 [salt.minion      :1711][INFO    ][14200] Returning information for job: 20191106203900797371
2019-11-06 20:39:23,378 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1136.57322502s left)
2019-11-06 20:39:30,894 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106203930881322
2019-11-06 20:39:30,917 [salt.minion      :1432][INFO    ][14268] Starting a new job with PID 14268
2019-11-06 20:39:30,944 [salt.minion      :1711][INFO    ][14268] Returning information for job: 20191106203930881322
2019-11-06 20:39:55,845 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1104.106143s left)
2019-11-06 20:40:00,984 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106204000971202
2019-11-06 20:40:01,007 [salt.minion      :1432][INFO    ][14317] Starting a new job with PID 14317
2019-11-06 20:40:01,033 [salt.minion      :1711][INFO    ][14317] Returning information for job: 20191106204000971202
2019-11-06 20:40:28,325 [salt.loaded.ext.module.maas:1023][INFO    ][13310] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1071.62659311s left)
2019-11-06 20:40:31,080 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command saltutil.find_job with jid 20191106204031067608
2019-11-06 20:40:31,104 [salt.minion      :1432][INFO    ][14387] Starting a new job with PID 14387
2019-11-06 20:40:31,132 [salt.minion      :1711][INFO    ][14387] Returning information for job: 20191106204031067608
2019-11-06 20:41:00,968 [salt.state       :300 ][INFO    ][13310] {'ret': True}
2019-11-06 20:41:00,969 [salt.state       :1951][INFO    ][13310] Completed state [maas.wait_for_machine_status] at time 20:41:00.969275 duration_in_ms=461022.045
2019-11-06 20:41:00,973 [salt.minion      :1711][INFO    ][13310] Returning information for job: 20191106203314928103
2019-11-06 20:41:01,661 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106204101647728
2019-11-06 20:41:01,683 [salt.minion      :1432][INFO    ][14478] Starting a new job with PID 14478
2019-11-06 20:41:05,362 [salt.state       :915 ][INFO    ][14478] Loading fresh modules for state activity
2019-11-06 20:41:05,497 [salt.state       :1780][INFO    ][14478] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:05.497845
2019-11-06 20:41:05,498 [salt.state       :1813][INFO    ][14478] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:41:05,499 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14478] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:41:07,058 [salt.state       :300 ][INFO    ][14478] {'pid': 14534, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:41:07,059 [salt.state       :1951][INFO    ][14478] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:07.059022 duration_in_ms=1561.177
2019-11-06 20:41:07,062 [salt.state       :1780][INFO    ][14478] Running state [maas_machines_storage_cmp002_lvm] at time 20:41:07.062372
2019-11-06 20:41:07,063 [salt.state       :1813][INFO    ][14478] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-06 20:41:07,669 [salt.state       :300 ][INFO    ][14478] Machine cmp002 is not in Ready state.
2019-11-06 20:41:07,670 [salt.state       :1951][INFO    ][14478] Completed state [maas_machines_storage_cmp002_lvm] at time 20:41:07.670082 duration_in_ms=607.713
2019-11-06 20:41:07,670 [salt.state       :1780][INFO    ][14478] Running state [maas_machines_storage_cmp001_lvm] at time 20:41:07.670650
2019-11-06 20:41:07,671 [salt.state       :1813][INFO    ][14478] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-06 20:41:08,315 [salt.state       :300 ][INFO    ][14478] Machine cmp001 is not in Ready state.
2019-11-06 20:41:08,316 [salt.state       :1951][INFO    ][14478] Completed state [maas_machines_storage_cmp001_lvm] at time 20:41:08.316228 duration_in_ms=645.577
2019-11-06 20:41:08,320 [salt.minion      :1711][INFO    ][14478] Returning information for job: 20191106204101647728
2019-11-06 20:41:08,832 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106204108819802
2019-11-06 20:41:08,853 [salt.minion      :1432][INFO    ][14544] Starting a new job with PID 14544
2019-11-06 20:41:09,575 [salt.state       :915 ][INFO    ][14544] Loading fresh modules for state activity
2019-11-06 20:41:09,664 [salt.state       :1780][INFO    ][14544] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:09.664126
2019-11-06 20:41:09,664 [salt.state       :1813][INFO    ][14544] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:41:09,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14544] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:41:11,174 [salt.state       :300 ][INFO    ][14544] {'pid': 14551, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:41:11,175 [salt.state       :1951][INFO    ][14544] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:11.175474 duration_in_ms=1511.349
2019-11-06 20:41:11,178 [salt.state       :1780][INFO    ][14544] Running state [maas.deploy_machines] at time 20:41:11.178008
2019-11-06 20:41:11,178 [salt.state       :1813][INFO    ][14544] Executing state module.run for [maas.deploy_machines]
2019-11-06 20:41:11,179 [salt.utils.decorators:613 ][WARNING ][14544] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:41:11,746 [salt.state       :300 ][INFO    ][14544] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-11-06 20:41:11,747 [salt.state       :1951][INFO    ][14544] Completed state [maas.deploy_machines] at time 20:41:11.747013 duration_in_ms=569.004
2019-11-06 20:41:11,750 [salt.minion      :1711][INFO    ][14544] Returning information for job: 20191106204108819802
2019-11-06 20:41:12,379 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command state.apply with jid 20191106204112369429
2019-11-06 20:41:12,398 [salt.minion      :1432][INFO    ][14560] Starting a new job with PID 14560
2019-11-06 20:41:13,144 [salt.state       :915 ][INFO    ][14560] Loading fresh modules for state activity
2019-11-06 20:41:13,232 [salt.state       :1780][INFO    ][14560] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:13.232302
2019-11-06 20:41:13,232 [salt.state       :1813][INFO    ][14560] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-06 20:41:13,234 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14560] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-06 20:41:14,800 [salt.state       :300 ][INFO    ][14560] {'pid': 14567, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-06 20:41:14,801 [salt.state       :1951][INFO    ][14560] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:14.801447 duration_in_ms=1569.144
2019-11-06 20:41:14,803 [salt.state       :1780][INFO    ][14560] Running state [maas.wait_for_machine_status] at time 20:41:14.803348
2019-11-06 20:41:14,803 [salt.state       :1813][INFO    ][14560] Executing state module.run for [maas.wait_for_machine_status]
2019-11-06 20:41:14,804 [salt.utils.decorators:613 ][WARNING ][14560] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-06 20:41:17,296 [salt.state       :300 ][INFO    ][14560] {'ret': True}
2019-11-06 20:41:17,296 [salt.state       :1951][INFO    ][14560] Completed state [maas.wait_for_machine_status] at time 20:41:17.296536 duration_in_ms=2493.186
2019-11-06 20:41:17,300 [salt.minion      :1711][INFO    ][14560] Returning information for job: 20191106204112369429
2019-11-06 21:11:49,561 [salt.utils.schedule:1377][INFO    ][7502] Running scheduled job: __mine_interval
2019-11-06 21:29:47,441 [salt.minion      :1308][INFO    ][7502] User sudo_ubuntu Executing command cp.push_dir with jid 20191106212947429104
2019-11-06 21:29:47,464 [salt.minion      :1432][INFO    ][18435] Starting a new job with PID 18435
