2019-04-26 20:12:28,265 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-26 20:13:18,309 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-26 20:14:08,359 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-26 20:14:58,405 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-26 20:15:48,457 [salt.minion      :870 ][ERROR   ][361] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-26 20:17:57,099 [salt.utils.decorators:613 ][WARNING ][2764] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 20:17:57,707 [salt.utils.decorators:613 ][WARNING ][2764] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 20:17:59,937 [salt.loaded.int.states.file:2298][WARNING ][2913] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-04-26 20:18:05,401 [salt.state       :2022][WARNING ][3012] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-26 20:18:07,975 [salt.utils.decorators:613 ][WARNING ][3012] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 20:33:13,579 [salt.utils.decorators:613 ][WARNING ][3012] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 20:53:51,072 [salt.utils.decorators:613 ][WARNING ][3012] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:08:51,928 [salt.utils.decorators:613 ][WARNING ][3012] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:08:56,019 [salt.loaded.ext.module.maasng:1008][WARNING ][3012] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-04-26 21:08:56,020 [salt.loaded.ext.module.maasng:1011][WARNING ][3012] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-04-26 21:08:56,756 [salt.loaded.ext.module.maasng:1235][WARNING ][3012] Ignoring parameter vlan:0
2019-04-26 21:08:57,675 [salt.utils.decorators:613 ][WARNING ][3012] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:08:59,772 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30951] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-26 21:08:59,803 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30951] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-04-26 21:08:59,827 [salt.utils.parsers:1051][WARNING ][361] Minion received a SIGTERM. Exiting.
2019-04-26 21:09:00,831 [salt.cli.daemons :293 ][INFO    ][31017] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-04-26 21:09:00,924 [salt.cli.daemons :82  ][INFO    ][31017] Starting up the Salt Minion
2019-04-26 21:09:00,925 [salt.utils.event :1017][INFO    ][31017] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-04-26 21:09:01,722 [salt.minion      :976 ][INFO    ][31017] Creating minion process manager
2019-04-26 21:09:03,010 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][31017] Executing command ['date', '+%z'] in directory '/root'
2019-04-26 21:09:03,029 [salt.utils.schedule:568 ][INFO    ][31017] Updating job settings for scheduled job: __mine_interval
2019-04-26 21:09:03,030 [salt.minion      :1108][INFO    ][31017] Added mine.update to scheduler
2019-04-26 21:09:03,034 [salt.minion      :1975][INFO    ][31017] Minion is starting as user 'root'
2019-04-26 21:09:03,045 [salt.minion      :2336][INFO    ][31017] Minion is ready to receive requests!
2019-04-26 21:09:03,330 [salt.utils.decorators:613 ][WARNING ][30955] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:09:03,404 [salt.loaded.ext.module.maas:412 ][WARNING ][30955] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:09:07,716 [salt.loaded.ext.module.maas:412 ][WARNING ][30955] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:09:12,160 [salt.loaded.ext.module.maas:412 ][WARNING ][30955] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:09:13,467 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426210913455105
2019-04-26 21:09:13,486 [salt.minion      :1432][INFO    ][31296] Starting a new job with PID 31296
2019-04-26 21:09:13,511 [salt.minion      :1711][INFO    ][31296] Returning information for job: 20190426210913455105
2019-04-26 21:09:14,926 [salt.loaded.ext.module.maas:412 ][WARNING ][30955] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:09:50,731 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426210950717234
2019-04-26 21:09:50,752 [salt.minion      :1432][INFO    ][31392] Starting a new job with PID 31392
2019-04-26 21:09:54,417 [salt.state       :915 ][INFO    ][31392] Loading fresh modules for state activity
2019-04-26 21:09:54,475 [salt.fileclient  :1219][INFO    ][31392] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-04-26 21:09:54,521 [salt.state       :1780][INFO    ][31392] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:09:54.521145
2019-04-26 21:09:54,521 [salt.state       :1813][INFO    ][31392] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:09:54,523 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31392] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:09:56,051 [salt.state       :300 ][INFO    ][31392] {'pid': 31400, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:09:56,052 [salt.state       :1951][INFO    ][31392] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:09:56.052391 duration_in_ms=1531.246
2019-04-26 21:09:56,055 [salt.state       :1780][INFO    ][31392] Running state [maas.wait_for_machine_status] at time 21:09:56.054943
2019-04-26 21:09:56,055 [salt.state       :1813][INFO    ][31392] Executing state module.run for [maas.wait_for_machine_status]
2019-04-26 21:09:56,056 [salt.utils.decorators:613 ][WARNING ][31392] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:09:56,760 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.30622196s left)
2019-04-26 21:10:05,816 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211005803189
2019-04-26 21:10:05,839 [salt.minion      :1432][INFO    ][31430] Starting a new job with PID 31430
2019-04-26 21:10:05,862 [salt.minion      :1711][INFO    ][31430] Returning information for job: 20190426211005803189
2019-04-26 21:10:27,473 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.59348297s left)
2019-04-26 21:10:35,864 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211035851388
2019-04-26 21:10:35,886 [salt.minion      :1432][INFO    ][31473] Starting a new job with PID 31473
2019-04-26 21:10:35,910 [salt.minion      :1711][INFO    ][31473] Returning information for job: 20190426211035851388
2019-04-26 21:10:58,449 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1437.61769891s left)
2019-04-26 21:11:05,905 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211105892907
2019-04-26 21:11:05,928 [salt.minion      :1432][INFO    ][31621] Starting a new job with PID 31621
2019-04-26 21:11:05,950 [salt.minion      :1711][INFO    ][31621] Returning information for job: 20190426211105892907
2019-04-26 21:11:29,493 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1406.57290387s left)
2019-04-26 21:11:35,955 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211135942350
2019-04-26 21:11:35,977 [salt.minion      :1432][INFO    ][31854] Starting a new job with PID 31854
2019-04-26 21:11:36,000 [salt.minion      :1711][INFO    ][31854] Returning information for job: 20190426211135942350
2019-04-26 21:12:00,778 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1375.28816795s left)
2019-04-26 21:12:06,007 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211205994648
2019-04-26 21:12:06,030 [salt.minion      :1432][INFO    ][31952] Starting a new job with PID 31952
2019-04-26 21:12:06,053 [salt.minion      :1711][INFO    ][31952] Returning information for job: 20190426211205994648
2019-04-26 21:12:32,119 [salt.loaded.ext.module.maas:1023][INFO    ][31392] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1343.9468329s left)
2019-04-26 21:12:36,062 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211236047267
2019-04-26 21:12:36,085 [salt.minion      :1432][INFO    ][32404] Starting a new job with PID 32404
2019-04-26 21:12:36,107 [salt.minion      :1711][INFO    ][32404] Returning information for job: 20190426211236047267
2019-04-26 21:13:05,177 [salt.state       :300 ][INFO    ][31392] {'ret': True}
2019-04-26 21:13:05,177 [salt.state       :1951][INFO    ][31392] Completed state [maas.wait_for_machine_status] at time 21:13:05.177435 duration_in_ms=189122.491
2019-04-26 21:13:05,181 [salt.minion      :1711][INFO    ][31392] Returning information for job: 20190426210950717234
2019-04-26 21:13:05,780 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426211305766471
2019-04-26 21:13:05,802 [salt.minion      :1432][INFO    ][32528] Starting a new job with PID 32528
2019-04-26 21:13:09,368 [salt.state       :915 ][INFO    ][32528] Loading fresh modules for state activity
2019-04-26 21:13:09,413 [salt.fileclient  :1219][INFO    ][32528] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-04-26 21:13:09,500 [salt.state       :1780][INFO    ][32528] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:09.500025
2019-04-26 21:13:09,500 [salt.state       :1813][INFO    ][32528] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:13:09,501 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32528] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:13:10,909 [salt.state       :300 ][INFO    ][32528] {'pid': 32626, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:13:10,910 [salt.state       :1951][INFO    ][32528] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:10.910085 duration_in_ms=1410.06
2019-04-26 21:13:10,913 [salt.state       :1780][INFO    ][32528] Running state [maas_machines_storage_cmp002_lvm] at time 21:13:10.913147
2019-04-26 21:13:10,913 [salt.state       :1813][INFO    ][32528] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-26 21:13:12,031 [salt.loaded.ext.module.maasng:610 ][INFO    ][32528] yendf7
2019-04-26 21:13:12,032 [salt.loaded.ext.module.maasng:626 ][INFO    ][32528] sda
2019-04-26 21:13:12,865 [salt.loaded.ext.module.maasng:361 ][INFO    ][32528] yendf7
2019-04-26 21:13:12,998 [salt.loaded.ext.module.maasng:367 ][INFO    ][32528] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yendf7', u'partition_table_type': u'GPT', u'filesystem': None, 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/yendf7/blockdevices/3/', u'type': u'physical', u'id': 3, u'partitions': [{u'size': 2397992648704, u'uuid': u'ca901098-3243-45fb-9702-5287e5bffcc5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yendf7', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'6c3a79eb-b368-46bb-96b8-de81a18388e5', 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/yendf7/blockdevices/3/partition/3', u'type': u'partition', u'id': 3, u'device_id': 3}]}, {u'size': 2397988454400, u'model': None, u'block_size': 4096, u'uuid': u'56c7f310-af88-43bd-bd45-2d68662cf8a0', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'yendf7', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'ee89b728-7306-4e10-aabe-1e322e69b135', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/7/', u'type': u'virtual', u'id': 7, u'partitions': []}]
2019-04-26 21:13:12,999 [salt.loaded.ext.module.maasng:632 ][INFO    ][32528] vgroot
2019-04-26 21:13:12,999 [salt.loaded.ext.module.maasng:635 ][INFO    ][32528] lvroot
2019-04-26 21:13:13,000 [salt.loaded.ext.module.maasng:639 ][INFO    ][32528] 107374182400
2019-04-26 21:13:13,562 [salt.loaded.ext.module.maasng:645 ][INFO    ][32528] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 23}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'system_id': u'yendf7', 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/yendf7/interfaces/5/'}, u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'yendf7', 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'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/9/', u'uuid': u'a689fd5c-3349-4d9d-9d21-363220e3cd08', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'yendf7', u'partition_table_type': None, u'filesystem': {u'uuid': u'a2f0c45d-f9ed-4bac-8988-fe25b4d7d5f2', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yendf7', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'e46781a7-6e0f-4e58-8773-63dd1fc52277', u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yendf7', u'filesystem': {u'uuid': u'2b549872-8fe3-4d2a-8128-f6f2506f0857', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'device_id': 3}]}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/9/', u'uuid': u'a689fd5c-3349-4d9d-9d21-363220e3cd08', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'yendf7', u'partition_table_type': None, u'filesystem': {u'uuid': u'a2f0c45d-f9ed-4bac-8988-fe25b4d7d5f2', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'serial': None, u'partitions': []}], 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'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yendf7', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 3, u'partitions': [{u'uuid': u'e46781a7-6e0f-4e58-8773-63dd1fc52277', u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yendf7', u'filesystem': {u'uuid': u'2b549872-8fe3-4d2a-8128-f6f2506f0857', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'device_id': 3}]}], u'ip_addresses': [u'192.168.11.41'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'yendf7', u'id': 5}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yendf7', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 3, u'partitions': [{u'uuid': u'e46781a7-6e0f-4e58-8773-63dd1fc52277', u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/blockdevices/3/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yendf7', u'filesystem': {u'uuid': u'2b549872-8fe3-4d2a-8128-f6f2506f0857', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'device_id': 3}]}, 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'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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 23}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'system_id': u'yendf7', 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/yendf7/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 24}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'yendf7', u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/interfaces/14/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 25}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'yendf7', u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/interfaces/15/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 26}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'yendf7', u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/yendf7/interfaces/16/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/yendf7/'}
2019-04-26 21:13:13,563 [salt.state       :300 ][INFO    ][32528] {'new': {'storage_layout': 'lvm'}}
2019-04-26 21:13:13,563 [salt.state       :1951][INFO    ][32528] Completed state [maas_machines_storage_cmp002_lvm] at time 21:13:13.563920 duration_in_ms=2650.773
2019-04-26 21:13:13,564 [salt.state       :1780][INFO    ][32528] Running state [maas_machines_storage_cmp001_lvm] at time 21:13:13.564247
2019-04-26 21:13:13,564 [salt.state       :1813][INFO    ][32528] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-26 21:13:14,335 [salt.loaded.ext.module.maasng:610 ][INFO    ][32528] scfywa
2019-04-26 21:13:14,335 [salt.loaded.ext.module.maasng:626 ][INFO    ][32528] sda
2019-04-26 21:13:14,654 [salt.loaded.ext.module.maasng:361 ][INFO    ][32528] scfywa
2019-04-26 21:13:14,740 [salt.loaded.ext.module.maasng:367 ][INFO    ][32528] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'scfywa', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'4ddb38c1-23d7-4c29-8643-2ebc45e122e9', u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/partition/2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'scfywa', u'filesystem': {u'uuid': u'7e7ed709-7973-4a10-971d-0e3a36d90f43', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 2, u'device_id': 2}]}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/6/', u'uuid': u'fcf7c850-a470-4c40-bd43-6f070545fe3d', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'scfywa', u'partition_table_type': None, u'filesystem': {u'uuid': u'64e97eb5-570e-4dcb-be46-32091546f145', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 6, u'serial': None, u'partitions': []}]
2019-04-26 21:13:14,741 [salt.loaded.ext.module.maasng:632 ][INFO    ][32528] vgroot
2019-04-26 21:13:14,741 [salt.loaded.ext.module.maasng:635 ][INFO    ][32528] lvroot
2019-04-26 21:13:14,741 [salt.loaded.ext.module.maasng:639 ][INFO    ][32528] 107374182400
2019-04-26 21:13:15,223 [salt.loaded.ext.module.maasng:645 ][INFO    ][32528] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 18}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'system_id': u'scfywa', u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/interfaces/6/'}, u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'scfywa', 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'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/10/', u'uuid': u'6f674736-a098-4424-9ffc-967c5b86be6e', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'scfywa', u'partition_table_type': None, u'filesystem': {u'uuid': u'0585779a-5ebb-4947-8f5a-0b6af7c6d169', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'scfywa', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'da97487c-4509-43d1-abd8-db549292e744', u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'scfywa', u'filesystem': {u'uuid': u'e4b2e980-8136-4882-b3aa-66a6be900d7a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}]}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/10/', u'uuid': u'6f674736-a098-4424-9ffc-967c5b86be6e', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'scfywa', u'partition_table_type': None, u'filesystem': {u'uuid': u'0585779a-5ebb-4947-8f5a-0b6af7c6d169', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'serial': None, u'partitions': []}], 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'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'scfywa', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'da97487c-4509-43d1-abd8-db549292e744', u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'scfywa', u'filesystem': {u'uuid': u'e4b2e980-8136-4882-b3aa-66a6be900d7a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}]}], u'ip_addresses': [u'192.168.11.39'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'scfywa', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 6, u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'scfywa', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'da97487c-4509-43d1-abd8-db549292e744', u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'scfywa', u'filesystem': {u'uuid': u'e4b2e980-8136-4882-b3aa-66a6be900d7a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}]}, u'current_testing_result_id': 7, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 18}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'system_id': u'scfywa', u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/interfaces/6/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 19}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'scfywa', u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/interfaces/11/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 20}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'scfywa', u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/interfaces/12/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 21}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'scfywa', u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/scfywa/interfaces/13/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/scfywa/'}
2019-04-26 21:13:15,225 [salt.state       :300 ][INFO    ][32528] {'new': {'storage_layout': 'lvm'}}
2019-04-26 21:13:15,226 [salt.state       :1951][INFO    ][32528] Completed state [maas_machines_storage_cmp001_lvm] at time 21:13:15.226032 duration_in_ms=1661.783
2019-04-26 21:13:15,229 [salt.minion      :1711][INFO    ][32528] Returning information for job: 20190426211305766471
2019-04-26 21:13:15,803 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426211315790932
2019-04-26 21:13:15,824 [salt.minion      :1432][INFO    ][32661] Starting a new job with PID 32661
2019-04-26 21:13:16,323 [salt.state       :915 ][INFO    ][32661] Loading fresh modules for state activity
2019-04-26 21:13:16,349 [salt.fileclient  :1219][INFO    ][32661] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-04-26 21:13:16,372 [salt.state       :1780][INFO    ][32661] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:16.372344
2019-04-26 21:13:16,372 [salt.state       :1813][INFO    ][32661] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:13:16,373 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32661] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:13:17,756 [salt.state       :300 ][INFO    ][32661] {'pid': 32669, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:13:17,757 [salt.state       :1951][INFO    ][32661] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:17.757361 duration_in_ms=1385.016
2019-04-26 21:13:17,759 [salt.state       :1780][INFO    ][32661] Running state [maas.deploy_machines] at time 21:13:17.759764
2019-04-26 21:13:17,760 [salt.state       :1813][INFO    ][32661] Executing state module.run for [maas.deploy_machines]
2019-04-26 21:13:17,760 [salt.utils.decorators:613 ][WARNING ][32661] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:13:18,147 [salt.loaded.ext.module.maas:684 ][INFO    ][32661] deploymachines hwe_kernel=hwe-16.04 system_id=7eq4sb distro_series=xenial
2019-04-26 21:13:24,262 [salt.loaded.ext.module.maas:684 ][INFO    ][32661] deploymachines hwe_kernel=hwe-16.04 system_id=yendf7 distro_series=xenial
2019-04-26 21:13:29,215 [salt.loaded.ext.module.maas:684 ][INFO    ][32661] deploymachines hwe_kernel=hwe-16.04 system_id=scfywa distro_series=xenial
2019-04-26 21:13:30,819 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211330807419
2019-04-26 21:13:30,837 [salt.minion      :1432][INFO    ][317] Starting a new job with PID 317
2019-04-26 21:13:30,861 [salt.minion      :1711][INFO    ][317] Returning information for job: 20190426211330807419
2019-04-26 21:13:35,430 [salt.loaded.ext.module.maas:684 ][INFO    ][32661] deploymachines hwe_kernel=hwe-16.04 system_id=r8q8pg distro_series=xenial
2019-04-26 21:13:41,251 [salt.state       :300 ][INFO    ][32661] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-04-26 21:13:41,252 [salt.state       :1951][INFO    ][32661] Completed state [maas.deploy_machines] at time 21:13:41.252358 duration_in_ms=23492.593
2019-04-26 21:13:41,255 [salt.minion      :1711][INFO    ][32661] Returning information for job: 20190426211315790932
2019-04-26 21:13:41,818 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426211341810889
2019-04-26 21:13:41,836 [salt.minion      :1432][INFO    ][439] Starting a new job with PID 439
2019-04-26 21:13:45,233 [salt.state       :915 ][INFO    ][439] Loading fresh modules for state activity
2019-04-26 21:13:45,283 [salt.fileclient  :1219][INFO    ][439] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-04-26 21:13:45,324 [salt.state       :1780][INFO    ][439] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:45.324037
2019-04-26 21:13:45,324 [salt.state       :1813][INFO    ][439] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:13:45,326 [salt.loaded.int.module.cmdmod:395 ][INFO    ][439] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:13:46,582 [salt.state       :300 ][INFO    ][439] {'pid': 446, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:13:46,583 [salt.state       :1951][INFO    ][439] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:13:46.583144 duration_in_ms=1259.105
2019-04-26 21:13:46,585 [salt.state       :1780][INFO    ][439] Running state [maas.wait_for_machine_status] at time 21:13:46.585442
2019-04-26 21:13:46,585 [salt.state       :1813][INFO    ][439] Executing state module.run for [maas.wait_for_machine_status]
2019-04-26 21:13:46,586 [salt.utils.decorators:613 ][WARNING ][439] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:13:49,134 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2247.4618392s left)
2019-04-26 21:13:56,856 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211356842664
2019-04-26 21:13:56,878 [salt.minion      :1432][INFO    ][642] Starting a new job with PID 642
2019-04-26 21:13:56,902 [salt.minion      :1711][INFO    ][642] Returning information for job: 20190426211356842664
2019-04-26 21:14:21,609 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2214.98706913s left)
2019-04-26 21:14:26,900 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211426886856
2019-04-26 21:14:26,916 [salt.minion      :1432][INFO    ][698] Starting a new job with PID 698
2019-04-26 21:14:26,938 [salt.minion      :1711][INFO    ][698] Returning information for job: 20190426211426886856
2019-04-26 21:14:53,872 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2182.72374821s left)
2019-04-26 21:14:57,005 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211456992356
2019-04-26 21:14:57,027 [salt.minion      :1432][INFO    ][717] Starting a new job with PID 717
2019-04-26 21:14:57,050 [salt.minion      :1711][INFO    ][717] Returning information for job: 20190426211456992356
2019-04-26 21:15:26,500 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2150.09580207s left)
2019-04-26 21:15:27,056 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211527043034
2019-04-26 21:15:27,078 [salt.minion      :1432][INFO    ][876] Starting a new job with PID 876
2019-04-26 21:15:27,103 [salt.minion      :1711][INFO    ][876] Returning information for job: 20190426211527043034
2019-04-26 21:15:57,109 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211557096796
2019-04-26 21:15:57,131 [salt.minion      :1432][INFO    ][991] Starting a new job with PID 991
2019-04-26 21:15:57,155 [salt.minion      :1711][INFO    ][991] Returning information for job: 20190426211557096796
2019-04-26 21:15:58,800 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2117.79618716s left)
2019-04-26 21:16:27,162 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211627148713
2019-04-26 21:16:27,185 [salt.minion      :1432][INFO    ][1596] Starting a new job with PID 1596
2019-04-26 21:16:27,211 [salt.minion      :1711][INFO    ][1596] Returning information for job: 20190426211627148713
2019-04-26 21:16:30,827 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2085.76858902s left)
2019-04-26 21:16:57,218 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211657205926
2019-04-26 21:16:57,242 [salt.minion      :1432][INFO    ][1616] Starting a new job with PID 1616
2019-04-26 21:16:57,264 [salt.minion      :1711][INFO    ][1616] Returning information for job: 20190426211657205926
2019-04-26 21:17:03,217 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2053.378896s left)
2019-04-26 21:17:27,275 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211727262146
2019-04-26 21:17:27,297 [salt.minion      :1432][INFO    ][1781] Starting a new job with PID 1781
2019-04-26 21:17:27,322 [salt.minion      :1711][INFO    ][1781] Returning information for job: 20190426211727262146
2019-04-26 21:17:35,598 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2020.99788022s left)
2019-04-26 21:17:57,337 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211757324388
2019-04-26 21:17:57,359 [salt.minion      :1432][INFO    ][1801] Starting a new job with PID 1801
2019-04-26 21:17:57,382 [salt.minion      :1711][INFO    ][1801] Returning information for job: 20190426211757324388
2019-04-26 21:18:07,813 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1988.78323603s left)
2019-04-26 21:18:27,413 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211827402359
2019-04-26 21:18:27,431 [salt.minion      :1432][INFO    ][2346] Starting a new job with PID 2346
2019-04-26 21:18:27,450 [salt.minion      :1711][INFO    ][2346] Returning information for job: 20190426211827402359
2019-04-26 21:18:41,353 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1955.24315619s left)
2019-04-26 21:18:57,492 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211857481666
2019-04-26 21:18:57,513 [salt.minion      :1432][INFO    ][2429] Starting a new job with PID 2429
2019-04-26 21:18:57,533 [salt.minion      :1711][INFO    ][2429] Returning information for job: 20190426211857481666
2019-04-26 21:19:27,582 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211927570135
2019-04-26 21:19:27,604 [salt.minion      :1432][INFO    ][2700] Starting a new job with PID 2700
2019-04-26 21:19:27,627 [salt.minion      :1711][INFO    ][2700] Returning information for job: 20190426211927570135
2019-04-26 21:19:57,677 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426211957664713
2019-04-26 21:19:57,699 [salt.minion      :1432][INFO    ][2752] Starting a new job with PID 2752
2019-04-26 21:19:57,722 [salt.minion      :1711][INFO    ][2752] Returning information for job: 20190426211957664713
2019-04-26 21:20:27,783 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212027770090
2019-04-26 21:20:27,805 [salt.minion      :1432][INFO    ][2810] Starting a new job with PID 2810
2019-04-26 21:20:27,829 [salt.minion      :1711][INFO    ][2810] Returning information for job: 20190426212027770090
2019-04-26 21:20:57,894 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212057882100
2019-04-26 21:20:57,916 [salt.minion      :1432][INFO    ][2885] Starting a new job with PID 2885
2019-04-26 21:20:57,939 [salt.minion      :1711][INFO    ][2885] Returning information for job: 20190426212057882100
2019-04-26 21:21:28,022 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212128010362
2019-04-26 21:21:28,044 [salt.minion      :1432][INFO    ][2946] Starting a new job with PID 2946
2019-04-26 21:21:28,064 [salt.minion      :1711][INFO    ][2946] Returning information for job: 20190426212128010362
2019-04-26 21:21:58,142 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212158130737
2019-04-26 21:21:58,160 [salt.minion      :1432][INFO    ][2998] Starting a new job with PID 2998
2019-04-26 21:21:58,181 [salt.minion      :1711][INFO    ][2998] Returning information for job: 20190426212158130737
2019-04-26 21:22:28,267 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212228255447
2019-04-26 21:22:28,289 [salt.minion      :1432][INFO    ][3057] Starting a new job with PID 3057
2019-04-26 21:22:28,310 [salt.minion      :1711][INFO    ][3057] Returning information for job: 20190426212228255447
2019-04-26 21:22:58,404 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212258390418
2019-04-26 21:22:58,426 [salt.minion      :1432][INFO    ][3147] Starting a new job with PID 3147
2019-04-26 21:22:58,448 [salt.minion      :1711][INFO    ][3147] Returning information for job: 20190426212258390418
2019-04-26 21:23:28,552 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212328540550
2019-04-26 21:23:28,573 [salt.minion      :1432][INFO    ][3194] Starting a new job with PID 3194
2019-04-26 21:23:28,597 [salt.minion      :1711][INFO    ][3194] Returning information for job: 20190426212328540550
2019-04-26 21:23:58,700 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212358689107
2019-04-26 21:23:58,721 [salt.minion      :1432][INFO    ][3231] Starting a new job with PID 3231
2019-04-26 21:23:58,743 [salt.minion      :1711][INFO    ][3231] Returning information for job: 20190426212358689107
2019-04-26 21:24:01,641 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1634.95543313s left)
2019-04-26 21:24:28,848 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212428835863
2019-04-26 21:24:28,870 [salt.minion      :1432][INFO    ][3603] Starting a new job with PID 3603
2019-04-26 21:24:28,892 [salt.minion      :1711][INFO    ][3603] Returning information for job: 20190426212428835863
2019-04-26 21:24:33,730 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1602.86607218s left)
2019-04-26 21:24:58,998 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212458986274
2019-04-26 21:24:59,021 [salt.minion      :1432][INFO    ][3653] Starting a new job with PID 3653
2019-04-26 21:24:59,046 [salt.minion      :1711][INFO    ][3653] Returning information for job: 20190426212458986274
2019-04-26 21:25:06,094 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1570.50198102s left)
2019-04-26 21:25:29,163 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212529149947
2019-04-26 21:25:29,185 [salt.minion      :1432][INFO    ][3718] Starting a new job with PID 3718
2019-04-26 21:25:29,209 [salt.minion      :1711][INFO    ][3718] Returning information for job: 20190426212529149947
2019-04-26 21:25:38,208 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1538.38758612s left)
2019-04-26 21:25:59,335 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212559322535
2019-04-26 21:25:59,358 [salt.minion      :1432][INFO    ][3836] Starting a new job with PID 3836
2019-04-26 21:25:59,380 [salt.minion      :1711][INFO    ][3836] Returning information for job: 20190426212559322535
2019-04-26 21:26:10,337 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001']
sleep for:30s Timeout:2250s (1506.2594502s left)
2019-04-26 21:26:29,400 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212629389053
2019-04-26 21:26:29,422 [salt.minion      :1432][INFO    ][4025] Starting a new job with PID 4025
2019-04-26 21:26:29,446 [salt.minion      :1711][INFO    ][4025] Returning information for job: 20190426212629389053
2019-04-26 21:26:42,935 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1473.66141605s left)
2019-04-26 21:26:59,586 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212659573449
2019-04-26 21:26:59,608 [salt.minion      :1432][INFO    ][4056] Starting a new job with PID 4056
2019-04-26 21:26:59,630 [salt.minion      :1711][INFO    ][4056] Returning information for job: 20190426212659573449
2019-04-26 21:27:15,279 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1441.3167901s left)
2019-04-26 21:27:29,773 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212729760746
2019-04-26 21:27:29,795 [salt.minion      :1432][INFO    ][4383] Starting a new job with PID 4383
2019-04-26 21:27:29,820 [salt.minion      :1711][INFO    ][4383] Returning information for job: 20190426212729760746
2019-04-26 21:27:47,754 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1408.84205222s left)
2019-04-26 21:27:59,983 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212759971187
2019-04-26 21:28:00,006 [salt.minion      :1432][INFO    ][4402] Starting a new job with PID 4402
2019-04-26 21:28:00,029 [salt.minion      :1711][INFO    ][4402] Returning information for job: 20190426212759971187
2019-04-26 21:28:20,268 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1376.32803917s left)
2019-04-26 21:28:30,206 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212830193349
2019-04-26 21:28:30,229 [salt.minion      :1432][INFO    ][4479] Starting a new job with PID 4479
2019-04-26 21:28:30,254 [salt.minion      :1711][INFO    ][4479] Returning information for job: 20190426212830193349
2019-04-26 21:28:52,717 [salt.loaded.ext.module.maas:1023][INFO    ][439] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1343.87881207s left)
2019-04-26 21:29:00,226 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426212900213749
2019-04-26 21:29:00,248 [salt.minion      :1432][INFO    ][4500] Starting a new job with PID 4500
2019-04-26 21:29:00,271 [salt.minion      :1711][INFO    ][4500] Returning information for job: 20190426212900213749
2019-04-26 21:29:24,522 [salt.loaded.ext.module.maas:993 ][INFO    ][439] Machine scfywa mark broken
2019-04-26 21:29:25,294 [salt.loaded.ext.module.maas:996 ][INFO    ][439] Machine scfywa mark fixed
2019-04-26 21:29:26,190 [salt.loaded.ext.module.maas:684 ][INFO    ][439] deploymachines hwe_kernel=hwe-16.04 system_id=scfywa distro_series=xenial
2019-04-26 21:29:28,774 [salt.loaded.ext.module.maas:160 ][ERROR   ][439] Failed for object cmp001 reason Unable to change power state to 'cycle' for node cmp001: another action is already in progress for that node.
2019-04-26 21:29:28,775 [salt.state       :302 ][ERROR   ][439] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['gtw01', 'cmp002', 'ctl01'], 'errors': {'cmp001': "Unable to change power state to 'cycle' for node cmp001: another action is already in progress for that node."}, 'success': []}
2019-04-26 21:29:28,775 [salt.state       :1951][INFO    ][439] Completed state [maas.wait_for_machine_status] at time 21:29:28.775610 duration_in_ms=942190.168
2019-04-26 21:29:28,778 [salt.minion      :1711][INFO    ][439] Returning information for job: 20190426211341810889
2019-04-26 21:29:39,578 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command pillar.get with jid 20190426212939565661
2019-04-26 21:29:39,600 [salt.minion      :1432][INFO    ][4642] Starting a new job with PID 4642
2019-04-26 21:29:39,607 [salt.minion      :1711][INFO    ][4642] Returning information for job: 20190426212939565661
2019-04-26 21:29:40,121 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command service.status with jid 20190426212940107684
2019-04-26 21:29:40,142 [salt.minion      :1432][INFO    ][4647] Starting a new job with PID 4647
2019-04-26 21:29:40,519 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4647] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:40,554 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4647] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-04-26 21:29:40,572 [salt.minion      :1711][INFO    ][4647] Returning information for job: 20190426212940107684
2019-04-26 21:29:41,109 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426212941096628
2019-04-26 21:29:41,130 [salt.minion      :1432][INFO    ][4658] Starting a new job with PID 4658
2019-04-26 21:29:44,790 [salt.state       :915 ][INFO    ][4658] Loading fresh modules for state activity
2019-04-26 21:29:45,238 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'salt-minion --version' in directory '/root'
2019-04-26 21:29:45,599 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'salt-minion --version' in directory '/root'
2019-04-26 21:29:46,433 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'salt-minion --version' in directory '/root'
2019-04-26 21:29:46,817 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'salt-minion --version' in directory '/root'
2019-04-26 21:29:48,204 [salt.state       :1780][INFO    ][4658] Running state [salt-minion] at time 21:29:48.204835
2019-04-26 21:29:48,205 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [salt-minion]
2019-04-26 21:29:48,205 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-26 21:29:48,280 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-04-26 21:29:48,281 [salt.state       :1951][INFO    ][4658] Completed state [salt-minion] at time 21:29:48.280954 duration_in_ms=76.12
2019-04-26 21:29:48,281 [salt.state       :1780][INFO    ][4658] Running state [salt_minion_dependency_packages] at time 21:29:48.281218
2019-04-26 21:29:48,281 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-04-26 21:29:48,286 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-04-26 21:29:48,286 [salt.state       :1951][INFO    ][4658] Completed state [salt_minion_dependency_packages] at time 21:29:48.286349 duration_in_ms=5.131
2019-04-26 21:29:48,288 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/minion.d/minion.conf] at time 21:29:48.288770
2019-04-26 21:29:48,288 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-04-26 21:29:48,470 [salt.state       :300 ][INFO    ][4658] File /etc/salt/minion.d/minion.conf is in the correct state
2019-04-26 21:29:48,470 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/minion.d/minion.conf] at time 21:29:48.470248 duration_in_ms=181.477
2019-04-26 21:29:48,472 [salt.state       :1780][INFO    ][4658] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:29:48.472318
2019-04-26 21:29:48,472 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-04-26 21:29:48,481 [salt.state       :300 ][INFO    ][4658] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-04-26 21:29:48,482 [salt.state       :1951][INFO    ][4658] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:29:48.482071 duration_in_ms=9.754
2019-04-26 21:29:48,482 [salt.state       :1780][INFO    ][4658] Running state [salt-minion] at time 21:29:48.482705
2019-04-26 21:29:48,482 [salt.state       :1813][INFO    ][4658] Executing state service.running for [salt-minion]
2019-04-26 21:29:48,483 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:48,517 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-04-26 21:29:48,533 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-04-26 21:29:48,548 [salt.state       :300 ][INFO    ][4658] The service salt-minion is already running
2019-04-26 21:29:48,549 [salt.state       :1951][INFO    ][4658] Completed state [salt-minion] at time 21:29:48.549210 duration_in_ms=66.504
2019-04-26 21:29:48,550 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains.d] at time 21:29:48.550244
2019-04-26 21:29:48,550 [salt.state       :1813][INFO    ][4658] Executing state file.directory for [/etc/salt/grains.d]
2019-04-26 21:29:48,551 [salt.state       :300 ][INFO    ][4658] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-04-26 21:29:48,551 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains.d] at time 21:29:48.551357 duration_in_ms=1.113
2019-04-26 21:29:48,551 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains] at time 21:29:48.551842
2019-04-26 21:29:48,552 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/grains]
2019-04-26 21:29:48,552 [salt.state       :300 ][INFO    ][4658] File /etc/salt/grains exists with proper permissions. No changes made.
2019-04-26 21:29:48,552 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains] at time 21:29:48.552609 duration_in_ms=0.768
2019-04-26 21:29:48,552 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains.d/placeholder] at time 21:29:48.552922
2019-04-26 21:29:48,553 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-04-26 21:29:48,553 [salt.state       :300 ][INFO    ][4658] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-04-26 21:29:48,553 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains.d/placeholder] at time 21:29:48.553655 duration_in_ms=0.733
2019-04-26 21:29:48,554 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains.d/sphinx] at time 21:29:48.553971
2019-04-26 21:29:48,554 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-04-26 21:29:48,565 [salt.state       :300 ][INFO    ][4658] File /etc/salt/grains.d/sphinx is in the correct state
2019-04-26 21:29:48,566 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains.d/sphinx] at time 21:29:48.566112 duration_in_ms=12.14
2019-04-26 21:29:48,568 [salt.state       :1780][INFO    ][4658] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.567978
2019-04-26 21:29:48,568 [salt.state       :1813][INFO    ][4658] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-04-26 21:29:48,568 [salt.state       :300 ][INFO    ][4658] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-04-26 21:29:48,568 [salt.state       :1951][INFO    ][4658] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.568725 duration_in_ms=0.748
2019-04-26 21:29:48,569 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains.d/dns_records] at time 21:29:48.569117
2019-04-26 21:29:48,569 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-04-26 21:29:48,583 [salt.state       :300 ][INFO    ][4658] File /etc/salt/grains.d/dns_records is in the correct state
2019-04-26 21:29:48,584 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains.d/dns_records] at time 21:29:48.584079 duration_in_ms=14.962
2019-04-26 21:29:48,584 [salt.state       :1780][INFO    ][4658] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.584833
2019-04-26 21:29:48,585 [salt.state       :1813][INFO    ][4658] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-04-26 21:29:48,585 [salt.state       :300 ][INFO    ][4658] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-04-26 21:29:48,585 [salt.state       :1951][INFO    ][4658] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.585584 duration_in_ms=0.751
2019-04-26 21:29:48,586 [salt.state       :1780][INFO    ][4658] Running state [/etc/salt/grains.d/salt] at time 21:29:48.585976
2019-04-26 21:29:48,586 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-04-26 21:29:48,601 [salt.state       :300 ][INFO    ][4658] File /etc/salt/grains.d/salt is in the correct state
2019-04-26 21:29:48,602 [salt.state       :1951][INFO    ][4658] Completed state [/etc/salt/grains.d/salt] at time 21:29:48.602046 duration_in_ms=16.07
2019-04-26 21:29:48,602 [salt.state       :1780][INFO    ][4658] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.602801
2019-04-26 21:29:48,603 [salt.state       :1813][INFO    ][4658] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-04-26 21:29:48,603 [salt.state       :300 ][INFO    ][4658] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-04-26 21:29:48,603 [salt.state       :1951][INFO    ][4658] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:29:48.603578 duration_in_ms=0.777
2019-04-26 21:29:48,605 [salt.state       :1780][INFO    ][4658] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:29:48.605168
2019-04-26 21:29:48,605 [salt.state       :1813][INFO    ][4658] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-04-26 21:29:48,605 [salt.state       :300 ][INFO    ][4658] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-04-26 21:29:48,606 [salt.state       :1951][INFO    ][4658] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:29:48.605967 duration_in_ms=0.799
2019-04-26 21:29:48,606 [salt.state       :1780][INFO    ][4658] Running state [mine.update] at time 21:29:48.606555
2019-04-26 21:29:48,606 [salt.state       :1813][INFO    ][4658] Executing state module.wait for [mine.update]
2019-04-26 21:29:48,607 [salt.state       :300 ][INFO    ][4658] No changes made for mine.update
2019-04-26 21:29:48,607 [salt.state       :1951][INFO    ][4658] Completed state [mine.update] at time 21:29:48.607263 duration_in_ms=0.708
2019-04-26 21:29:48,607 [salt.state       :1780][INFO    ][4658] Running state [ca-certificates] at time 21:29:48.607495
2019-04-26 21:29:48,607 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [ca-certificates]
2019-04-26 21:29:48,614 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-04-26 21:29:48,614 [salt.state       :1951][INFO    ][4658] Completed state [ca-certificates] at time 21:29:48.614290 duration_in_ms=6.794
2019-04-26 21:29:48,615 [salt.state       :1780][INFO    ][4658] Running state [update-ca-certificates] at time 21:29:48.615168
2019-04-26 21:29:48,615 [salt.state       :1813][INFO    ][4658] Executing state cmd.wait for [update-ca-certificates]
2019-04-26 21:29:48,615 [salt.state       :300 ][INFO    ][4658] No changes made for update-ca-certificates
2019-04-26 21:29:48,615 [salt.state       :1951][INFO    ][4658] Completed state [update-ca-certificates] at time 21:29:48.615904 duration_in_ms=0.735
2019-04-26 21:29:48,616 [salt.state       :1780][INFO    ][4658] Running state [iptables] at time 21:29:48.616117
2019-04-26 21:29:48,616 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [iptables]
2019-04-26 21:29:48,621 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-04-26 21:29:48,622 [salt.state       :1951][INFO    ][4658] Completed state [iptables] at time 21:29:48.622063 duration_in_ms=5.946
2019-04-26 21:29:48,622 [salt.state       :1780][INFO    ][4658] Running state [iptables-persistent] at time 21:29:48.622277
2019-04-26 21:29:48,622 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [iptables-persistent]
2019-04-26 21:29:48,628 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-04-26 21:29:48,628 [salt.state       :1951][INFO    ][4658] Completed state [iptables-persistent] at time 21:29:48.628233 duration_in_ms=5.956
2019-04-26 21:29:48,629 [salt.state       :1780][INFO    ][4658] Running state [iptables_modules_v4_load] at time 21:29:48.629064
2019-04-26 21:29:48,629 [salt.state       :1813][INFO    ][4658] Executing state kmod.present for [iptables_modules_v4_load]
2019-04-26 21:29:48,629 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'lsmod' in directory '/root'
2019-04-26 21:29:48,653 [salt.state       :300 ][INFO    ][4658] Kernel modules iptable_filter, ip_tables are already present
2019-04-26 21:29:48,653 [salt.state       :1951][INFO    ][4658] Completed state [iptables_modules_v4_load] at time 21:29:48.653749 duration_in_ms=24.684
2019-04-26 21:29:48,654 [salt.state       :1780][INFO    ][4658] Running state [/etc/iptables/rules.v4] at time 21:29:48.654786
2019-04-26 21:29:48,655 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/iptables/rules.v4]
2019-04-26 21:29:48,769 [salt.state       :300 ][INFO    ][4658] File /etc/iptables/rules.v4 is in the correct state
2019-04-26 21:29:48,770 [salt.state       :1951][INFO    ][4658] Completed state [/etc/iptables/rules.v4] at time 21:29:48.770078 duration_in_ms=115.292
2019-04-26 21:29:48,771 [salt.state       :1780][INFO    ][4658] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:29:48.771231
2019-04-26 21:29:48,771 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-04-26 21:29:48,772 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-04-26 21:29:48,792 [salt.state       :300 ][INFO    ][4658] onlyif execution failed
2019-04-26 21:29:48,792 [salt.state       :1951][INFO    ][4658] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:29:48.792573 duration_in_ms=21.341
2019-04-26 21:29:48,794 [salt.state       :1780][INFO    ][4658] Running state [netfilter-persistent] at time 21:29:48.793997
2019-04-26 21:29:48,794 [salt.state       :1813][INFO    ][4658] Executing state service.running for [netfilter-persistent]
2019-04-26 21:29:48,795 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:48,815 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-04-26 21:29:48,834 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-04-26 21:29:48,851 [salt.state       :300 ][INFO    ][4658] The service netfilter-persistent is already running
2019-04-26 21:29:48,852 [salt.state       :1951][INFO    ][4658] Completed state [netfilter-persistent] at time 21:29:48.852118 duration_in_ms=58.12
2019-04-26 21:29:48,853 [salt.state       :1780][INFO    ][4658] Running state [iptables_extra.remove_stale_tables] at time 21:29:48.853386
2019-04-26 21:29:48,853 [salt.state       :1813][INFO    ][4658] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-04-26 21:29:48,854 [salt.state       :300 ][INFO    ][4658] No changes made for iptables_extra.remove_stale_tables
2019-04-26 21:29:48,854 [salt.state       :1951][INFO    ][4658] Completed state [iptables_extra.remove_stale_tables] at time 21:29:48.854760 duration_in_ms=1.374
2019-04-26 21:29:48,855 [salt.state       :1780][INFO    ][4658] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:29:48.855135
2019-04-26 21:29:48,855 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-04-26 21:29:48,856 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-04-26 21:29:48,871 [salt.state       :300 ][INFO    ][4658] onlyif execution failed
2019-04-26 21:29:48,872 [salt.state       :1951][INFO    ][4658] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:29:48.872299 duration_in_ms=17.164
2019-04-26 21:29:48,873 [salt.state       :1780][INFO    ][4658] Running state [/etc/iptables/rules.v6] at time 21:29:48.873694
2019-04-26 21:29:48,874 [salt.state       :1813][INFO    ][4658] Executing state file.absent for [/etc/iptables/rules.v6]
2019-04-26 21:29:48,874 [salt.state       :300 ][INFO    ][4658] File /etc/iptables/rules.v6 is not present
2019-04-26 21:29:48,875 [salt.state       :1951][INFO    ][4658] Completed state [/etc/iptables/rules.v6] at time 21:29:48.875132 duration_in_ms=1.438
2019-04-26 21:29:48,876 [salt.state       :1780][INFO    ][4658] Running state [iptables_extra.flush_all] at time 21:29:48.876094
2019-04-26 21:29:48,876 [salt.state       :1813][INFO    ][4658] Executing state module.wait for [iptables_extra.flush_all]
2019-04-26 21:29:48,876 [salt.state       :300 ][INFO    ][4658] No changes made for iptables_extra.flush_all
2019-04-26 21:29:48,877 [salt.state       :1951][INFO    ][4658] Completed state [iptables_extra.flush_all] at time 21:29:48.877223 duration_in_ms=1.129
2019-04-26 21:29:48,881 [salt.minion      :1711][INFO    ][4658] Returning information for job: 20190426212941096628
2019-04-26 21:29:49,517 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426212949504224
2019-04-26 21:29:49,540 [salt.minion      :1432][INFO    ][4734] Starting a new job with PID 4734
2019-04-26 21:29:50,285 [salt.state       :915 ][INFO    ][4734] Loading fresh modules for state activity
2019-04-26 21:29:50,903 [salt.state       :1780][INFO    ][4734] Running state [maas-rack-controller] at time 21:29:50.903693
2019-04-26 21:29:50,904 [salt.state       :1813][INFO    ][4734] Executing state pkg.installed for [maas-rack-controller]
2019-04-26 21:29:50,904 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4734] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-26 21:29:50,981 [salt.state       :300 ][INFO    ][4734] All specified packages are already installed
2019-04-26 21:29:50,982 [salt.state       :1951][INFO    ][4734] Completed state [maas-rack-controller] at time 21:29:50.982021 duration_in_ms=78.329
2019-04-26 21:29:50,982 [salt.state       :1780][INFO    ][4734] Running state [ipmitool] at time 21:29:50.982283
2019-04-26 21:29:50,982 [salt.state       :1813][INFO    ][4734] Executing state pkg.installed for [ipmitool]
2019-04-26 21:29:50,987 [salt.state       :300 ][INFO    ][4734] All specified packages are already installed
2019-04-26 21:29:50,987 [salt.state       :1951][INFO    ][4734] Completed state [ipmitool] at time 21:29:50.987177 duration_in_ms=4.895
2019-04-26 21:29:50,989 [salt.state       :1780][INFO    ][4734] Running state [/etc/maas/rackd.conf] at time 21:29:50.989435
2019-04-26 21:29:50,989 [salt.state       :1813][INFO    ][4734] Executing state file.line for [/etc/maas/rackd.conf]
2019-04-26 21:29:50,990 [salt.state       :300 ][INFO    ][4734] No changes needed to be made
2019-04-26 21:29:50,990 [salt.state       :1951][INFO    ][4734] Completed state [/etc/maas/rackd.conf] at time 21:29:50.990579 duration_in_ms=1.145
2019-04-26 21:29:50,990 [salt.state       :1780][INFO    ][4734] Running state [/etc/maas/rackd.conf] at time 21:29:50.990749
2019-04-26 21:29:50,990 [salt.state       :1813][INFO    ][4734] Executing state file.managed for [/etc/maas/rackd.conf]
2019-04-26 21:29:50,991 [salt.loaded.int.states.file:2298][WARNING ][4734] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-04-26 21:29:50,991 [salt.state       :300 ][INFO    ][4734] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-04-26 21:29:50,991 [salt.state       :1951][INFO    ][4734] Completed state [/etc/maas/rackd.conf] at time 21:29:50.991671 duration_in_ms=0.922
2019-04-26 21:29:50,992 [salt.state       :1780][INFO    ][4734] Running state [maas-rackd] at time 21:29:50.992368
2019-04-26 21:29:50,992 [salt.state       :1813][INFO    ][4734] Executing state service.running for [maas-rackd]
2019-04-26 21:29:50,993 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4734] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:51,026 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4734] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-04-26 21:29:51,042 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4734] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-04-26 21:29:51,058 [salt.state       :300 ][INFO    ][4734] The service maas-rackd is already running
2019-04-26 21:29:51,058 [salt.state       :1951][INFO    ][4734] Completed state [maas-rackd] at time 21:29:51.058922 duration_in_ms=66.553
2019-04-26 21:29:51,060 [salt.minion      :1711][INFO    ][4734] Returning information for job: 20190426212949504224
2019-04-26 21:29:51,639 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426212951626320
2019-04-26 21:29:51,662 [salt.minion      :1432][INFO    ][4757] Starting a new job with PID 4757
2019-04-26 21:29:52,403 [salt.state       :915 ][INFO    ][4757] Loading fresh modules for state activity
2019-04-26 21:29:53,095 [salt.state       :1780][INFO    ][4757] Running state [maas-region-controller] at time 21:29:53.095397
2019-04-26 21:29:53,095 [salt.state       :1813][INFO    ][4757] Executing state pkg.installed for [maas-region-controller]
2019-04-26 21:29:53,096 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-26 21:29:53,175 [salt.state       :300 ][INFO    ][4757] All specified packages are already installed
2019-04-26 21:29:53,175 [salt.state       :1951][INFO    ][4757] Completed state [maas-region-controller] at time 21:29:53.175616 duration_in_ms=80.218
2019-04-26 21:29:53,175 [salt.state       :1780][INFO    ][4757] Running state [python-oauth] at time 21:29:53.175873
2019-04-26 21:29:53,176 [salt.state       :1813][INFO    ][4757] Executing state pkg.installed for [python-oauth]
2019-04-26 21:29:53,181 [salt.state       :300 ][INFO    ][4757] All specified packages are already installed
2019-04-26 21:29:53,181 [salt.state       :1951][INFO    ][4757] Completed state [python-oauth] at time 21:29:53.181180 duration_in_ms=5.307
2019-04-26 21:29:53,183 [salt.state       :1780][INFO    ][4757] Running state [/etc/maas/regiond.conf] at time 21:29:53.183667
2019-04-26 21:29:53,183 [salt.state       :1813][INFO    ][4757] Executing state file.replace for [/etc/maas/regiond.conf]
2019-04-26 21:29:53,237 [salt.state       :300 ][INFO    ][4757] No changes needed to be made
2019-04-26 21:29:53,238 [salt.state       :1951][INFO    ][4757] Completed state [/etc/maas/regiond.conf] at time 21:29:53.238228 duration_in_ms=54.56
2019-04-26 21:29:53,239 [salt.state       :1780][INFO    ][4757] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:29:53.238964
2019-04-26 21:29:53,239 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-04-26 21:29:53,314 [salt.state       :300 ][INFO    ][4757] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-04-26 21:29:53,315 [salt.state       :1951][INFO    ][4757] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:29:53.315144 duration_in_ms=76.181
2019-04-26 21:29:53,315 [salt.state       :1780][INFO    ][4757] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:29:53.315748
2019-04-26 21:29:53,316 [salt.state       :1813][INFO    ][4757] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-26 21:29:53,335 [salt.state       :300 ][INFO    ][4757] No changes needed to be made
2019-04-26 21:29:53,335 [salt.state       :1951][INFO    ][4757] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:29:53.335512 duration_in_ms=19.763
2019-04-26 21:29:53,336 [salt.state       :1780][INFO    ][4757] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:29:53.336271
2019-04-26 21:29:53,336 [salt.state       :1813][INFO    ][4757] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-26 21:29:53,370 [salt.state       :300 ][INFO    ][4757] No changes needed to be made
2019-04-26 21:29:53,371 [salt.state       :1951][INFO    ][4757] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:29:53.371228 duration_in_ms=34.957
2019-04-26 21:29:53,372 [salt.state       :1780][INFO    ][4757] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:29:53.371961
2019-04-26 21:29:53,372 [salt.state       :1813][INFO    ][4757] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-04-26 21:29:53,405 [salt.state       :300 ][INFO    ][4757] No changes needed to be made
2019-04-26 21:29:53,406 [salt.state       :1951][INFO    ][4757] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:29:53.406190 duration_in_ms=34.23
2019-04-26 21:29:53,406 [salt.state       :1780][INFO    ][4757] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:29:53.406830
2019-04-26 21:29:53,407 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-04-26 21:29:53,420 [salt.state       :300 ][INFO    ][4757] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-04-26 21:29:53,421 [salt.state       :1951][INFO    ][4757] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:29:53.421197 duration_in_ms=14.368
2019-04-26 21:29:53,422 [salt.state       :1780][INFO    ][4757] Running state [a2enmod headers] at time 21:29:53.422843
2019-04-26 21:29:53,423 [salt.state       :1813][INFO    ][4757] Executing state cmd.run for [a2enmod headers]
2019-04-26 21:29:53,424 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command 'a2enmod headers' in directory '/root'
2019-04-26 21:29:53,504 [salt.state       :300 ][INFO    ][4757] {'pid': 4777, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-04-26 21:29:53,505 [salt.state       :1951][INFO    ][4757] Completed state [a2enmod headers] at time 21:29:53.505733 duration_in_ms=82.886
2019-04-26 21:29:53,506 [salt.state       :1780][INFO    ][4757] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:29:53.506874
2019-04-26 21:29:53,507 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-04-26 21:29:53,531 [salt.state       :300 ][INFO    ][4757] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-04-26 21:29:53,532 [salt.state       :1951][INFO    ][4757] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:29:53.532010 duration_in_ms=25.135
2019-04-26 21:29:53,533 [salt.state       :1780][INFO    ][4757] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:29:53.533176
2019-04-26 21:29:53,533 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-04-26 21:29:53,620 [salt.state       :300 ][INFO    ][4757] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-04-26 21:29:53,621 [salt.state       :1951][INFO    ][4757] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:29:53.621254 duration_in_ms=88.077
2019-04-26 21:29:53,622 [salt.state       :1780][INFO    ][4757] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:29:53.622138
2019-04-26 21:29:53,622 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-04-26 21:29:53,698 [salt.state       :300 ][INFO    ][4757] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-04-26 21:29:53,698 [salt.state       :1951][INFO    ][4757] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:29:53.698706 duration_in_ms=76.568
2019-04-26 21:29:53,699 [salt.state       :1780][INFO    ][4757] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:29:53.699361
2019-04-26 21:29:53,699 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-04-26 21:29:53,770 [salt.state       :300 ][INFO    ][4757] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-04-26 21:29:53,770 [salt.state       :1951][INFO    ][4757] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:29:53.770491 duration_in_ms=71.116
2019-04-26 21:29:53,770 [salt.state       :1780][INFO    ][4757] Running state [/root/.pgpass] at time 21:29:53.770822
2019-04-26 21:29:53,771 [salt.state       :1813][INFO    ][4757] Executing state file.managed for [/root/.pgpass]
2019-04-26 21:29:53,824 [salt.state       :300 ][INFO    ][4757] File /root/.pgpass is in the correct state
2019-04-26 21:29:53,824 [salt.state       :1951][INFO    ][4757] Completed state [/root/.pgpass] at time 21:29:53.824282 duration_in_ms=53.46
2019-04-26 21:29:53,830 [salt.state       :1780][INFO    ][4757] Running state [maas-region syncdb --noinput] at time 21:29:53.830133
2019-04-26 21:29:53,830 [salt.state       :1813][INFO    ][4757] Executing state cmd.run for [maas-region syncdb --noinput]
2019-04-26 21:29:53,831 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-04-26 21:29:55,852 [salt.state       :300 ][INFO    ][4757] {'pid': 4790, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sites, piston3, contenttypes, metadataserver, maasserver, sessions, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-04-26 21:29:55,853 [salt.state       :1951][INFO    ][4757] Completed state [maas-region syncdb --noinput] at time 21:29:55.852995 duration_in_ms=2022.862
2019-04-26 21:29:55,853 [salt.state       :2022][WARNING ][4757] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-26 21:29:55,856 [salt.state       :1780][INFO    ][4757] Running state [maas-regiond] at time 21:29:55.856082
2019-04-26 21:29:55,856 [salt.state       :1813][INFO    ][4757] Executing state service.running for [maas-regiond]
2019-04-26 21:29:55,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:55,896 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-04-26 21:29:55,915 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-04-26 21:29:55,933 [salt.state       :300 ][INFO    ][4757] The service maas-regiond is already running
2019-04-26 21:29:55,933 [salt.state       :1951][INFO    ][4757] Completed state [maas-regiond] at time 21:29:55.933783 duration_in_ms=77.701
2019-04-26 21:29:55,936 [salt.state       :1780][INFO    ][4757] Running state [bind9] at time 21:29:55.936451
2019-04-26 21:29:55,937 [salt.state       :1813][INFO    ][4757] Executing state service.running for [bind9]
2019-04-26 21:29:55,938 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:55,957 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-04-26 21:29:55,975 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-04-26 21:29:55,992 [salt.state       :300 ][INFO    ][4757] The service bind9 is already running
2019-04-26 21:29:55,993 [salt.state       :1951][INFO    ][4757] Completed state [bind9] at time 21:29:55.993429 duration_in_ms=56.977
2019-04-26 21:29:55,996 [salt.state       :1780][INFO    ][4757] Running state [apache2] at time 21:29:55.996098
2019-04-26 21:29:55,996 [salt.state       :1813][INFO    ][4757] Executing state service.running for [apache2]
2019-04-26 21:29:55,997 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-04-26 21:29:56,016 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-04-26 21:29:56,033 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-04-26 21:29:56,055 [salt.state       :300 ][INFO    ][4757] The service apache2 is already running
2019-04-26 21:29:56,055 [salt.state       :1951][INFO    ][4757] Completed state [apache2] at time 21:29:56.055868 duration_in_ms=59.77
2019-04-26 21:29:56,058 [salt.state       :1780][INFO    ][4757] Running state [maasng.wait_for_http_code] at time 21:29:56.058413
2019-04-26 21:29:56,058 [salt.state       :1813][INFO    ][4757] Executing state module.run for [maasng.wait_for_http_code]
2019-04-26 21:29:56,059 [salt.utils.decorators:613 ][WARNING ][4757] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:29:56,185 [salt.state       :300 ][INFO    ][4757] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-04-26 21:29:56,185 [salt.state       :1951][INFO    ][4757] Completed state [maasng.wait_for_http_code] at time 21:29:56.185837 duration_in_ms=127.423
2019-04-26 21:29:56,187 [salt.state       :1780][INFO    ][4757] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:29:56.187195
2019-04-26 21:29:56,187 [salt.state       :1813][INFO    ][4757] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-04-26 21:29:56,188 [salt.state       :300 ][INFO    ][4757] /var/lib/maas/.setup_admin exists
2019-04-26 21:29:56,188 [salt.state       :1951][INFO    ][4757] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:29:56.188757 duration_in_ms=1.562
2019-04-26 21:29:56,189 [salt.state       :1780][INFO    ][4757] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:29:56.189837
2019-04-26 21:29:56,190 [salt.state       :1813][INFO    ][4757] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:29:56,191 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4757] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:29:57,655 [salt.state       :300 ][INFO    ][4757] {'pid': 4811, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:29:57,656 [salt.state       :1951][INFO    ][4757] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:29:57.655945 duration_in_ms=1466.108
2019-04-26 21:29:57,666 [salt.state       :1780][INFO    ][4757] Running state [maas_region_boot_source_resources_mirror] at time 21:29:57.666403
2019-04-26 21:29:57,666 [salt.state       :1813][INFO    ][4757] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-04-26 21:29:57,776 [salt.state       :300 ][INFO    ][4757] {'changes': {}}
2019-04-26 21:29:57,776 [salt.state       :1951][INFO    ][4757] Completed state [maas_region_boot_source_resources_mirror] at time 21:29:57.776753 duration_in_ms=110.35
2019-04-26 21:29:57,777 [salt.state       :1780][INFO    ][4757] Running state [maasng.boot_resources_import] at time 21:29:57.777904
2019-04-26 21:29:57,778 [salt.state       :1813][INFO    ][4757] Executing state module.run for [maasng.boot_resources_import]
2019-04-26 21:29:57,779 [salt.utils.decorators:613 ][WARNING ][4757] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:29:57,884 [salt.loaded.ext.module.maasng:1600][INFO    ][4757] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-04-26 21:30:02,949 [salt.loaded.ext.module.maasng:1600][INFO    ][4757] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-04-26 21:30:06,676 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213006663390
2019-04-26 21:30:06,699 [salt.minion      :1432][INFO    ][4851] Starting a new job with PID 4851
2019-04-26 21:30:06,721 [salt.minion      :1711][INFO    ][4851] Returning information for job: 20190426213006663390
2019-04-26 21:30:08,007 [salt.loaded.ext.module.maasng:1600][INFO    ][4757] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-04-26 21:30:13,121 [salt.state       :300 ][INFO    ][4757] {'ret': True}
2019-04-26 21:30:13,121 [salt.state       :1951][INFO    ][4757] Completed state [maasng.boot_resources_import] at time 21:30:13.121609 duration_in_ms=15343.704
2019-04-26 21:30:13,122 [salt.state       :1780][INFO    ][4757] Running state [maas_region_boot_sources_selection_xenial] at time 21:30:13.122810
2019-04-26 21:30:13,123 [salt.state       :1813][INFO    ][4757] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-04-26 21:30:13,330 [salt.state       :300 ][INFO    ][4757] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-04-26 21:30:13,330 [salt.state       :1951][INFO    ][4757] Completed state [maas_region_boot_sources_selection_xenial] at time 21:30:13.330589 duration_in_ms=207.773
2019-04-26 21:30:13,332 [salt.state       :1780][INFO    ][4757] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:30:13.331998
2019-04-26 21:30:13,332 [salt.state       :1813][INFO    ][4757] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-04-26 21:30:13,333 [salt.utils.decorators:613 ][WARNING ][4757] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:30:13,333 [salt.loaded.ext.module.maasng:1771][INFO    ][4757] boot-sources sync initiated for ALL Rack's
2019-04-26 21:30:14,443 [salt.state       :300 ][INFO    ][4757] {'ret': True}
2019-04-26 21:30:14,444 [salt.state       :1951][INFO    ][4757] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:30:14.444000 duration_in_ms=1112.001
2019-04-26 21:30:14,446 [salt.state       :1780][INFO    ][4757] Running state [maas.process_maas_config] at time 21:30:14.446143
2019-04-26 21:30:14,446 [salt.state       :1813][INFO    ][4757] Executing state module.run for [maas.process_maas_config]
2019-04-26 21:30:14,447 [salt.utils.decorators:613 ][WARNING ][4757] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:30:14,448 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=enable_http_proxy value=True
2019-04-26 21:30:14,511 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=upstream_dns value=8.8.8.8
2019-04-26 21:30:14,575 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=commissioning_distro_series value=xenial
2019-04-26 21:30:18,863 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=default_osystem value=ubuntu
2019-04-26 21:30:18,939 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=active_discovery_interval value=600
2019-04-26 21:30:18,998 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=dnssec_validation value=no
2019-04-26 21:30:19,057 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=maas_name value=mas01
2019-04-26 21:30:19,111 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=network_discovery value=enabled
2019-04-26 21:30:19,219 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=enable_third_party_drivers value=True
2019-04-26 21:30:19,273 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=default_storage_layout value=lvm
2019-04-26 21:30:19,365 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=ntp_external_only value=True
2019-04-26 21:30:19,426 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=disk_erase_with_secure_erase value=False
2019-04-26 21:30:19,486 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=default_distro_series value=xenial
2019-04-26 21:30:19,566 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-04-26 21:30:19,702 [salt.state       :300 ][INFO    ][4757] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-04-26 21:30:19,703 [salt.state       :1951][INFO    ][4757] Completed state [maas.process_maas_config] at time 21:30:19.702947 duration_in_ms=5256.804
2019-04-26 21:30:19,704 [salt.state       :1780][INFO    ][4757] Running state [pxe_admin] at time 21:30:19.704096
2019-04-26 21:30:19,704 [salt.state       :1813][INFO    ][4757] Executing state maasng.fabric_present for [pxe_admin]
2019-04-26 21:30:19,786 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-26 21:30:19,863 [salt.loaded.ext.module.maasng:1008][WARNING ][4757] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-04-26 21:30:19,863 [salt.loaded.ext.module.maasng:1011][WARNING ][4757] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-04-26 21:30:19,929 [salt.state       :300 ][INFO    ][4757] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-04-26 21:30:19,930 [salt.state       :1951][INFO    ][4757] Completed state [pxe_admin] at time 21:30:19.930275 duration_in_ms=226.178
2019-04-26 21:30:19,930 [salt.state       :1780][INFO    ][4757] Running state [vlan 0] at time 21:30:19.930878
2019-04-26 21:30:19,931 [salt.state       :1813][INFO    ][4757] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-26 21:30:20,013 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-26 21:30:20,135 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'xrgrt6', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-26 21:30:20,435 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-26 21:30:20,513 [salt.state       :300 ][INFO    ][4757] {'new': 'Vlan untagged was updated'}
2019-04-26 21:30:20,514 [salt.state       :1951][INFO    ][4757] Completed state [vlan 0] at time 21:30:20.513998 duration_in_ms=583.12
2019-04-26 21:30:20,515 [salt.state       :1780][INFO    ][4757] Running state [192.168.11.0/24] at time 21:30:20.515245
2019-04-26 21:30:20,515 [salt.state       :1813][INFO    ][4757] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-04-26 21:30:20,816 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-26 21:30:20,816 [salt.loaded.ext.module.maasng:1235][WARNING ][4757] Ignoring parameter vlan:0
2019-04-26 21:30:20,894 [salt.state       :300 ][INFO    ][4757] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-04-26 21:30:20,894 [salt.state       :1951][INFO    ][4757] Completed state [192.168.11.0/24] at time 21:30:20.894656 duration_in_ms=379.409
2019-04-26 21:30:20,896 [salt.state       :1780][INFO    ][4757] Running state [maas_create_iprange_1] at time 21:30:20.895959
2019-04-26 21:30:20,896 [salt.state       :1813][INFO    ][4757] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-04-26 21:30:20,955 [salt.state       :300 ][INFO    ][4757] Iprange maas_create_iprange_1 already exist.
2019-04-26 21:30:20,956 [salt.state       :1951][INFO    ][4757] Completed state [maas_create_iprange_1] at time 21:30:20.956292 duration_in_ms=60.334
2019-04-26 21:30:20,956 [salt.state       :1780][INFO    ][4757] Running state [vlan 0] at time 21:30:20.956657
2019-04-26 21:30:20,957 [salt.state       :1813][INFO    ][4757] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-26 21:30:21,010 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-26 21:30:21,100 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-26 21:30:21,315 [salt.loaded.ext.module.maasng:945 ][INFO    ][4757] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'xrgrt6', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-04-26 21:30:21,418 [salt.state       :300 ][INFO    ][4757] {'new': 'Vlan untagged was updated'}
2019-04-26 21:30:21,418 [salt.state       :1951][INFO    ][4757] Completed state [vlan 0] at time 21:30:21.418863 duration_in_ms=462.204
2019-04-26 21:30:21,419 [salt.state       :1780][INFO    ][4757] Running state [opnfv] at time 21:30:21.419823
2019-04-26 21:30:21,420 [salt.state       :1813][INFO    ][4757] Executing state maasng.sshkey_present for [opnfv]
2019-04-26 21:30:21,464 [salt.loaded.ext.module.maasng:1903][INFO    ][4757] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-04-26 21:30:21,465 [salt.state       :300 ][INFO    ][4757] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-04-26 21:30:21,465 [salt.state       :1951][INFO    ][4757] Completed state [opnfv] at time 21:30:21.465829 duration_in_ms=46.006
2019-04-26 21:30:21,466 [salt.state       :1780][INFO    ][4757] Running state [maas.process_tags] at time 21:30:21.466696
2019-04-26 21:30:21,467 [salt.state       :1813][INFO    ][4757] Executing state module.run for [maas.process_tags]
2019-04-26 21:30:21,467 [salt.utils.decorators:613 ][WARNING ][4757] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:30:21,513 [salt.loaded.ext.module.maas:92  ][INFO    ][4757] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-04-26 21:30:21,573 [salt.state       :300 ][INFO    ][4757] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-04-26 21:30:21,574 [salt.state       :1951][INFO    ][4757] Completed state [maas.process_tags] at time 21:30:21.573965 duration_in_ms=107.269
2019-04-26 21:30:21,578 [salt.minion      :1711][INFO    ][4757] Returning information for job: 20190426212951626320
2019-04-26 21:30:22,155 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426213022145990
2019-04-26 21:30:22,175 [salt.minion      :1432][INFO    ][5243] Starting a new job with PID 5243
2019-04-26 21:30:25,784 [salt.state       :915 ][INFO    ][5243] Loading fresh modules for state activity
2019-04-26 21:30:25,880 [salt.state       :1780][INFO    ][5243] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:25.880682
2019-04-26 21:30:25,881 [salt.state       :1813][INFO    ][5243] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:30:25,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5243] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:30:27,290 [salt.state       :300 ][INFO    ][5243] {'pid': 5266, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:30:27,291 [salt.state       :1951][INFO    ][5243] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:30:27.291293 duration_in_ms=1410.612
2019-04-26 21:30:27,292 [salt.state       :1780][INFO    ][5243] Running state [maas.process_machines] at time 21:30:27.292479
2019-04-26 21:30:27,292 [salt.state       :1813][INFO    ][5243] Executing state module.run for [maas.process_machines]
2019-04-26 21:30:27,293 [salt.utils.decorators:613 ][WARNING ][5243] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:30:27,799 [salt.loaded.ext.module.maas:412 ][WARNING ][5243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:30:27,800 [salt.loaded.ext.module.maas:92  ][INFO    ][5243] 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=7eq4sb architecture=amd64/generic power_parameters_power_user=admin
2019-04-26 21:30:29,066 [salt.loaded.ext.module.maas:412 ][WARNING ][5243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:30:29,067 [salt.loaded.ext.module.maas:92  ][INFO    ][5243] 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=yendf7 architecture=amd64/generic power_parameters_power_user=admin
2019-04-26 21:30:30,323 [salt.loaded.ext.module.maas:412 ][WARNING ][5243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:30:30,324 [salt.loaded.ext.module.maas:92  ][INFO    ][5243] 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=scfywa architecture=amd64/generic power_parameters_power_user=admin
2019-04-26 21:30:31,532 [salt.loaded.ext.module.maas:412 ][WARNING ][5243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-26 21:30:31,533 [salt.loaded.ext.module.maas:92  ][INFO    ][5243] 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=r8q8pg architecture=amd64/generic power_parameters_power_user=admin
2019-04-26 21:30:32,616 [salt.state       :300 ][INFO    ][5243] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-04-26 21:30:32,616 [salt.state       :1951][INFO    ][5243] Completed state [maas.process_machines] at time 21:30:32.616555 duration_in_ms=5324.074
2019-04-26 21:30:32,620 [salt.minion      :1711][INFO    ][5243] Returning information for job: 20190426213022145990
2019-04-26 21:31:05,345 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426213105333018
2019-04-26 21:31:05,368 [salt.minion      :1432][INFO    ][5478] Starting a new job with PID 5478
2019-04-26 21:31:09,105 [salt.state       :915 ][INFO    ][5478] Loading fresh modules for state activity
2019-04-26 21:31:09,179 [salt.state       :1780][INFO    ][5478] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:09.179712
2019-04-26 21:31:09,180 [salt.state       :1813][INFO    ][5478] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:31:09,182 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5478] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:31:10,634 [salt.state       :300 ][INFO    ][5478] {'pid': 5511, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:31:10,635 [salt.state       :1951][INFO    ][5478] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:10.635361 duration_in_ms=1455.65
2019-04-26 21:31:10,636 [salt.state       :1780][INFO    ][5478] Running state [maas.wait_for_machine_status] at time 21:31:10.636864
2019-04-26 21:31:10,637 [salt.state       :1813][INFO    ][5478] Executing state module.run for [maas.wait_for_machine_status]
2019-04-26 21:31:10,637 [salt.utils.decorators:613 ][WARNING ][5478] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:31:12,323 [salt.loaded.ext.module.maas:993 ][INFO    ][5478] Machine scfywa mark broken
2019-04-26 21:31:12,973 [salt.loaded.ext.module.maas:996 ][INFO    ][5478] Machine scfywa mark fixed
2019-04-26 21:31:14,144 [salt.loaded.ext.module.maas:684 ][INFO    ][5478] deploymachines hwe_kernel=hwe-16.04 system_id=scfywa distro_series=xenial
2019-04-26 21:31:17,720 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1492.92173004s left)
2019-04-26 21:31:20,397 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213120384581
2019-04-26 21:31:20,419 [salt.minion      :1432][INFO    ][5576] Starting a new job with PID 5576
2019-04-26 21:31:20,444 [salt.minion      :1711][INFO    ][5576] Returning information for job: 20190426213120384581
2019-04-26 21:31:50,156 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1460.48522401s left)
2019-04-26 21:31:50,641 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213150587676
2019-04-26 21:31:50,663 [salt.minion      :1432][INFO    ][5602] Starting a new job with PID 5602
2019-04-26 21:31:50,687 [salt.minion      :1711][INFO    ][5602] Returning information for job: 20190426213150587676
2019-04-26 21:32:20,684 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213220671270
2019-04-26 21:32:20,707 [salt.minion      :1432][INFO    ][5653] Starting a new job with PID 5653
2019-04-26 21:32:20,731 [salt.minion      :1711][INFO    ][5653] Returning information for job: 20190426213220671270
2019-04-26 21:32:22,607 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1428.03476095s left)
2019-04-26 21:32:50,733 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213250720220
2019-04-26 21:32:50,756 [salt.minion      :1432][INFO    ][5670] Starting a new job with PID 5670
2019-04-26 21:32:50,782 [salt.minion      :1711][INFO    ][5670] Returning information for job: 20190426213250720220
2019-04-26 21:32:55,136 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1395.50494099s left)
2019-04-26 21:33:20,787 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213320775547
2019-04-26 21:33:20,810 [salt.minion      :1432][INFO    ][5775] Starting a new job with PID 5775
2019-04-26 21:33:20,836 [salt.minion      :1711][INFO    ][5775] Returning information for job: 20190426213320775547
2019-04-26 21:33:27,477 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1363.16439199s left)
2019-04-26 21:33:50,841 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213350828233
2019-04-26 21:33:50,864 [salt.minion      :1432][INFO    ][5799] Starting a new job with PID 5799
2019-04-26 21:33:50,891 [salt.minion      :1711][INFO    ][5799] Returning information for job: 20190426213350828233
2019-04-26 21:33:59,893 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1330.74829006s left)
2019-04-26 21:34:20,901 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213420889064
2019-04-26 21:34:20,924 [salt.minion      :1432][INFO    ][6013] Starting a new job with PID 6013
2019-04-26 21:34:20,949 [salt.minion      :1711][INFO    ][6013] Returning information for job: 20190426213420889064
2019-04-26 21:34:32,312 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1298.32927394s left)
2019-04-26 21:34:50,959 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213450946430
2019-04-26 21:34:50,981 [salt.minion      :1432][INFO    ][6034] Starting a new job with PID 6034
2019-04-26 21:34:51,007 [salt.minion      :1711][INFO    ][6034] Returning information for job: 20190426213450946430
2019-04-26 21:35:04,924 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1265.71776605s left)
2019-04-26 21:35:21,029 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213521016274
2019-04-26 21:35:21,052 [salt.minion      :1432][INFO    ][6116] Starting a new job with PID 6116
2019-04-26 21:35:21,079 [salt.minion      :1711][INFO    ][6116] Returning information for job: 20190426213521016274
2019-04-26 21:35:37,296 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1233.34589505s left)
2019-04-26 21:35:51,099 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213551086258
2019-04-26 21:35:51,118 [salt.minion      :1432][INFO    ][6136] Starting a new job with PID 6136
2019-04-26 21:35:51,143 [salt.minion      :1711][INFO    ][6136] Returning information for job: 20190426213551086258
2019-04-26 21:36:09,193 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1201.44840002s left)
2019-04-26 21:36:21,166 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213621153718
2019-04-26 21:36:21,189 [salt.minion      :1432][INFO    ][6298] Starting a new job with PID 6298
2019-04-26 21:36:21,215 [salt.minion      :1711][INFO    ][6298] Returning information for job: 20190426213621153718
2019-04-26 21:36:41,672 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1168.96898699s left)
2019-04-26 21:36:51,242 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213651229544
2019-04-26 21:36:51,265 [salt.minion      :1432][INFO    ][6323] Starting a new job with PID 6323
2019-04-26 21:36:51,291 [salt.minion      :1711][INFO    ][6323] Returning information for job: 20190426213651229544
2019-04-26 21:37:13,900 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1136.7410481s left)
2019-04-26 21:37:21,330 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213721317281
2019-04-26 21:37:21,352 [salt.minion      :1432][INFO    ][6445] Starting a new job with PID 6445
2019-04-26 21:37:21,378 [salt.minion      :1711][INFO    ][6445] Returning information for job: 20190426213721317281
2019-04-26 21:37:46,006 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1104.63554811s left)
2019-04-26 21:37:51,417 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213751404775
2019-04-26 21:37:51,440 [salt.minion      :1432][INFO    ][6464] Starting a new job with PID 6464
2019-04-26 21:37:51,464 [salt.minion      :1711][INFO    ][6464] Returning information for job: 20190426213751404775
2019-04-26 21:38:18,412 [salt.loaded.ext.module.maas:1023][INFO    ][5478] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1072.22940993s left)
2019-04-26 21:38:21,515 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command saltutil.find_job with jid 20190426213821502043
2019-04-26 21:38:21,538 [salt.minion      :1432][INFO    ][6572] Starting a new job with PID 6572
2019-04-26 21:38:21,565 [salt.minion      :1711][INFO    ][6572] Returning information for job: 20190426213821502043
2019-04-26 21:38:51,089 [salt.state       :300 ][INFO    ][5478] {'ret': True}
2019-04-26 21:38:51,090 [salt.state       :1951][INFO    ][5478] Completed state [maas.wait_for_machine_status] at time 21:38:51.090328 duration_in_ms=460453.46
2019-04-26 21:38:51,094 [salt.minion      :1711][INFO    ][5478] Returning information for job: 20190426213105333018
2019-04-26 21:38:51,740 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426213851726712
2019-04-26 21:38:51,761 [salt.minion      :1432][INFO    ][6616] Starting a new job with PID 6616
2019-04-26 21:38:55,421 [salt.state       :915 ][INFO    ][6616] Loading fresh modules for state activity
2019-04-26 21:38:55,508 [salt.state       :1780][INFO    ][6616] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:55.508252
2019-04-26 21:38:55,508 [salt.state       :1813][INFO    ][6616] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:38:55,509 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6616] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:38:56,898 [salt.state       :300 ][INFO    ][6616] {'pid': 6624, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:38:56,899 [salt.state       :1951][INFO    ][6616] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:56.899053 duration_in_ms=1390.801
2019-04-26 21:38:56,900 [salt.state       :1780][INFO    ][6616] Running state [maas_machines_storage_cmp002_lvm] at time 21:38:56.900367
2019-04-26 21:38:56,900 [salt.state       :1813][INFO    ][6616] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-26 21:38:57,540 [salt.state       :300 ][INFO    ][6616] Machine cmp002 is not in Ready state.
2019-04-26 21:38:57,540 [salt.state       :1951][INFO    ][6616] Completed state [maas_machines_storage_cmp002_lvm] at time 21:38:57.540561 duration_in_ms=640.193
2019-04-26 21:38:57,541 [salt.state       :1780][INFO    ][6616] Running state [maas_machines_storage_cmp001_lvm] at time 21:38:57.541118
2019-04-26 21:38:57,541 [salt.state       :1813][INFO    ][6616] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-26 21:38:58,145 [salt.state       :300 ][INFO    ][6616] Machine cmp001 is not in Ready state.
2019-04-26 21:38:58,145 [salt.state       :1951][INFO    ][6616] Completed state [maas_machines_storage_cmp001_lvm] at time 21:38:58.145830 duration_in_ms=604.711
2019-04-26 21:38:58,150 [salt.minion      :1711][INFO    ][6616] Returning information for job: 20190426213851726712
2019-04-26 21:38:58,789 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426213858775258
2019-04-26 21:38:58,811 [salt.minion      :1432][INFO    ][6634] Starting a new job with PID 6634
2019-04-26 21:38:59,523 [salt.state       :915 ][INFO    ][6634] Loading fresh modules for state activity
2019-04-26 21:38:59,612 [salt.state       :1780][INFO    ][6634] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:38:59.612112
2019-04-26 21:38:59,612 [salt.state       :1813][INFO    ][6634] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:38:59,614 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6634] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:39:01,065 [salt.state       :300 ][INFO    ][6634] {'pid': 6641, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:39:01,066 [salt.state       :1951][INFO    ][6634] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:39:01.066324 duration_in_ms=1454.213
2019-04-26 21:39:01,067 [salt.state       :1780][INFO    ][6634] Running state [maas.deploy_machines] at time 21:39:01.067514
2019-04-26 21:39:01,067 [salt.state       :1813][INFO    ][6634] Executing state module.run for [maas.deploy_machines]
2019-04-26 21:39:01,068 [salt.utils.decorators:613 ][WARNING ][6634] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:39:01,749 [salt.state       :300 ][INFO    ][6634] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-04-26 21:39:01,750 [salt.state       :1951][INFO    ][6634] Completed state [maas.deploy_machines] at time 21:39:01.750318 duration_in_ms=682.802
2019-04-26 21:39:01,754 [salt.minion      :1711][INFO    ][6634] Returning information for job: 20190426213858775258
2019-04-26 21:39:02,318 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command state.apply with jid 20190426213902303261
2019-04-26 21:39:02,335 [salt.minion      :1432][INFO    ][6665] Starting a new job with PID 6665
2019-04-26 21:39:03,040 [salt.state       :915 ][INFO    ][6665] Loading fresh modules for state activity
2019-04-26 21:39:03,087 [salt.state       :1780][INFO    ][6665] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:39:03.087398
2019-04-26 21:39:03,087 [salt.state       :1813][INFO    ][6665] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-26 21:39:03,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6665] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-26 21:39:04,404 [salt.state       :300 ][INFO    ][6665] {'pid': 6672, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-26 21:39:04,405 [salt.state       :1951][INFO    ][6665] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:39:04.405558 duration_in_ms=1318.159
2019-04-26 21:39:04,408 [salt.state       :1780][INFO    ][6665] Running state [maas.wait_for_machine_status] at time 21:39:04.407937
2019-04-26 21:39:04,408 [salt.state       :1813][INFO    ][6665] Executing state module.run for [maas.wait_for_machine_status]
2019-04-26 21:39:04,409 [salt.utils.decorators:613 ][WARNING ][6665] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-26 21:39:06,653 [salt.state       :300 ][INFO    ][6665] {'ret': True}
2019-04-26 21:39:06,653 [salt.state       :1951][INFO    ][6665] Completed state [maas.wait_for_machine_status] at time 21:39:06.653841 duration_in_ms=2245.903
2019-04-26 21:39:06,657 [salt.minion      :1711][INFO    ][6665] Returning information for job: 20190426213902303261
2019-04-26 22:09:04,047 [salt.utils.schedule:1377][INFO    ][31017] Running scheduled job: __mine_interval
2019-04-26 22:29:09,899 [salt.minion      :1308][INFO    ][31017] User sudo_ubuntu Executing command cp.push_dir with jid 20190426222909886266
2019-04-26 22:29:09,921 [salt.minion      :1432][INFO    ][10401] Starting a new job with PID 10401
