2019-06-25 20:07:40,094 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-25 20:08:30,138 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-25 20:09:20,184 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-25 20:10:10,228 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-25 20:11:00,279 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-25 20:13:07,846 [salt.utils.decorators:613 ][WARNING ][2745] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 20:13:08,479 [salt.utils.decorators:613 ][WARNING ][2745] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 20:13:10,722 [salt.loaded.int.states.file:2298][WARNING ][2885] 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-06-25 20:13:16,430 [salt.state       :2022][WARNING ][2994] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-25 20:13:18,987 [salt.utils.decorators:613 ][WARNING ][2994] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 20:28:23,286 [salt.utils.decorators:613 ][WARNING ][2994] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 20:52:30,424 [salt.utils.decorators:613 ][WARNING ][2994] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:07:31,412 [salt.utils.decorators:613 ][WARNING ][2994] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:07:35,871 [salt.loaded.ext.module.maasng:1008][WARNING ][2994] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-25 21:07:35,872 [salt.loaded.ext.module.maasng:1011][WARNING ][2994] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-25 21:07:36,536 [salt.loaded.ext.module.maasng:1235][WARNING ][2994] Ignoring parameter vlan:0
2019-06-25 21:07:37,432 [salt.utils.decorators:613 ][WARNING ][2994] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:07:43,346 [salt.utils.decorators:613 ][WARNING ][7189] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:07:43,411 [salt.loaded.ext.module.maas:412 ][WARNING ][7189] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:07:47,263 [salt.loaded.ext.module.maas:412 ][WARNING ][7189] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:07:51,323 [salt.loaded.ext.module.maas:412 ][WARNING ][7189] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:07:55,252 [salt.loaded.ext.module.maas:412 ][WARNING ][7189] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:07:59,592 [salt.loaded.ext.module.maas:412 ][WARNING ][7189] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:08:05,441 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8139] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-25 21:08:05,472 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8139] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-25 21:08:05,496 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-06-25 21:08:06,544 [salt.cli.daemons :293 ][INFO    ][8189] Setting up the Salt Minion "mas01.mcp-odl-noha.local"
2019-06-25 21:08:06,645 [salt.cli.daemons :82  ][INFO    ][8189] Starting up the Salt Minion
2019-06-25 21:08:06,646 [salt.utils.event :1017][INFO    ][8189] Starting pull socket on /var/run/salt/minion/minion_event_0f3e0c7467_pull.ipc
2019-06-25 21:08:07,571 [salt.minion      :976 ][INFO    ][8189] Creating minion process manager
2019-06-25 21:08:09,093 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][8189] Executing command ['date', '+%z'] in directory '/root'
2019-06-25 21:08:09,115 [salt.utils.schedule:568 ][INFO    ][8189] Updating job settings for scheduled job: __mine_interval
2019-06-25 21:08:09,117 [salt.minion      :1108][INFO    ][8189] Added mine.update to scheduler
2019-06-25 21:08:09,123 [salt.minion      :1975][INFO    ][8189] Minion is starting as user 'root'
2019-06-25 21:08:09,139 [salt.minion      :2336][INFO    ][8189] Minion is ready to receive requests!
2019-06-25 21:08:33,898 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625210833884733
2019-06-25 21:08:33,913 [salt.minion      :1432][INFO    ][8329] Starting a new job with PID 8329
2019-06-25 21:08:37,337 [salt.state       :915 ][INFO    ][8329] Loading fresh modules for state activity
2019-06-25 21:08:37,389 [salt.fileclient  :1219][INFO    ][8329] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-25 21:08:37,432 [salt.state       :1780][INFO    ][8329] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:08:37.432434
2019-06-25 21:08:37,432 [salt.state       :1813][INFO    ][8329] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:08:37,434 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8329] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:08:38,916 [salt.state       :300 ][INFO    ][8329] {'pid': 8336, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:08:38,917 [salt.state       :1951][INFO    ][8329] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:08:38.917079 duration_in_ms=1484.645
2019-06-25 21:08:38,919 [salt.state       :1780][INFO    ][8329] Running state [maas.wait_for_machine_status] at time 21:08:38.919793
2019-06-25 21:08:38,920 [salt.state       :1813][INFO    ][8329] Executing state module.run for [maas.wait_for_machine_status]
2019-06-25 21:08:38,921 [salt.utils.decorators:613 ][WARNING ][8329] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:08:39,785 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.14726782s left)
2019-06-25 21:08:48,949 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625210848940958
2019-06-25 21:08:48,969 [salt.minion      :1432][INFO    ][8363] Starting a new job with PID 8363
2019-06-25 21:08:48,991 [salt.minion      :1711][INFO    ][8363] Returning information for job: 20190625210848940958
2019-06-25 21:09:10,767 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.16488004s left)
2019-06-25 21:09:18,986 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625210918976704
2019-06-25 21:09:19,002 [salt.minion      :1432][INFO    ][8432] Starting a new job with PID 8432
2019-06-25 21:09:19,023 [salt.minion      :1711][INFO    ][8432] Returning information for job: 20190625210918976704
2019-06-25 21:09:41,606 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1437.3256979s left)
2019-06-25 21:09:49,039 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625210949032998
2019-06-25 21:09:49,055 [salt.minion      :1432][INFO    ][8651] Starting a new job with PID 8651
2019-06-25 21:09:49,065 [salt.minion      :1711][INFO    ][8651] Returning information for job: 20190625210949032998
2019-06-25 21:10:12,726 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1406.20551205s left)
2019-06-25 21:10:19,057 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211019051499
2019-06-25 21:10:19,070 [salt.minion      :1432][INFO    ][8891] Starting a new job with PID 8891
2019-06-25 21:10:19,083 [salt.minion      :1711][INFO    ][8891] Returning information for job: 20190625211019051499
2019-06-25 21:10:44,151 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1374.78058505s left)
2019-06-25 21:10:49,074 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211049068644
2019-06-25 21:10:49,087 [salt.minion      :1432][INFO    ][9385] Starting a new job with PID 9385
2019-06-25 21:10:49,104 [salt.minion      :1711][INFO    ][9385] Returning information for job: 20190625211049068644
2019-06-25 21:11:15,969 [salt.loaded.ext.module.maas:1023][INFO    ][8329] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1342.96278191s left)
2019-06-25 21:11:19,111 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211119105086
2019-06-25 21:11:19,124 [salt.minion      :1432][INFO    ][9767] Starting a new job with PID 9767
2019-06-25 21:11:19,136 [salt.minion      :1711][INFO    ][9767] Returning information for job: 20190625211119105086
2019-06-25 21:11:49,143 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211149130758
2019-06-25 21:11:49,164 [salt.minion      :1432][INFO    ][9959] Starting a new job with PID 9959
2019-06-25 21:11:49,186 [salt.minion      :1711][INFO    ][9959] Returning information for job: 20190625211149130758
2019-06-25 21:11:49,520 [salt.state       :300 ][INFO    ][8329] {'ret': True}
2019-06-25 21:11:49,520 [salt.state       :1951][INFO    ][8329] Completed state [maas.wait_for_machine_status] at time 21:11:49.520657 duration_in_ms=190600.864
2019-06-25 21:11:49,523 [salt.minion      :1711][INFO    ][8329] Returning information for job: 20190625210833884733
2019-06-25 21:11:50,164 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211150151411
2019-06-25 21:11:50,188 [salt.minion      :1432][INFO    ][9966] Starting a new job with PID 9966
2019-06-25 21:11:53,847 [salt.state       :915 ][INFO    ][9966] Loading fresh modules for state activity
2019-06-25 21:11:53,875 [salt.fileclient  :1219][INFO    ][9966] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-25 21:11:53,934 [salt.state       :1780][INFO    ][9966] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:11:53.934113
2019-06-25 21:11:53,934 [salt.state       :1813][INFO    ][9966] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:11:53,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9966] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:11:55,203 [salt.state       :300 ][INFO    ][9966] {'pid': 9973, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:11:55,204 [salt.state       :1951][INFO    ][9966] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:11:55.204671 duration_in_ms=1270.556
2019-06-25 21:11:55,207 [salt.state       :1780][INFO    ][9966] Running state [maas_machines_storage_cmp002_lvm] at time 21:11:55.207684
2019-06-25 21:11:55,208 [salt.state       :1813][INFO    ][9966] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-25 21:11:56,456 [salt.loaded.ext.module.maasng:610 ][INFO    ][9966] e6xmeq
2019-06-25 21:11:56,457 [salt.loaded.ext.module.maasng:626 ][INFO    ][9966] sda
2019-06-25 21:11:57,198 [salt.loaded.ext.module.maasng:361 ][INFO    ][9966] e6xmeq
2019-06-25 21:11:57,336 [salt.loaded.ext.module.maasng:367 ][INFO    ][9966] [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 5, u'filesystem': None, u'partitions': [{u'uuid': u'aa23e8f9-b169-4630-93c9-133d137ca300', u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'e6xmeq', u'filesystem': {u'uuid': u'5297cc80-69f3-4c58-a12f-bb4cff348dc3', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 5, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'e6xmeq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/', u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, {u'size': 2397988454400, u'block_size': 4096, u'uuid': u'9d288a99-face-4775-af0f-98eefec5c525', u'tags': [], u'used_size': 2397988454400, u'id': 10, u'filesystem': {u'uuid': u'0330c8ff-101d-40aa-8551-76f83bffdf29', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'e6xmeq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/10/', u'type': u'virtual', u'serial': None, u'name': u'vgroot-lvroot'}]
2019-06-25 21:11:57,337 [salt.loaded.ext.module.maasng:632 ][INFO    ][9966] vgroot
2019-06-25 21:11:57,337 [salt.loaded.ext.module.maasng:635 ][INFO    ][9966] lvroot
2019-06-25 21:11:57,338 [salt.loaded.ext.module.maasng:639 ][INFO    ][9966] 107374182400
2019-06-25 21:11:58,081 [salt.loaded.ext.module.maasng:645 ][INFO    ][9966] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 35}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'e6xmeq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/interfaces/5/'}, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'e6xmeq', u'power_state': u'on', 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"From 'Testing' to 'Ready'", u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/11/', u'uuid': u'97350374-d723-4123-9ff9-a7d5a83f5c9a', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'ccbfb38c-9029-43ac-969d-91104622718a', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'e6xmeq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'58895298-ed2d-44e9-90d4-e5a812d0cc37', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'e6xmeq', u'device_id': 5, u'filesystem': {u'uuid': u'6c3dd8db-b250-42ee-931d-65aaaf24808a', 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'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'e6xmeq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], 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'e6xmeq', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'58895298-ed2d-44e9-90d4-e5a812d0cc37', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'e6xmeq', u'device_id': 5, u'filesystem': {u'uuid': u'6c3dd8db-b250-42ee-931d-65aaaf24808a', 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'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'e6xmeq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 35}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'e6xmeq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 21, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'e6xmeq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/interfaces/21/'}, {u'name': u'enp9s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 22, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'e6xmeq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/interfaces/22/'}, {u'name': u'enp8s0', u'links': [{u'id': 38, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 23, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'e6xmeq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/interfaces/23/'}], u'address_ttl': None, u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'58895298-ed2d-44e9-90d4-e5a812d0cc37', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'e6xmeq', u'device_id': 5, u'filesystem': {u'uuid': u'6c3dd8db-b250-42ee-931d-65aaaf24808a', 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'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/5/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'e6xmeq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/e6xmeq/blockdevices/11/', u'uuid': u'97350374-d723-4123-9ff9-a7d5a83f5c9a', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'ccbfb38c-9029-43ac-969d-91104622718a', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'e6xmeq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'size': 107374182400}], u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/e6xmeq/'}
2019-06-25 21:11:58,083 [salt.state       :300 ][INFO    ][9966] {'new': {'storage_layout': 'lvm'}}
2019-06-25 21:11:58,084 [salt.state       :1951][INFO    ][9966] Completed state [maas_machines_storage_cmp002_lvm] at time 21:11:58.084077 duration_in_ms=2876.392
2019-06-25 21:11:58,084 [salt.state       :1780][INFO    ][9966] Running state [maas_machines_storage_cmp001_lvm] at time 21:11:58.084644
2019-06-25 21:11:58,085 [salt.state       :1813][INFO    ][9966] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-25 21:11:59,587 [salt.loaded.ext.module.maasng:610 ][INFO    ][9966] yteya8
2019-06-25 21:11:59,588 [salt.loaded.ext.module.maasng:626 ][INFO    ][9966] sda
2019-06-25 21:12:00,293 [salt.loaded.ext.module.maasng:361 ][INFO    ][9966] yteya8
2019-06-25 21:12:00,426 [salt.loaded.ext.module.maasng:367 ][INFO    ][9966] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'e2f45b01-df6d-4dd2-9642-ef7f4ccf2092', u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/partition/4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yteya8', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ef8671db-9ec0-47f7-8357-4886130cf738', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 4, u'device_id': 4}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yteya8', 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'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'name': u'sda'}, {u'size': 2397988454400, u'model': None, u'block_size': 4096, u'uuid': u'da4bb635-3bca-4706-a2aa-6ec75801a5ee', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'yteya8', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'400b68c4-1be9-4b59-b2e3-34e8562ec8bd', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/9/', u'used_size': 2397988454400, u'id': 9, u'name': u'vgroot-lvroot'}]
2019-06-25 21:12:00,427 [salt.loaded.ext.module.maasng:632 ][INFO    ][9966] vgroot
2019-06-25 21:12:00,427 [salt.loaded.ext.module.maasng:635 ][INFO    ][9966] lvroot
2019-06-25 21:12:00,427 [salt.loaded.ext.module.maasng:639 ][INFO    ][9966] 107374182400
2019-06-25 21:12:01,116 [salt.loaded.ext.module.maasng:645 ][INFO    ][9966] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 7, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'yteya8', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/interfaces/7/'}, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'current_commissioning_result_id': 8, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'yteya8', u'power_state': u'on', 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"From 'Testing' to 'Ready'", u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/12/', u'uuid': u'9ac6399f-95cb-458a-9a4f-9a2540ada794', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'35fb88c0-2225-42ba-9516-d7bba78ce15b', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 12, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'yteya8', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8f17099c-b361-489c-b0c6-6962c89c72aa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yteya8', u'device_id': 4, u'filesystem': {u'uuid': u'd11a1b17-e069-4190-8d11-ce3f7f327a61', 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'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yteya8', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'ip_addresses': [u'192.168.11.40'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'yteya8', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8f17099c-b361-489c-b0c6-6962c89c72aa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yteya8', u'device_id': 4, u'filesystem': {u'uuid': u'd11a1b17-e069-4190-8d11-ce3f7f327a61', 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'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yteya8', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, u'current_testing_result_id': 9, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 7, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'yteya8', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/interfaces/7/'}, {u'name': u'enp8s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 17, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'yteya8', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/interfaces/17/'}, {u'name': u'enp9s0', u'links': [{u'id': 33, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 19, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'yteya8', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/interfaces/19/'}, {u'name': u'enp7s0', u'links': [{u'id': 34, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 20, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'yteya8', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/interfaces/20/'}], u'address_ttl': None, u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8f17099c-b361-489c-b0c6-6962c89c72aa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yteya8', u'device_id': 4, u'filesystem': {u'uuid': u'd11a1b17-e069-4190-8d11-ce3f7f327a61', 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'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/4/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yteya8', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/yteya8/blockdevices/12/', u'uuid': u'9ac6399f-95cb-458a-9a4f-9a2540ada794', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'uuid': u'35fb88c0-2225-42ba-9516-d7bba78ce15b', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id': 12, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'yteya8', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'size': 107374182400}], u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/yteya8/'}
2019-06-25 21:12:01,118 [salt.state       :300 ][INFO    ][9966] {'new': {'storage_layout': 'lvm'}}
2019-06-25 21:12:01,119 [salt.state       :1951][INFO    ][9966] Completed state [maas_machines_storage_cmp001_lvm] at time 21:12:01.119184 duration_in_ms=3034.54
2019-06-25 21:12:01,123 [salt.minion      :1711][INFO    ][9966] Returning information for job: 20190625211150151411
2019-06-25 21:12:01,732 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211201720106
2019-06-25 21:12:01,752 [salt.minion      :1432][INFO    ][9992] Starting a new job with PID 9992
2019-06-25 21:12:02,440 [salt.state       :915 ][INFO    ][9992] Loading fresh modules for state activity
2019-06-25 21:12:02,469 [salt.fileclient  :1219][INFO    ][9992] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-25 21:12:02,495 [salt.state       :1780][INFO    ][9992] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:02.495608
2019-06-25 21:12:02,495 [salt.state       :1813][INFO    ][9992] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:12:02,497 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9992] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:12:04,071 [salt.state       :300 ][INFO    ][9992] {'pid': 9999, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:12:04,072 [salt.state       :1951][INFO    ][9992] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:04.072261 duration_in_ms=1576.652
2019-06-25 21:12:04,075 [salt.state       :1780][INFO    ][9992] Running state [maas.deploy_machines] at time 21:12:04.074959
2019-06-25 21:12:04,075 [salt.state       :1813][INFO    ][9992] Executing state module.run for [maas.deploy_machines]
2019-06-25 21:12:04,076 [salt.utils.decorators:613 ][WARNING ][9992] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:12:04,618 [salt.loaded.ext.module.maas:684 ][INFO    ][9992] deploymachines hwe_kernel=hwe-16.04 system_id=4hwags distro_series=xenial
2019-06-25 21:12:11,973 [salt.loaded.ext.module.maas:684 ][INFO    ][9992] deploymachines hwe_kernel=hwe-16.04 system_id=e6xmeq distro_series=xenial
2019-06-25 21:12:16,830 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211216817216
2019-06-25 21:12:16,851 [salt.minion      :1432][INFO    ][10142] Starting a new job with PID 10142
2019-06-25 21:12:16,876 [salt.minion      :1711][INFO    ][10142] Returning information for job: 20190625211216817216
2019-06-25 21:12:19,115 [salt.loaded.ext.module.maas:684 ][INFO    ][9992] deploymachines hwe_kernel=hwe-16.04 system_id=tkf7sy distro_series=xenial
2019-06-25 21:12:26,444 [salt.loaded.ext.module.maas:684 ][INFO    ][9992] deploymachines hwe_kernel=hwe-16.04 system_id=yteya8 distro_series=xenial
2019-06-25 21:12:33,854 [salt.loaded.ext.module.maas:684 ][INFO    ][9992] deploymachines hwe_kernel=hwe-16.04 system_id=gdeqra distro_series=xenial
2019-06-25 21:12:41,202 [salt.state       :300 ][INFO    ][9992] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']}}
2019-06-25 21:12:41,203 [salt.state       :1951][INFO    ][9992] Completed state [maas.deploy_machines] at time 21:12:41.203031 duration_in_ms=37128.071
2019-06-25 21:12:41,206 [salt.minion      :1711][INFO    ][9992] Returning information for job: 20190625211201720106
2019-06-25 21:12:41,856 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211241842298
2019-06-25 21:12:41,878 [salt.minion      :1432][INFO    ][10350] Starting a new job with PID 10350
2019-06-25 21:12:45,430 [salt.state       :915 ][INFO    ][10350] Loading fresh modules for state activity
2019-06-25 21:12:45,483 [salt.fileclient  :1219][INFO    ][10350] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-25 21:12:45,531 [salt.state       :1780][INFO    ][10350] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:45.531022
2019-06-25 21:12:45,531 [salt.state       :1813][INFO    ][10350] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:12:45,533 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10350] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:12:46,870 [salt.state       :300 ][INFO    ][10350] {'pid': 10367, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:12:46,871 [salt.state       :1951][INFO    ][10350] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:12:46.870926 duration_in_ms=1339.903
2019-06-25 21:12:46,873 [salt.state       :1780][INFO    ][10350] Running state [maas.wait_for_machine_status] at time 21:12:46.873326
2019-06-25 21:12:46,873 [salt.state       :1813][INFO    ][10350] Executing state module.run for [maas.wait_for_machine_status]
2019-06-25 21:12:46,874 [salt.utils.decorators:613 ][WARNING ][10350] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:12:49,419 [salt.loaded.ext.module.maas:1023][INFO    ][10350] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2247.46469402s left)
2019-06-25 21:12:56,933 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211256920891
2019-06-25 21:12:56,957 [salt.minion      :1432][INFO    ][10380] Starting a new job with PID 10380
2019-06-25 21:12:56,980 [salt.minion      :1711][INFO    ][10380] Returning information for job: 20190625211256920891
2019-06-25 21:13:23,878 [salt.loaded.ext.module.maas:1023][INFO    ][10350] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2213.00582504s left)
2019-06-25 21:13:26,985 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211326973406
2019-06-25 21:13:27,008 [salt.minion      :1432][INFO    ][10461] Starting a new job with PID 10461
2019-06-25 21:13:27,032 [salt.minion      :1711][INFO    ][10461] Returning information for job: 20190625211326973406
2019-06-25 21:13:57,086 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211357079554
2019-06-25 21:13:57,105 [salt.minion      :1432][INFO    ][10565] Starting a new job with PID 10565
2019-06-25 21:13:57,120 [salt.minion      :1711][INFO    ][10565] Returning information for job: 20190625211357079554
2019-06-25 21:14:27,108 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211427095217
2019-06-25 21:14:27,127 [salt.minion      :1432][INFO    ][10736] Starting a new job with PID 10736
2019-06-25 21:14:27,146 [salt.minion      :1711][INFO    ][10736] Returning information for job: 20190625211427095217
2019-06-25 21:14:57,164 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211457151783
2019-06-25 21:14:57,183 [salt.minion      :1432][INFO    ][10787] Starting a new job with PID 10787
2019-06-25 21:14:57,204 [salt.minion      :1711][INFO    ][10787] Returning information for job: 20190625211457151783
2019-06-25 21:15:27,232 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211527217853
2019-06-25 21:15:27,251 [salt.minion      :1432][INFO    ][10855] Starting a new job with PID 10855
2019-06-25 21:15:27,269 [salt.minion      :1711][INFO    ][10855] Returning information for job: 20190625211527217853
2019-06-25 21:15:57,308 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211557295342
2019-06-25 21:15:57,329 [salt.minion      :1432][INFO    ][10894] Starting a new job with PID 10894
2019-06-25 21:15:57,351 [salt.minion      :1711][INFO    ][10894] Returning information for job: 20190625211557295342
2019-06-25 21:16:27,388 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211627379055
2019-06-25 21:16:27,410 [salt.minion      :1432][INFO    ][10994] Starting a new job with PID 10994
2019-06-25 21:16:27,434 [salt.minion      :1711][INFO    ][10994] Returning information for job: 20190625211627379055
2019-06-25 21:16:57,477 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211657463198
2019-06-25 21:16:57,502 [salt.minion      :1432][INFO    ][11021] Starting a new job with PID 11021
2019-06-25 21:16:57,524 [salt.minion      :1711][INFO    ][11021] Returning information for job: 20190625211657463198
2019-06-25 21:17:27,578 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211727565533
2019-06-25 21:17:27,601 [salt.minion      :1432][INFO    ][11069] Starting a new job with PID 11069
2019-06-25 21:17:27,626 [salt.minion      :1711][INFO    ][11069] Returning information for job: 20190625211727565533
2019-06-25 21:17:57,688 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211757677207
2019-06-25 21:17:57,711 [salt.minion      :1432][INFO    ][11108] Starting a new job with PID 11108
2019-06-25 21:17:57,735 [salt.minion      :1711][INFO    ][11108] Returning information for job: 20190625211757677207
2019-06-25 21:18:27,792 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211827779961
2019-06-25 21:18:27,816 [salt.minion      :1432][INFO    ][11148] Starting a new job with PID 11148
2019-06-25 21:18:27,838 [salt.minion      :1711][INFO    ][11148] Returning information for job: 20190625211827779961
2019-06-25 21:18:57,903 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211857888440
2019-06-25 21:18:57,926 [salt.minion      :1432][INFO    ][11174] Starting a new job with PID 11174
2019-06-25 21:18:57,951 [salt.minion      :1711][INFO    ][11174] Returning information for job: 20190625211857888440
2019-06-25 21:19:03,814 [salt.state       :302 ][ERROR   ][10350] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-06-25 21:19:03,814 [salt.state       :1951][INFO    ][10350] Completed state [maas.wait_for_machine_status] at time 21:19:03.814600 duration_in_ms=376941.274
2019-06-25 21:19:03,817 [salt.minion      :1711][INFO    ][10350] Returning information for job: 20190625211241842298
2019-06-25 21:19:14,505 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command pillar.get with jid 20190625211914492771
2019-06-25 21:19:14,519 [salt.minion      :1432][INFO    ][11501] Starting a new job with PID 11501
2019-06-25 21:19:14,527 [salt.minion      :1711][INFO    ][11501] Returning information for job: 20190625211914492771
2019-06-25 21:19:14,989 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command service.status with jid 20190625211914979334
2019-06-25 21:19:15,004 [salt.minion      :1432][INFO    ][11506] Starting a new job with PID 11506
2019-06-25 21:19:15,456 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11506] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:15,494 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11506] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-25 21:19:15,510 [salt.minion      :1711][INFO    ][11506] Returning information for job: 20190625211914979334
2019-06-25 21:19:16,056 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211916044451
2019-06-25 21:19:16,073 [salt.minion      :1432][INFO    ][11517] Starting a new job with PID 11517
2019-06-25 21:19:19,642 [salt.state       :915 ][INFO    ][11517] Loading fresh modules for state activity
2019-06-25 21:19:19,955 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:19:20,154 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:19:20,708 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:19:20,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:19:22,178 [salt.state       :1780][INFO    ][11517] Running state [salt-minion] at time 21:19:22.178872
2019-06-25 21:19:22,179 [salt.state       :1813][INFO    ][11517] Executing state pkg.installed for [salt-minion]
2019-06-25 21:19:22,179 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:19:22,260 [salt.state       :300 ][INFO    ][11517] All specified packages are already installed
2019-06-25 21:19:22,260 [salt.state       :1951][INFO    ][11517] Completed state [salt-minion] at time 21:19:22.260663 duration_in_ms=81.792
2019-06-25 21:19:22,261 [salt.state       :1780][INFO    ][11517] Running state [salt_minion_dependency_packages] at time 21:19:22.260964
2019-06-25 21:19:22,261 [salt.state       :1813][INFO    ][11517] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-25 21:19:22,267 [salt.state       :300 ][INFO    ][11517] All specified packages are already installed
2019-06-25 21:19:22,267 [salt.state       :1951][INFO    ][11517] Completed state [salt_minion_dependency_packages] at time 21:19:22.267362 duration_in_ms=6.398
2019-06-25 21:19:22,270 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/minion.d/minion.conf] at time 21:19:22.270264
2019-06-25 21:19:22,270 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-25 21:19:22,458 [salt.state       :300 ][INFO    ][11517] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-25 21:19:22,458 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/minion.d/minion.conf] at time 21:19:22.458566 duration_in_ms=188.303
2019-06-25 21:19:22,460 [salt.state       :1780][INFO    ][11517] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:22.460663
2019-06-25 21:19:22,460 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-25 21:19:22,470 [salt.state       :300 ][INFO    ][11517] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-25 21:19:22,470 [salt.state       :1951][INFO    ][11517] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:22.470470 duration_in_ms=9.807
2019-06-25 21:19:22,471 [salt.state       :1780][INFO    ][11517] Running state [salt-minion] at time 21:19:22.471096
2019-06-25 21:19:22,471 [salt.state       :1813][INFO    ][11517] Executing state service.running for [salt-minion]
2019-06-25 21:19:22,471 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:22,506 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-25 21:19:22,522 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-25 21:19:22,538 [salt.state       :300 ][INFO    ][11517] The service salt-minion is already running
2019-06-25 21:19:22,539 [salt.state       :1951][INFO    ][11517] Completed state [salt-minion] at time 21:19:22.539282 duration_in_ms=68.186
2019-06-25 21:19:22,540 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains.d] at time 21:19:22.540745
2019-06-25 21:19:22,541 [salt.state       :1813][INFO    ][11517] Executing state file.directory for [/etc/salt/grains.d]
2019-06-25 21:19:22,542 [salt.state       :300 ][INFO    ][11517] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-25 21:19:22,542 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains.d] at time 21:19:22.542200 duration_in_ms=1.455
2019-06-25 21:19:22,542 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains] at time 21:19:22.542839
2019-06-25 21:19:22,543 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/grains]
2019-06-25 21:19:22,543 [salt.state       :300 ][INFO    ][11517] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-25 21:19:22,543 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains] at time 21:19:22.543863 duration_in_ms=1.024
2019-06-25 21:19:22,544 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains.d/placeholder] at time 21:19:22.544294
2019-06-25 21:19:22,544 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-25 21:19:22,545 [salt.state       :300 ][INFO    ][11517] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-25 21:19:22,545 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains.d/placeholder] at time 21:19:22.545287 duration_in_ms=0.993
2019-06-25 21:19:22,545 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains.d/sphinx] at time 21:19:22.545712
2019-06-25 21:19:22,546 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-25 21:19:22,560 [salt.state       :300 ][INFO    ][11517] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-25 21:19:22,560 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains.d/sphinx] at time 21:19:22.560369 duration_in_ms=14.657
2019-06-25 21:19:22,562 [salt.state       :1780][INFO    ][11517] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.562477
2019-06-25 21:19:22,562 [salt.state       :1813][INFO    ][11517] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:19:22,563 [salt.state       :300 ][INFO    ][11517] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:19:22,563 [salt.state       :1951][INFO    ][11517] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.563290 duration_in_ms=0.814
2019-06-25 21:19:22,563 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains.d/dns_records] at time 21:19:22.563733
2019-06-25 21:19:22,564 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-25 21:19:22,578 [salt.state       :300 ][INFO    ][11517] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-25 21:19:22,578 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains.d/dns_records] at time 21:19:22.578685 duration_in_ms=14.951
2019-06-25 21:19:22,580 [salt.state       :1780][INFO    ][11517] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.580168
2019-06-25 21:19:22,580 [salt.state       :1813][INFO    ][11517] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:19:22,581 [salt.state       :300 ][INFO    ][11517] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:19:22,581 [salt.state       :1951][INFO    ][11517] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.581568 duration_in_ms=1.4
2019-06-25 21:19:22,582 [salt.state       :1780][INFO    ][11517] Running state [/etc/salt/grains.d/salt] at time 21:19:22.582259
2019-06-25 21:19:22,582 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-25 21:19:22,596 [salt.state       :300 ][INFO    ][11517] File /etc/salt/grains.d/salt is in the correct state
2019-06-25 21:19:22,596 [salt.state       :1951][INFO    ][11517] Completed state [/etc/salt/grains.d/salt] at time 21:19:22.596505 duration_in_ms=14.246
2019-06-25 21:19:22,597 [salt.state       :1780][INFO    ][11517] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.597799
2019-06-25 21:19:22,598 [salt.state       :1813][INFO    ][11517] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:19:22,598 [salt.state       :300 ][INFO    ][11517] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:19:22,599 [salt.state       :1951][INFO    ][11517] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:22.599038 duration_in_ms=1.239
2019-06-25 21:19:22,601 [salt.state       :1780][INFO    ][11517] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:22.601865
2019-06-25 21:19:22,602 [salt.state       :1813][INFO    ][11517] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-25 21:19:22,602 [salt.state       :300 ][INFO    ][11517] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-25 21:19:22,603 [salt.state       :1951][INFO    ][11517] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:22.603131 duration_in_ms=1.266
2019-06-25 21:19:22,604 [salt.state       :1780][INFO    ][11517] Running state [mine.update] at time 21:19:22.604104
2019-06-25 21:19:22,604 [salt.state       :1813][INFO    ][11517] Executing state module.wait for [mine.update]
2019-06-25 21:19:22,605 [salt.state       :300 ][INFO    ][11517] No changes made for mine.update
2019-06-25 21:19:22,605 [salt.state       :1951][INFO    ][11517] Completed state [mine.update] at time 21:19:22.605271 duration_in_ms=1.167
2019-06-25 21:19:22,605 [salt.state       :1780][INFO    ][11517] Running state [ca-certificates] at time 21:19:22.605648
2019-06-25 21:19:22,606 [salt.state       :1813][INFO    ][11517] Executing state pkg.installed for [ca-certificates]
2019-06-25 21:19:22,616 [salt.state       :300 ][INFO    ][11517] All specified packages are already installed
2019-06-25 21:19:22,617 [salt.state       :1951][INFO    ][11517] Completed state [ca-certificates] at time 21:19:22.617046 duration_in_ms=11.397
2019-06-25 21:19:22,618 [salt.state       :1780][INFO    ][11517] Running state [update-ca-certificates] at time 21:19:22.618338
2019-06-25 21:19:22,618 [salt.state       :1813][INFO    ][11517] Executing state cmd.wait for [update-ca-certificates]
2019-06-25 21:19:22,619 [salt.state       :300 ][INFO    ][11517] No changes made for update-ca-certificates
2019-06-25 21:19:22,619 [salt.state       :1951][INFO    ][11517] Completed state [update-ca-certificates] at time 21:19:22.619416 duration_in_ms=1.078
2019-06-25 21:19:22,619 [salt.state       :1780][INFO    ][11517] Running state [iptables] at time 21:19:22.619760
2019-06-25 21:19:22,620 [salt.state       :1813][INFO    ][11517] Executing state pkg.installed for [iptables]
2019-06-25 21:19:22,629 [salt.state       :300 ][INFO    ][11517] All specified packages are already installed
2019-06-25 21:19:22,629 [salt.state       :1951][INFO    ][11517] Completed state [iptables] at time 21:19:22.629613 duration_in_ms=9.852
2019-06-25 21:19:22,629 [salt.state       :1780][INFO    ][11517] Running state [iptables-persistent] at time 21:19:22.629924
2019-06-25 21:19:22,630 [salt.state       :1813][INFO    ][11517] Executing state pkg.installed for [iptables-persistent]
2019-06-25 21:19:22,639 [salt.state       :300 ][INFO    ][11517] All specified packages are already installed
2019-06-25 21:19:22,640 [salt.state       :1951][INFO    ][11517] Completed state [iptables-persistent] at time 21:19:22.639970 duration_in_ms=10.046
2019-06-25 21:19:22,641 [salt.state       :1780][INFO    ][11517] Running state [iptables_modules_v4_load] at time 21:19:22.641186
2019-06-25 21:19:22,641 [salt.state       :1813][INFO    ][11517] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-25 21:19:22,642 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'lsmod' in directory '/root'
2019-06-25 21:19:22,663 [salt.state       :300 ][INFO    ][11517] Kernel modules iptable_filter, ip_tables are already present
2019-06-25 21:19:22,664 [salt.state       :1951][INFO    ][11517] Completed state [iptables_modules_v4_load] at time 21:19:22.663960 duration_in_ms=22.773
2019-06-25 21:19:22,664 [salt.state       :1780][INFO    ][11517] Running state [/etc/iptables/rules.v4] at time 21:19:22.664907
2019-06-25 21:19:22,665 [salt.state       :1813][INFO    ][11517] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-25 21:19:22,776 [salt.state       :300 ][INFO    ][11517] File /etc/iptables/rules.v4 is in the correct state
2019-06-25 21:19:22,776 [salt.state       :1951][INFO    ][11517] Completed state [/etc/iptables/rules.v4] at time 21:19:22.776288 duration_in_ms=111.381
2019-06-25 21:19:22,777 [salt.state       :1780][INFO    ][11517] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:22.777396
2019-06-25 21:19:22,777 [salt.state       :1813][INFO    ][11517] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-25 21:19:22,778 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-25 21:19:22,798 [salt.state       :300 ][INFO    ][11517] onlyif execution failed
2019-06-25 21:19:22,798 [salt.state       :1951][INFO    ][11517] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:22.798410 duration_in_ms=21.014
2019-06-25 21:19:22,799 [salt.state       :1780][INFO    ][11517] Running state [netfilter-persistent] at time 21:19:22.799427
2019-06-25 21:19:22,799 [salt.state       :1813][INFO    ][11517] Executing state service.running for [netfilter-persistent]
2019-06-25 21:19:22,800 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:22,819 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-25 21:19:22,837 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-25 21:19:22,854 [salt.state       :300 ][INFO    ][11517] The service netfilter-persistent is already running
2019-06-25 21:19:22,855 [salt.state       :1951][INFO    ][11517] Completed state [netfilter-persistent] at time 21:19:22.855285 duration_in_ms=55.857
2019-06-25 21:19:22,856 [salt.state       :1780][INFO    ][11517] Running state [iptables_extra.remove_stale_tables] at time 21:19:22.856609
2019-06-25 21:19:22,857 [salt.state       :1813][INFO    ][11517] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-25 21:19:22,857 [salt.state       :300 ][INFO    ][11517] No changes made for iptables_extra.remove_stale_tables
2019-06-25 21:19:22,858 [salt.state       :1951][INFO    ][11517] Completed state [iptables_extra.remove_stale_tables] at time 21:19:22.857959 duration_in_ms=1.35
2019-06-25 21:19:22,858 [salt.state       :1780][INFO    ][11517] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:22.858321
2019-06-25 21:19:22,858 [salt.state       :1813][INFO    ][11517] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-25 21:19:22,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11517] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-25 21:19:22,874 [salt.state       :300 ][INFO    ][11517] onlyif execution failed
2019-06-25 21:19:22,875 [salt.state       :1951][INFO    ][11517] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:22.875397 duration_in_ms=17.075
2019-06-25 21:19:22,877 [salt.state       :1780][INFO    ][11517] Running state [/etc/iptables/rules.v6] at time 21:19:22.877024
2019-06-25 21:19:22,877 [salt.state       :1813][INFO    ][11517] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-25 21:19:22,878 [salt.state       :300 ][INFO    ][11517] File /etc/iptables/rules.v6 is not present
2019-06-25 21:19:22,878 [salt.state       :1951][INFO    ][11517] Completed state [/etc/iptables/rules.v6] at time 21:19:22.878648 duration_in_ms=1.624
2019-06-25 21:19:22,879 [salt.state       :1780][INFO    ][11517] Running state [iptables_extra.flush_all] at time 21:19:22.879704
2019-06-25 21:19:22,880 [salt.state       :1813][INFO    ][11517] Executing state module.wait for [iptables_extra.flush_all]
2019-06-25 21:19:22,880 [salt.state       :300 ][INFO    ][11517] No changes made for iptables_extra.flush_all
2019-06-25 21:19:22,880 [salt.state       :1951][INFO    ][11517] Completed state [iptables_extra.flush_all] at time 21:19:22.880893 duration_in_ms=1.189
2019-06-25 21:19:22,885 [salt.minion      :1711][INFO    ][11517] Returning information for job: 20190625211916044451
2019-06-25 21:19:23,473 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211923464206
2019-06-25 21:19:23,495 [salt.minion      :1432][INFO    ][11870] Starting a new job with PID 11870
2019-06-25 21:19:24,192 [salt.state       :915 ][INFO    ][11870] Loading fresh modules for state activity
2019-06-25 21:19:24,782 [salt.state       :1780][INFO    ][11870] Running state [maas-rack-controller] at time 21:19:24.782528
2019-06-25 21:19:24,782 [salt.state       :1813][INFO    ][11870] Executing state pkg.installed for [maas-rack-controller]
2019-06-25 21:19:24,783 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11870] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:19:24,943 [salt.state       :300 ][INFO    ][11870] All specified packages are already installed
2019-06-25 21:19:24,944 [salt.state       :1951][INFO    ][11870] Completed state [maas-rack-controller] at time 21:19:24.944255 duration_in_ms=161.726
2019-06-25 21:19:24,944 [salt.state       :1780][INFO    ][11870] Running state [ipmitool] at time 21:19:24.944707
2019-06-25 21:19:24,945 [salt.state       :1813][INFO    ][11870] Executing state pkg.installed for [ipmitool]
2019-06-25 21:19:24,949 [salt.state       :300 ][INFO    ][11870] All specified packages are already installed
2019-06-25 21:19:24,950 [salt.state       :1951][INFO    ][11870] Completed state [ipmitool] at time 21:19:24.950016 duration_in_ms=5.309
2019-06-25 21:19:24,952 [salt.state       :1780][INFO    ][11870] Running state [/etc/maas/rackd.conf] at time 21:19:24.952469
2019-06-25 21:19:24,952 [salt.state       :1813][INFO    ][11870] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-25 21:19:24,953 [salt.state       :300 ][INFO    ][11870] No changes needed to be made
2019-06-25 21:19:24,953 [salt.state       :1951][INFO    ][11870] Completed state [/etc/maas/rackd.conf] at time 21:19:24.953864 duration_in_ms=1.395
2019-06-25 21:19:24,954 [salt.state       :1780][INFO    ][11870] Running state [/etc/maas/rackd.conf] at time 21:19:24.954132
2019-06-25 21:19:24,954 [salt.state       :1813][INFO    ][11870] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-25 21:19:24,954 [salt.loaded.int.states.file:2298][WARNING ][11870] 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-06-25 21:19:24,955 [salt.state       :300 ][INFO    ][11870] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-25 21:19:24,955 [salt.state       :1951][INFO    ][11870] Completed state [/etc/maas/rackd.conf] at time 21:19:24.955411 duration_in_ms=1.279
2019-06-25 21:19:24,956 [salt.state       :1780][INFO    ][11870] Running state [maas-rackd] at time 21:19:24.956260
2019-06-25 21:19:24,956 [salt.state       :1813][INFO    ][11870] Executing state service.running for [maas-rackd]
2019-06-25 21:19:24,957 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11870] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:24,991 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11870] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-25 21:19:25,007 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11870] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-25 21:19:25,024 [salt.state       :300 ][INFO    ][11870] The service maas-rackd is already running
2019-06-25 21:19:25,024 [salt.state       :1951][INFO    ][11870] Completed state [maas-rackd] at time 21:19:25.024405 duration_in_ms=68.144
2019-06-25 21:19:25,025 [salt.minion      :1711][INFO    ][11870] Returning information for job: 20190625211923464206
2019-06-25 21:19:25,553 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211925541051
2019-06-25 21:19:25,574 [salt.minion      :1432][INFO    ][11897] Starting a new job with PID 11897
2019-06-25 21:19:26,247 [salt.state       :915 ][INFO    ][11897] Loading fresh modules for state activity
2019-06-25 21:19:26,913 [salt.state       :1780][INFO    ][11897] Running state [maas-region-controller] at time 21:19:26.913871
2019-06-25 21:19:26,914 [salt.state       :1813][INFO    ][11897] Executing state pkg.installed for [maas-region-controller]
2019-06-25 21:19:26,914 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:19:27,006 [salt.state       :300 ][INFO    ][11897] All specified packages are already installed
2019-06-25 21:19:27,007 [salt.state       :1951][INFO    ][11897] Completed state [maas-region-controller] at time 21:19:27.006948 duration_in_ms=93.078
2019-06-25 21:19:27,007 [salt.state       :1780][INFO    ][11897] Running state [python-oauth] at time 21:19:27.007282
2019-06-25 21:19:27,007 [salt.state       :1813][INFO    ][11897] Executing state pkg.installed for [python-oauth]
2019-06-25 21:19:27,014 [salt.state       :300 ][INFO    ][11897] All specified packages are already installed
2019-06-25 21:19:27,014 [salt.state       :1951][INFO    ][11897] Completed state [python-oauth] at time 21:19:27.014417 duration_in_ms=7.135
2019-06-25 21:19:27,017 [salt.state       :1780][INFO    ][11897] Running state [/etc/maas/regiond.conf] at time 21:19:27.017518
2019-06-25 21:19:27,017 [salt.state       :1813][INFO    ][11897] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-25 21:19:27,069 [salt.state       :300 ][INFO    ][11897] No changes needed to be made
2019-06-25 21:19:27,070 [salt.state       :1951][INFO    ][11897] Completed state [/etc/maas/regiond.conf] at time 21:19:27.070212 duration_in_ms=52.695
2019-06-25 21:19:27,070 [salt.state       :1780][INFO    ][11897] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:27.070684
2019-06-25 21:19:27,071 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-25 21:19:27,135 [salt.state       :300 ][INFO    ][11897] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-25 21:19:27,135 [salt.state       :1951][INFO    ][11897] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:27.135460 duration_in_ms=64.776
2019-06-25 21:19:27,135 [salt.state       :1780][INFO    ][11897] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:27.135934
2019-06-25 21:19:27,136 [salt.state       :1813][INFO    ][11897] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-25 21:19:27,166 [salt.state       :300 ][INFO    ][11897] No changes needed to be made
2019-06-25 21:19:27,166 [salt.state       :1951][INFO    ][11897] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:27.166699 duration_in_ms=30.764
2019-06-25 21:19:27,167 [salt.state       :1780][INFO    ][11897] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:27.167123
2019-06-25 21:19:27,167 [salt.state       :1813][INFO    ][11897] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-25 21:19:27,196 [salt.state       :300 ][INFO    ][11897] No changes needed to be made
2019-06-25 21:19:27,196 [salt.state       :1951][INFO    ][11897] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:27.196599 duration_in_ms=29.477
2019-06-25 21:19:27,197 [salt.state       :1780][INFO    ][11897] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:27.197026
2019-06-25 21:19:27,197 [salt.state       :1813][INFO    ][11897] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-25 21:19:27,218 [salt.state       :300 ][INFO    ][11897] No changes needed to be made
2019-06-25 21:19:27,218 [salt.state       :1951][INFO    ][11897] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:27.218187 duration_in_ms=21.161
2019-06-25 21:19:27,218 [salt.state       :1780][INFO    ][11897] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:27.218602
2019-06-25 21:19:27,218 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-25 21:19:27,229 [salt.state       :300 ][INFO    ][11897] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-25 21:19:27,229 [salt.state       :1951][INFO    ][11897] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:27.229846 duration_in_ms=11.244
2019-06-25 21:19:27,230 [salt.state       :1780][INFO    ][11897] Running state [a2enmod headers] at time 21:19:27.230941
2019-06-25 21:19:27,231 [salt.state       :1813][INFO    ][11897] Executing state cmd.run for [a2enmod headers]
2019-06-25 21:19:27,231 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command 'a2enmod headers' in directory '/root'
2019-06-25 21:19:27,303 [salt.state       :300 ][INFO    ][11897] {'pid': 11926, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-25 21:19:27,304 [salt.state       :1951][INFO    ][11897] Completed state [a2enmod headers] at time 21:19:27.304129 duration_in_ms=73.187
2019-06-25 21:19:27,304 [salt.state       :1780][INFO    ][11897] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:27.304572
2019-06-25 21:19:27,305 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-25 21:19:27,319 [salt.state       :300 ][INFO    ][11897] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-25 21:19:27,320 [salt.state       :1951][INFO    ][11897] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:27.320149 duration_in_ms=15.577
2019-06-25 21:19:27,320 [salt.state       :1780][INFO    ][11897] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:27.320786
2019-06-25 21:19:27,321 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-25 21:19:27,387 [salt.state       :300 ][INFO    ][11897] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-25 21:19:27,387 [salt.state       :1951][INFO    ][11897] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:27.387309 duration_in_ms=66.523
2019-06-25 21:19:27,387 [salt.state       :1780][INFO    ][11897] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:27.387835
2019-06-25 21:19:27,388 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-25 21:19:27,440 [salt.state       :300 ][INFO    ][11897] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-25 21:19:27,441 [salt.state       :1951][INFO    ][11897] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:27.441105 duration_in_ms=53.27
2019-06-25 21:19:27,441 [salt.state       :1780][INFO    ][11897] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:27.441517
2019-06-25 21:19:27,441 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-25 21:19:27,507 [salt.state       :300 ][INFO    ][11897] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-25 21:19:27,507 [salt.state       :1951][INFO    ][11897] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:27.507327 duration_in_ms=65.808
2019-06-25 21:19:27,507 [salt.state       :1780][INFO    ][11897] Running state [/root/.pgpass] at time 21:19:27.507657
2019-06-25 21:19:27,507 [salt.state       :1813][INFO    ][11897] Executing state file.managed for [/root/.pgpass]
2019-06-25 21:19:27,548 [salt.state       :300 ][INFO    ][11897] File /root/.pgpass is in the correct state
2019-06-25 21:19:27,548 [salt.state       :1951][INFO    ][11897] Completed state [/root/.pgpass] at time 21:19:27.548884 duration_in_ms=41.228
2019-06-25 21:19:27,552 [salt.state       :1780][INFO    ][11897] Running state [maas-region syncdb --noinput] at time 21:19:27.552453
2019-06-25 21:19:27,552 [salt.state       :1813][INFO    ][11897] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-25 21:19:27,553 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-25 21:19:29,770 [salt.state       :300 ][INFO    ][11897] {'pid': 11939, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: contenttypes, sessions, auth, metadataserver, sites, maasserver, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-25 21:19:29,771 [salt.state       :1951][INFO    ][11897] Completed state [maas-region syncdb --noinput] at time 21:19:29.771453 duration_in_ms=2218.997
2019-06-25 21:19:29,772 [salt.state       :2022][WARNING ][11897] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-25 21:19:29,775 [salt.state       :1780][INFO    ][11897] Running state [maas-regiond] at time 21:19:29.774932
2019-06-25 21:19:29,775 [salt.state       :1813][INFO    ][11897] Executing state service.running for [maas-regiond]
2019-06-25 21:19:29,776 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:29,819 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-25 21:19:29,839 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-25 21:19:29,858 [salt.state       :300 ][INFO    ][11897] The service maas-regiond is already running
2019-06-25 21:19:29,858 [salt.state       :1951][INFO    ][11897] Completed state [maas-regiond] at time 21:19:29.858888 duration_in_ms=83.957
2019-06-25 21:19:29,861 [salt.state       :1780][INFO    ][11897] Running state [bind9] at time 21:19:29.861526
2019-06-25 21:19:29,862 [salt.state       :1813][INFO    ][11897] Executing state service.running for [bind9]
2019-06-25 21:19:29,863 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:29,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-25 21:19:29,902 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-25 21:19:29,920 [salt.state       :300 ][INFO    ][11897] The service bind9 is already running
2019-06-25 21:19:29,920 [salt.state       :1951][INFO    ][11897] Completed state [bind9] at time 21:19:29.920852 duration_in_ms=59.326
2019-06-25 21:19:29,923 [salt.state       :1780][INFO    ][11897] Running state [apache2] at time 21:19:29.923056
2019-06-25 21:19:29,923 [salt.state       :1813][INFO    ][11897] Executing state service.running for [apache2]
2019-06-25 21:19:29,924 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-25 21:19:29,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-25 21:19:29,961 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-25 21:19:29,984 [salt.state       :300 ][INFO    ][11897] The service apache2 is already running
2019-06-25 21:19:29,985 [salt.state       :1951][INFO    ][11897] Completed state [apache2] at time 21:19:29.985140 duration_in_ms=62.084
2019-06-25 21:19:29,987 [salt.state       :1780][INFO    ][11897] Running state [maasng.wait_for_http_code] at time 21:19:29.987201
2019-06-25 21:19:29,987 [salt.state       :1813][INFO    ][11897] Executing state module.run for [maasng.wait_for_http_code]
2019-06-25 21:19:29,988 [salt.utils.decorators:613 ][WARNING ][11897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:29,998 [salt.state       :300 ][INFO    ][11897] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-25 21:19:29,998 [salt.state       :1951][INFO    ][11897] Completed state [maasng.wait_for_http_code] at time 21:19:29.998781 duration_in_ms=11.579
2019-06-25 21:19:30,000 [salt.state       :1780][INFO    ][11897] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:30.000166
2019-06-25 21:19:30,000 [salt.state       :1813][INFO    ][11897] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-25 21:19:30,001 [salt.state       :300 ][INFO    ][11897] /var/lib/maas/.setup_admin exists
2019-06-25 21:19:30,001 [salt.state       :1951][INFO    ][11897] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:30.001796 duration_in_ms=1.63
2019-06-25 21:19:30,003 [salt.state       :1780][INFO    ][11897] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:30.002953
2019-06-25 21:19:30,003 [salt.state       :1813][INFO    ][11897] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:19:30,004 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11897] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:19:31,526 [salt.state       :300 ][INFO    ][11897] {'pid': 11958, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:19:31,527 [salt.state       :1951][INFO    ][11897] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:31.526944 duration_in_ms=1523.99
2019-06-25 21:19:31,538 [salt.state       :1780][INFO    ][11897] Running state [maas_region_boot_source_resources_mirror] at time 21:19:31.538297
2019-06-25 21:19:31,538 [salt.state       :1813][INFO    ][11897] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-25 21:19:31,636 [salt.state       :300 ][INFO    ][11897] {'changes': {}}
2019-06-25 21:19:31,637 [salt.state       :1951][INFO    ][11897] Completed state [maas_region_boot_source_resources_mirror] at time 21:19:31.637256 duration_in_ms=98.959
2019-06-25 21:19:31,638 [salt.state       :1780][INFO    ][11897] Running state [maasng.boot_resources_import] at time 21:19:31.638354
2019-06-25 21:19:31,638 [salt.state       :1813][INFO    ][11897] Executing state module.run for [maasng.boot_resources_import]
2019-06-25 21:19:31,639 [salt.utils.decorators:613 ][WARNING ][11897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:31,756 [salt.loaded.ext.module.maasng:1600][INFO    ][11897] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-25 21:19:36,814 [salt.loaded.ext.module.maasng:1600][INFO    ][11897] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-25 21:19:40,634 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625211940620680
2019-06-25 21:19:40,657 [salt.minion      :1432][INFO    ][11992] Starting a new job with PID 11992
2019-06-25 21:19:40,681 [salt.minion      :1711][INFO    ][11992] Returning information for job: 20190625211940620680
2019-06-25 21:19:41,868 [salt.loaded.ext.module.maasng:1600][INFO    ][11897] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-25 21:19:46,983 [salt.state       :300 ][INFO    ][11897] {'ret': True}
2019-06-25 21:19:46,984 [salt.state       :1951][INFO    ][11897] Completed state [maasng.boot_resources_import] at time 21:19:46.984216 duration_in_ms=15345.862
2019-06-25 21:19:46,985 [salt.state       :1780][INFO    ][11897] Running state [maas_region_boot_sources_selection_xenial] at time 21:19:46.985302
2019-06-25 21:19:46,985 [salt.state       :1813][INFO    ][11897] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-25 21:19:47,198 [salt.state       :300 ][INFO    ][11897] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-25 21:19:47,199 [salt.state       :1951][INFO    ][11897] Completed state [maas_region_boot_sources_selection_xenial] at time 21:19:47.199263 duration_in_ms=213.959
2019-06-25 21:19:47,201 [salt.state       :1780][INFO    ][11897] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:19:47.200994
2019-06-25 21:19:47,201 [salt.state       :1813][INFO    ][11897] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-25 21:19:47,202 [salt.utils.decorators:613 ][WARNING ][11897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:47,203 [salt.loaded.ext.module.maasng:1771][INFO    ][11897] boot-sources sync initiated for ALL Rack's
2019-06-25 21:19:48,216 [salt.state       :300 ][INFO    ][11897] {'ret': True}
2019-06-25 21:19:48,216 [salt.state       :1951][INFO    ][11897] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:19:48.216794 duration_in_ms=1015.799
2019-06-25 21:19:48,219 [salt.state       :1780][INFO    ][11897] Running state [maas.process_maas_config] at time 21:19:48.218970
2019-06-25 21:19:48,219 [salt.state       :1813][INFO    ][11897] Executing state module.run for [maas.process_maas_config]
2019-06-25 21:19:48,220 [salt.utils.decorators:613 ][WARNING ][11897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:48,221 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=enable_http_proxy value=True
2019-06-25 21:19:48,283 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=upstream_dns value=8.8.8.8
2019-06-25 21:19:48,354 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=commissioning_distro_series value=xenial
2019-06-25 21:19:48,424 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=default_osystem value=ubuntu
2019-06-25 21:19:48,490 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=active_discovery_interval value=600
2019-06-25 21:19:48,550 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=dnssec_validation value=no
2019-06-25 21:19:48,610 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=maas_name value=mas01
2019-06-25 21:19:48,676 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=network_discovery value=enabled
2019-06-25 21:19:48,790 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=enable_third_party_drivers value=True
2019-06-25 21:19:48,850 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=default_storage_layout value=lvm
2019-06-25 21:19:48,909 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=ntp_external_only value=True
2019-06-25 21:19:48,969 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-25 21:19:49,029 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=default_distro_series value=xenial
2019-06-25 21:19:49,095 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-25 21:19:49,240 [salt.state       :300 ][INFO    ][11897] {'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-06-25 21:19:49,240 [salt.state       :1951][INFO    ][11897] Completed state [maas.process_maas_config] at time 21:19:49.240469 duration_in_ms=1021.499
2019-06-25 21:19:49,241 [salt.state       :1780][INFO    ][11897] Running state [pxe_admin] at time 21:19:49.241473
2019-06-25 21:19:49,242 [salt.state       :1813][INFO    ][11897] Executing state maasng.fabric_present for [pxe_admin]
2019-06-25 21:19:49,310 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/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'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:49,388 [salt.loaded.ext.module.maasng:1008][WARNING ][11897] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-25 21:19:49,388 [salt.loaded.ext.module.maasng:1011][WARNING ][11897] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-25 21:19:49,460 [salt.state       :300 ][INFO    ][11897] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-25 21:19:49,461 [salt.state       :1951][INFO    ][11897] Completed state [pxe_admin] at time 21:19:49.461241 duration_in_ms=219.767
2019-06-25 21:19:49,461 [salt.state       :1780][INFO    ][11897] Running state [vlan 0] at time 21:19:49.461729
2019-06-25 21:19:49,462 [salt.state       :1813][INFO    ][11897] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-25 21:19:49,531 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'gnmcfc', 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-06-25 21:19:49,657 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'gnmcfc', 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'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:51,490 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/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'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:51,581 [salt.state       :300 ][INFO    ][11897] {'new': 'Vlan untagged was updated'}
2019-06-25 21:19:51,581 [salt.state       :1951][INFO    ][11897] Completed state [vlan 0] at time 21:19:51.581582 duration_in_ms=2119.852
2019-06-25 21:19:51,583 [salt.state       :1780][INFO    ][11897] Running state [192.168.11.0/24] at time 21:19:51.583129
2019-06-25 21:19:51,583 [salt.state       :1813][INFO    ][11897] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-25 21:19:51,779 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'gnmcfc', 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'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:51,780 [salt.loaded.ext.module.maasng:1235][WARNING ][11897] Ignoring parameter vlan:0
2019-06-25 21:19:51,858 [salt.state       :300 ][INFO    ][11897] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-25 21:19:51,858 [salt.state       :1951][INFO    ][11897] Completed state [192.168.11.0/24] at time 21:19:51.858593 duration_in_ms=275.463
2019-06-25 21:19:51,859 [salt.state       :1780][INFO    ][11897] Running state [maas_create_iprange_1] at time 21:19:51.859721
2019-06-25 21:19:51,860 [salt.state       :1813][INFO    ][11897] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-25 21:19:51,916 [salt.state       :300 ][INFO    ][11897] Iprange maas_create_iprange_1 already exist.
2019-06-25 21:19:51,917 [salt.state       :1951][INFO    ][11897] Completed state [maas_create_iprange_1] at time 21:19:51.917146 duration_in_ms=57.426
2019-06-25 21:19:51,917 [salt.state       :1780][INFO    ][11897] Running state [vlan 0] at time 21:19:51.917348
2019-06-25 21:19:51,917 [salt.state       :1813][INFO    ][11897] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-25 21:19:51,977 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'gnmcfc', 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'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:52,094 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'gnmcfc', 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-06-25 21:19:52,388 [salt.loaded.ext.module.maasng:945 ][INFO    ][11897] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:19:52,486 [salt.state       :300 ][INFO    ][11897] {'new': 'Vlan untagged was updated'}
2019-06-25 21:19:52,487 [salt.state       :1951][INFO    ][11897] Completed state [vlan 0] at time 21:19:52.487296 duration_in_ms=569.946
2019-06-25 21:19:52,488 [salt.state       :1780][INFO    ][11897] Running state [opnfv] at time 21:19:52.488258
2019-06-25 21:19:52,488 [salt.state       :1813][INFO    ][11897] Executing state maasng.sshkey_present for [opnfv]
2019-06-25 21:19:52,559 [salt.loaded.ext.module.maasng:1903][INFO    ][11897] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-06-25 21:19:52,560 [salt.state       :300 ][INFO    ][11897] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-25 21:19:52,560 [salt.state       :1951][INFO    ][11897] Completed state [opnfv] at time 21:19:52.560802 duration_in_ms=72.543
2019-06-25 21:19:52,561 [salt.state       :1780][INFO    ][11897] Running state [maas.process_tags] at time 21:19:52.561747
2019-06-25 21:19:52,562 [salt.state       :1813][INFO    ][11897] Executing state module.run for [maas.process_tags]
2019-06-25 21:19:52,562 [salt.utils.decorators:613 ][WARNING ][11897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:52,624 [salt.loaded.ext.module.maas:92  ][INFO    ][11897] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-25 21:19:52,678 [salt.state       :300 ][INFO    ][11897] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-25 21:19:52,679 [salt.state       :1951][INFO    ][11897] Completed state [maas.process_tags] at time 21:19:52.679319 duration_in_ms=117.571
2019-06-25 21:19:52,686 [salt.minion      :1711][INFO    ][11897] Returning information for job: 20190625211925541051
2019-06-25 21:19:53,234 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625211953221040
2019-06-25 21:19:53,254 [salt.minion      :1432][INFO    ][12362] Starting a new job with PID 12362
2019-06-25 21:19:56,744 [salt.state       :915 ][INFO    ][12362] Loading fresh modules for state activity
2019-06-25 21:19:56,836 [salt.state       :1780][INFO    ][12362] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:56.836226
2019-06-25 21:19:56,836 [salt.state       :1813][INFO    ][12362] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:19:56,838 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12362] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:19:58,324 [salt.state       :300 ][INFO    ][12362] {'pid': 12387, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:19:58,325 [salt.state       :1951][INFO    ][12362] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:58.325351 duration_in_ms=1489.125
2019-06-25 21:19:58,328 [salt.state       :1780][INFO    ][12362] Running state [maas.process_machines] at time 21:19:58.328028
2019-06-25 21:19:58,328 [salt.state       :1813][INFO    ][12362] Executing state module.run for [maas.process_machines]
2019-06-25 21:19:58,329 [salt.utils.decorators:613 ][WARNING ][12362] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:19:58,900 [salt.loaded.ext.module.maas:412 ][WARNING ][12362] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:19:58,901 [salt.loaded.ext.module.maas:92  ][INFO    ][12362] 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=4hwags architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:20:00,163 [salt.loaded.ext.module.maas:412 ][WARNING ][12362] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:20:00,164 [salt.loaded.ext.module.maas:92  ][INFO    ][12362] 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=e6xmeq architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:20:01,289 [salt.loaded.ext.module.maas:412 ][WARNING ][12362] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:20:01,289 [salt.loaded.ext.module.maas:92  ][INFO    ][12362] machine hostname=odl01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=tkf7sy architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:20:02,536 [salt.loaded.ext.module.maas:412 ][WARNING ][12362] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:20:02,537 [salt.loaded.ext.module.maas:92  ][INFO    ][12362] 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=yteya8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:20:03,597 [salt.loaded.ext.module.maas:412 ][WARNING ][12362] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:20:03,598 [salt.loaded.ext.module.maas:92  ][INFO    ][12362] 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=gdeqra architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:20:04,404 [salt.state       :300 ][INFO    ][12362] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-25 21:20:04,405 [salt.state       :1951][INFO    ][12362] Completed state [maas.process_machines] at time 21:20:04.405153 duration_in_ms=6077.125
2019-06-25 21:20:04,407 [salt.minion      :1711][INFO    ][12362] Returning information for job: 20190625211953221040
2019-06-25 21:20:35,455 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212035441950
2019-06-25 21:20:35,477 [salt.minion      :1432][INFO    ][13013] Starting a new job with PID 13013
2019-06-25 21:20:39,145 [salt.state       :915 ][INFO    ][13013] Loading fresh modules for state activity
2019-06-25 21:20:39,236 [salt.state       :1780][INFO    ][13013] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:39.236384
2019-06-25 21:20:39,236 [salt.state       :1813][INFO    ][13013] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:20:39,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13013] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:20:40,719 [salt.state       :300 ][INFO    ][13013] {'pid': 13020, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:20:40,720 [salt.state       :1951][INFO    ][13013] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:40.720126 duration_in_ms=1483.741
2019-06-25 21:20:40,722 [salt.state       :1780][INFO    ][13013] Running state [maas.wait_for_machine_status] at time 21:20:40.722811
2019-06-25 21:20:40,723 [salt.state       :1813][INFO    ][13013] Executing state module.run for [maas.wait_for_machine_status]
2019-06-25 21:20:40,724 [salt.utils.decorators:613 ][WARNING ][13013] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:20:44,254 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1496.48074389s left)
2019-06-25 21:20:50,547 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212050530638
2019-06-25 21:20:50,570 [salt.minion      :1432][INFO    ][13047] Starting a new job with PID 13047
2019-06-25 21:20:50,595 [salt.minion      :1711][INFO    ][13047] Returning information for job: 20190625212050530638
2019-06-25 21:21:17,568 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1463.1666348s left)
2019-06-25 21:21:20,596 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212120583436
2019-06-25 21:21:20,619 [salt.minion      :1432][INFO    ][13169] Starting a new job with PID 13169
2019-06-25 21:21:20,642 [salt.minion      :1711][INFO    ][13169] Returning information for job: 20190625212120583436
2019-06-25 21:21:50,697 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212150684217
2019-06-25 21:21:50,715 [salt.minion      :1432][INFO    ][13187] Starting a new job with PID 13187
2019-06-25 21:21:50,731 [salt.minion      :1711][INFO    ][13187] Returning information for job: 20190625212150684217
2019-06-25 21:21:50,975 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1429.75997591s left)
2019-06-25 21:22:20,722 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212220713804
2019-06-25 21:22:20,739 [salt.minion      :1432][INFO    ][13520] Starting a new job with PID 13520
2019-06-25 21:22:20,756 [salt.minion      :1711][INFO    ][13520] Returning information for job: 20190625212220713804
2019-06-25 21:22:23,842 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1396.8927269s left)
2019-06-25 21:22:50,757 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212250743976
2019-06-25 21:22:50,780 [salt.minion      :1432][INFO    ][13633] Starting a new job with PID 13633
2019-06-25 21:22:50,803 [salt.minion      :1711][INFO    ][13633] Returning information for job: 20190625212250743976
2019-06-25 21:22:57,361 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1363.37319493s left)
2019-06-25 21:23:20,810 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212320797368
2019-06-25 21:23:20,833 [salt.minion      :1432][INFO    ][13916] Starting a new job with PID 13916
2019-06-25 21:23:20,855 [salt.minion      :1711][INFO    ][13916] Returning information for job: 20190625212320797368
2019-06-25 21:23:30,617 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1330.11722088s left)
2019-06-25 21:23:50,870 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212350857229
2019-06-25 21:23:50,892 [salt.minion      :1432][INFO    ][13950] Starting a new job with PID 13950
2019-06-25 21:23:50,916 [salt.minion      :1711][INFO    ][13950] Returning information for job: 20190625212350857229
2019-06-25 21:24:03,782 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1296.95291901s left)
2019-06-25 21:24:20,929 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212420915294
2019-06-25 21:24:20,952 [salt.minion      :1432][INFO    ][14009] Starting a new job with PID 14009
2019-06-25 21:24:20,976 [salt.minion      :1711][INFO    ][14009] Returning information for job: 20190625212420915294
2019-06-25 21:24:36,909 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1263.8253808s left)
2019-06-25 21:24:50,953 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212450940721
2019-06-25 21:24:50,971 [salt.minion      :1432][INFO    ][14191] Starting a new job with PID 14191
2019-06-25 21:24:50,982 [salt.minion      :1711][INFO    ][14191] Returning information for job: 20190625212450940721
2019-06-25 21:25:10,320 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1230.41503596s left)
2019-06-25 21:25:21,052 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212521043215
2019-06-25 21:25:21,065 [salt.minion      :1432][INFO    ][14603] Starting a new job with PID 14603
2019-06-25 21:25:21,078 [salt.minion      :1711][INFO    ][14603] Returning information for job: 20190625212521043215
2019-06-25 21:25:43,666 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1197.06833696s left)
2019-06-25 21:25:51,100 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212551087655
2019-06-25 21:25:51,123 [salt.minion      :1432][INFO    ][14747] Starting a new job with PID 14747
2019-06-25 21:25:51,147 [salt.minion      :1711][INFO    ][14747] Returning information for job: 20190625212551087655
2019-06-25 21:26:17,452 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1163.28292894s left)
2019-06-25 21:26:21,179 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212621166715
2019-06-25 21:26:21,203 [salt.minion      :1432][INFO    ][14904] Starting a new job with PID 14904
2019-06-25 21:26:21,227 [salt.minion      :1711][INFO    ][14904] Returning information for job: 20190625212621166715
2019-06-25 21:26:50,904 [salt.loaded.ext.module.maas:1023][INFO    ][13013] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1129.83089185s left)
2019-06-25 21:26:51,264 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212651251583
2019-06-25 21:26:51,287 [salt.minion      :1432][INFO    ][14924] Starting a new job with PID 14924
2019-06-25 21:26:51,311 [salt.minion      :1711][INFO    ][14924] Returning information for job: 20190625212651251583
2019-06-25 21:27:21,351 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212721338951
2019-06-25 21:27:21,372 [salt.minion      :1432][INFO    ][15008] Starting a new job with PID 15008
2019-06-25 21:27:21,394 [salt.minion      :1711][INFO    ][15008] Returning information for job: 20190625212721338951
2019-06-25 21:27:21,684 [salt.loaded.ext.module.maas:993 ][INFO    ][13013] Machine 4hwags mark broken
2019-06-25 21:27:22,487 [salt.loaded.ext.module.maas:996 ][INFO    ][13013] Machine 4hwags mark fixed
2019-06-25 21:27:23,693 [salt.loaded.ext.module.maas:684 ][INFO    ][13013] deploymachines hwe_kernel=hwe-16.04 system_id=4hwags distro_series=xenial
2019-06-25 21:27:26,487 [salt.loaded.ext.module.maas:160 ][ERROR   ][13013] Failed for object gtw01 reason Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node.
2019-06-25 21:27:26,488 [salt.state       :302 ][ERROR   ][13013] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {'gtw01': "Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node."}, 'success': []}
2019-06-25 21:27:26,488 [salt.state       :1951][INFO    ][13013] Completed state [maas.wait_for_machine_status] at time 21:27:26.488632 duration_in_ms=405765.819
2019-06-25 21:27:26,492 [salt.minion      :1711][INFO    ][13013] Returning information for job: 20190625212035441950
2019-06-25 21:27:37,281 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command pillar.get with jid 20190625212737268805
2019-06-25 21:27:37,302 [salt.minion      :1432][INFO    ][15081] Starting a new job with PID 15081
2019-06-25 21:27:37,310 [salt.minion      :1711][INFO    ][15081] Returning information for job: 20190625212737268805
2019-06-25 21:27:37,814 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command service.status with jid 20190625212737807418
2019-06-25 21:27:37,836 [salt.minion      :1432][INFO    ][15086] Starting a new job with PID 15086
2019-06-25 21:27:38,226 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15086] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:38,259 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15086] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-25 21:27:38,275 [salt.minion      :1711][INFO    ][15086] Returning information for job: 20190625212737807418
2019-06-25 21:27:38,823 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212738810161
2019-06-25 21:27:38,845 [salt.minion      :1432][INFO    ][15097] Starting a new job with PID 15097
2019-06-25 21:27:42,534 [salt.state       :915 ][INFO    ][15097] Loading fresh modules for state activity
2019-06-25 21:27:42,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:27:43,241 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:27:44,139 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:27:44,497 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'salt-minion --version' in directory '/root'
2019-06-25 21:27:45,880 [salt.state       :1780][INFO    ][15097] Running state [salt-minion] at time 21:27:45.879955
2019-06-25 21:27:45,880 [salt.state       :1813][INFO    ][15097] Executing state pkg.installed for [salt-minion]
2019-06-25 21:27:45,880 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:27:45,952 [salt.state       :300 ][INFO    ][15097] All specified packages are already installed
2019-06-25 21:27:45,952 [salt.state       :1951][INFO    ][15097] Completed state [salt-minion] at time 21:27:45.952467 duration_in_ms=72.513
2019-06-25 21:27:45,952 [salt.state       :1780][INFO    ][15097] Running state [salt_minion_dependency_packages] at time 21:27:45.952736
2019-06-25 21:27:45,952 [salt.state       :1813][INFO    ][15097] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-25 21:27:45,957 [salt.state       :300 ][INFO    ][15097] All specified packages are already installed
2019-06-25 21:27:45,957 [salt.state       :1951][INFO    ][15097] Completed state [salt_minion_dependency_packages] at time 21:27:45.957675 duration_in_ms=4.938
2019-06-25 21:27:45,960 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/minion.d/minion.conf] at time 21:27:45.959997
2019-06-25 21:27:45,960 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-25 21:27:46,142 [salt.state       :300 ][INFO    ][15097] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-25 21:27:46,142 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/minion.d/minion.conf] at time 21:27:46.142581 duration_in_ms=182.583
2019-06-25 21:27:46,146 [salt.state       :1780][INFO    ][15097] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:27:46.146472
2019-06-25 21:27:46,146 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-25 21:27:46,158 [salt.state       :300 ][INFO    ][15097] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-25 21:27:46,158 [salt.state       :1951][INFO    ][15097] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:27:46.158919 duration_in_ms=12.447
2019-06-25 21:27:46,160 [salt.state       :1780][INFO    ][15097] Running state [salt-minion] at time 21:27:46.160045
2019-06-25 21:27:46,160 [salt.state       :1813][INFO    ][15097] Executing state service.running for [salt-minion]
2019-06-25 21:27:46,161 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:46,192 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-25 21:27:46,209 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-25 21:27:46,224 [salt.state       :300 ][INFO    ][15097] The service salt-minion is already running
2019-06-25 21:27:46,225 [salt.state       :1951][INFO    ][15097] Completed state [salt-minion] at time 21:27:46.225186 duration_in_ms=65.14
2019-06-25 21:27:46,227 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains.d] at time 21:27:46.227152
2019-06-25 21:27:46,227 [salt.state       :1813][INFO    ][15097] Executing state file.directory for [/etc/salt/grains.d]
2019-06-25 21:27:46,228 [salt.state       :300 ][INFO    ][15097] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-25 21:27:46,229 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains.d] at time 21:27:46.229125 duration_in_ms=1.972
2019-06-25 21:27:46,230 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains] at time 21:27:46.230064
2019-06-25 21:27:46,230 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/grains]
2019-06-25 21:27:46,231 [salt.state       :300 ][INFO    ][15097] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-25 21:27:46,231 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains] at time 21:27:46.231482 duration_in_ms=1.417
2019-06-25 21:27:46,232 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains.d/placeholder] at time 21:27:46.232104
2019-06-25 21:27:46,232 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-25 21:27:46,233 [salt.state       :300 ][INFO    ][15097] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-25 21:27:46,233 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains.d/placeholder] at time 21:27:46.233393 duration_in_ms=1.288
2019-06-25 21:27:46,234 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains.d/sphinx] at time 21:27:46.234008
2019-06-25 21:27:46,234 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-25 21:27:46,243 [salt.state       :300 ][INFO    ][15097] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-25 21:27:46,244 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains.d/sphinx] at time 21:27:46.243992 duration_in_ms=9.984
2019-06-25 21:27:46,246 [salt.state       :1780][INFO    ][15097] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.246708
2019-06-25 21:27:46,247 [salt.state       :1813][INFO    ][15097] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:27:46,247 [salt.state       :300 ][INFO    ][15097] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:27:46,247 [salt.state       :1951][INFO    ][15097] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.247805 duration_in_ms=1.096
2019-06-25 21:27:46,248 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains.d/dns_records] at time 21:27:46.248409
2019-06-25 21:27:46,248 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-25 21:27:46,261 [salt.state       :300 ][INFO    ][15097] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-25 21:27:46,262 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains.d/dns_records] at time 21:27:46.261942 duration_in_ms=13.533
2019-06-25 21:27:46,263 [salt.state       :1780][INFO    ][15097] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.263059
2019-06-25 21:27:46,263 [salt.state       :1813][INFO    ][15097] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:27:46,263 [salt.state       :300 ][INFO    ][15097] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:27:46,264 [salt.state       :1951][INFO    ][15097] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.264166 duration_in_ms=1.107
2019-06-25 21:27:46,264 [salt.state       :1780][INFO    ][15097] Running state [/etc/salt/grains.d/salt] at time 21:27:46.264763
2019-06-25 21:27:46,265 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-25 21:27:46,273 [salt.state       :300 ][INFO    ][15097] File /etc/salt/grains.d/salt is in the correct state
2019-06-25 21:27:46,273 [salt.state       :1951][INFO    ][15097] Completed state [/etc/salt/grains.d/salt] at time 21:27:46.273786 duration_in_ms=9.021
2019-06-25 21:27:46,274 [salt.state       :1780][INFO    ][15097] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.274863
2019-06-25 21:27:46,275 [salt.state       :1813][INFO    ][15097] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-25 21:27:46,275 [salt.state       :300 ][INFO    ][15097] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-25 21:27:46,276 [salt.state       :1951][INFO    ][15097] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:27:46.275953 duration_in_ms=1.09
2019-06-25 21:27:46,278 [salt.state       :1780][INFO    ][15097] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:27:46.278203
2019-06-25 21:27:46,278 [salt.state       :1813][INFO    ][15097] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-25 21:27:46,279 [salt.state       :300 ][INFO    ][15097] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-25 21:27:46,279 [salt.state       :1951][INFO    ][15097] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:27:46.279288 duration_in_ms=1.084
2019-06-25 21:27:46,280 [salt.state       :1780][INFO    ][15097] Running state [mine.update] at time 21:27:46.280148
2019-06-25 21:27:46,280 [salt.state       :1813][INFO    ][15097] Executing state module.wait for [mine.update]
2019-06-25 21:27:46,280 [salt.state       :300 ][INFO    ][15097] No changes made for mine.update
2019-06-25 21:27:46,281 [salt.state       :1951][INFO    ][15097] Completed state [mine.update] at time 21:27:46.281158 duration_in_ms=1.009
2019-06-25 21:27:46,281 [salt.state       :1780][INFO    ][15097] Running state [ca-certificates] at time 21:27:46.281482
2019-06-25 21:27:46,281 [salt.state       :1813][INFO    ][15097] Executing state pkg.installed for [ca-certificates]
2019-06-25 21:27:46,290 [salt.state       :300 ][INFO    ][15097] All specified packages are already installed
2019-06-25 21:27:46,290 [salt.state       :1951][INFO    ][15097] Completed state [ca-certificates] at time 21:27:46.290719 duration_in_ms=9.236
2019-06-25 21:27:46,291 [salt.state       :1780][INFO    ][15097] Running state [update-ca-certificates] at time 21:27:46.291910
2019-06-25 21:27:46,292 [salt.state       :1813][INFO    ][15097] Executing state cmd.wait for [update-ca-certificates]
2019-06-25 21:27:46,292 [salt.state       :300 ][INFO    ][15097] No changes made for update-ca-certificates
2019-06-25 21:27:46,292 [salt.state       :1951][INFO    ][15097] Completed state [update-ca-certificates] at time 21:27:46.292907 duration_in_ms=0.996
2019-06-25 21:27:46,293 [salt.state       :1780][INFO    ][15097] Running state [iptables] at time 21:27:46.293224
2019-06-25 21:27:46,293 [salt.state       :1813][INFO    ][15097] Executing state pkg.installed for [iptables]
2019-06-25 21:27:46,301 [salt.state       :300 ][INFO    ][15097] All specified packages are already installed
2019-06-25 21:27:46,301 [salt.state       :1951][INFO    ][15097] Completed state [iptables] at time 21:27:46.301338 duration_in_ms=8.113
2019-06-25 21:27:46,301 [salt.state       :1780][INFO    ][15097] Running state [iptables-persistent] at time 21:27:46.301683
2019-06-25 21:27:46,302 [salt.state       :1813][INFO    ][15097] Executing state pkg.installed for [iptables-persistent]
2019-06-25 21:27:46,309 [salt.state       :300 ][INFO    ][15097] All specified packages are already installed
2019-06-25 21:27:46,309 [salt.state       :1951][INFO    ][15097] Completed state [iptables-persistent] at time 21:27:46.309626 duration_in_ms=7.942
2019-06-25 21:27:46,310 [salt.state       :1780][INFO    ][15097] Running state [iptables_modules_v4_load] at time 21:27:46.310739
2019-06-25 21:27:46,311 [salt.state       :1813][INFO    ][15097] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-25 21:27:46,311 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'lsmod' in directory '/root'
2019-06-25 21:27:46,331 [salt.state       :300 ][INFO    ][15097] Kernel modules iptable_filter, ip_tables are already present
2019-06-25 21:27:46,332 [salt.state       :1951][INFO    ][15097] Completed state [iptables_modules_v4_load] at time 21:27:46.331994 duration_in_ms=21.255
2019-06-25 21:27:46,332 [salt.state       :1780][INFO    ][15097] Running state [/etc/iptables/rules.v4] at time 21:27:46.332717
2019-06-25 21:27:46,333 [salt.state       :1813][INFO    ][15097] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-25 21:27:46,435 [salt.state       :300 ][INFO    ][15097] File /etc/iptables/rules.v4 is in the correct state
2019-06-25 21:27:46,436 [salt.state       :1951][INFO    ][15097] Completed state [/etc/iptables/rules.v4] at time 21:27:46.436310 duration_in_ms=103.591
2019-06-25 21:27:46,438 [salt.state       :1780][INFO    ][15097] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:27:46.438255
2019-06-25 21:27:46,438 [salt.state       :1813][INFO    ][15097] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-25 21:27:46,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-25 21:27:46,458 [salt.state       :300 ][INFO    ][15097] onlyif execution failed
2019-06-25 21:27:46,459 [salt.state       :1951][INFO    ][15097] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:27:46.459228 duration_in_ms=20.973
2019-06-25 21:27:46,460 [salt.state       :1780][INFO    ][15097] Running state [netfilter-persistent] at time 21:27:46.460914
2019-06-25 21:27:46,461 [salt.state       :1813][INFO    ][15097] Executing state service.running for [netfilter-persistent]
2019-06-25 21:27:46,462 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:46,485 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-25 21:27:46,506 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-25 21:27:46,525 [salt.state       :300 ][INFO    ][15097] The service netfilter-persistent is already running
2019-06-25 21:27:46,526 [salt.state       :1951][INFO    ][15097] Completed state [netfilter-persistent] at time 21:27:46.526423 duration_in_ms=65.509
2019-06-25 21:27:46,527 [salt.state       :1780][INFO    ][15097] Running state [iptables_extra.remove_stale_tables] at time 21:27:46.527649
2019-06-25 21:27:46,528 [salt.state       :1813][INFO    ][15097] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-25 21:27:46,528 [salt.state       :300 ][INFO    ][15097] No changes made for iptables_extra.remove_stale_tables
2019-06-25 21:27:46,529 [salt.state       :1951][INFO    ][15097] Completed state [iptables_extra.remove_stale_tables] at time 21:27:46.528955 duration_in_ms=1.305
2019-06-25 21:27:46,529 [salt.state       :1780][INFO    ][15097] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:27:46.529325
2019-06-25 21:27:46,529 [salt.state       :1813][INFO    ][15097] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-25 21:27:46,530 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15097] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-25 21:27:46,547 [salt.state       :300 ][INFO    ][15097] onlyif execution failed
2019-06-25 21:27:46,548 [salt.state       :1951][INFO    ][15097] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:27:46.548371 duration_in_ms=19.046
2019-06-25 21:27:46,549 [salt.state       :1780][INFO    ][15097] Running state [/etc/iptables/rules.v6] at time 21:27:46.549630
2019-06-25 21:27:46,550 [salt.state       :1813][INFO    ][15097] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-25 21:27:46,550 [salt.state       :300 ][INFO    ][15097] File /etc/iptables/rules.v6 is not present
2019-06-25 21:27:46,550 [salt.state       :1951][INFO    ][15097] Completed state [/etc/iptables/rules.v6] at time 21:27:46.550923 duration_in_ms=1.292
2019-06-25 21:27:46,551 [salt.state       :1780][INFO    ][15097] Running state [iptables_extra.flush_all] at time 21:27:46.551770
2019-06-25 21:27:46,552 [salt.state       :1813][INFO    ][15097] Executing state module.wait for [iptables_extra.flush_all]
2019-06-25 21:27:46,552 [salt.state       :300 ][INFO    ][15097] No changes made for iptables_extra.flush_all
2019-06-25 21:27:46,552 [salt.state       :1951][INFO    ][15097] Completed state [iptables_extra.flush_all] at time 21:27:46.552792 duration_in_ms=1.022
2019-06-25 21:27:46,556 [salt.minion      :1711][INFO    ][15097] Returning information for job: 20190625212738810161
2019-06-25 21:27:47,048 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212747039950
2019-06-25 21:27:47,065 [salt.minion      :1432][INFO    ][15186] Starting a new job with PID 15186
2019-06-25 21:27:47,734 [salt.state       :915 ][INFO    ][15186] Loading fresh modules for state activity
2019-06-25 21:27:48,331 [salt.state       :1780][INFO    ][15186] Running state [maas-rack-controller] at time 21:27:48.331091
2019-06-25 21:27:48,331 [salt.state       :1813][INFO    ][15186] Executing state pkg.installed for [maas-rack-controller]
2019-06-25 21:27:48,331 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15186] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:27:48,425 [salt.state       :300 ][INFO    ][15186] All specified packages are already installed
2019-06-25 21:27:48,426 [salt.state       :1951][INFO    ][15186] Completed state [maas-rack-controller] at time 21:27:48.425934 duration_in_ms=94.842
2019-06-25 21:27:48,426 [salt.state       :1780][INFO    ][15186] Running state [ipmitool] at time 21:27:48.426310
2019-06-25 21:27:48,426 [salt.state       :1813][INFO    ][15186] Executing state pkg.installed for [ipmitool]
2019-06-25 21:27:48,433 [salt.state       :300 ][INFO    ][15186] All specified packages are already installed
2019-06-25 21:27:48,434 [salt.state       :1951][INFO    ][15186] Completed state [ipmitool] at time 21:27:48.434039 duration_in_ms=7.729
2019-06-25 21:27:48,437 [salt.state       :1780][INFO    ][15186] Running state [/etc/maas/rackd.conf] at time 21:27:48.437290
2019-06-25 21:27:48,437 [salt.state       :1813][INFO    ][15186] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-25 21:27:48,438 [salt.state       :300 ][INFO    ][15186] No changes needed to be made
2019-06-25 21:27:48,438 [salt.state       :1951][INFO    ][15186] Completed state [/etc/maas/rackd.conf] at time 21:27:48.438936 duration_in_ms=1.645
2019-06-25 21:27:48,439 [salt.state       :1780][INFO    ][15186] Running state [/etc/maas/rackd.conf] at time 21:27:48.439177
2019-06-25 21:27:48,439 [salt.state       :1813][INFO    ][15186] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-25 21:27:48,439 [salt.loaded.int.states.file:2298][WARNING ][15186] 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-06-25 21:27:48,440 [salt.state       :300 ][INFO    ][15186] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-25 21:27:48,440 [salt.state       :1951][INFO    ][15186] Completed state [/etc/maas/rackd.conf] at time 21:27:48.440505 duration_in_ms=1.328
2019-06-25 21:27:48,441 [salt.state       :1780][INFO    ][15186] Running state [maas-rackd] at time 21:27:48.441517
2019-06-25 21:27:48,441 [salt.state       :1813][INFO    ][15186] Executing state service.running for [maas-rackd]
2019-06-25 21:27:48,442 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15186] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:48,474 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15186] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-25 21:27:48,490 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15186] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-25 21:27:48,504 [salt.state       :300 ][INFO    ][15186] The service maas-rackd is already running
2019-06-25 21:27:48,505 [salt.state       :1951][INFO    ][15186] Completed state [maas-rackd] at time 21:27:48.504945 duration_in_ms=63.428
2019-06-25 21:27:48,549 [salt.minion      :1711][INFO    ][15186] Returning information for job: 20190625212747039950
2019-06-25 21:27:49,111 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212749098434
2019-06-25 21:27:49,130 [salt.minion      :1432][INFO    ][15209] Starting a new job with PID 15209
2019-06-25 21:27:49,841 [salt.state       :915 ][INFO    ][15209] Loading fresh modules for state activity
2019-06-25 21:27:50,561 [salt.state       :1780][INFO    ][15209] Running state [maas-region-controller] at time 21:27:50.561757
2019-06-25 21:27:50,562 [salt.state       :1813][INFO    ][15209] Executing state pkg.installed for [maas-region-controller]
2019-06-25 21:27:50,562 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-25 21:27:50,640 [salt.state       :300 ][INFO    ][15209] All specified packages are already installed
2019-06-25 21:27:50,640 [salt.state       :1951][INFO    ][15209] Completed state [maas-region-controller] at time 21:27:50.640423 duration_in_ms=78.665
2019-06-25 21:27:50,640 [salt.state       :1780][INFO    ][15209] Running state [python-oauth] at time 21:27:50.640724
2019-06-25 21:27:50,641 [salt.state       :1813][INFO    ][15209] Executing state pkg.installed for [python-oauth]
2019-06-25 21:27:50,646 [salt.state       :300 ][INFO    ][15209] All specified packages are already installed
2019-06-25 21:27:50,646 [salt.state       :1951][INFO    ][15209] Completed state [python-oauth] at time 21:27:50.646572 duration_in_ms=5.849
2019-06-25 21:27:50,649 [salt.state       :1780][INFO    ][15209] Running state [/etc/maas/regiond.conf] at time 21:27:50.649188
2019-06-25 21:27:50,649 [salt.state       :1813][INFO    ][15209] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-25 21:27:50,699 [salt.state       :300 ][INFO    ][15209] No changes needed to be made
2019-06-25 21:27:50,699 [salt.state       :1951][INFO    ][15209] Completed state [/etc/maas/regiond.conf] at time 21:27:50.699368 duration_in_ms=50.18
2019-06-25 21:27:50,700 [salt.state       :1780][INFO    ][15209] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:27:50.700036
2019-06-25 21:27:50,700 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-25 21:27:50,788 [salt.state       :300 ][INFO    ][15209] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-25 21:27:50,788 [salt.state       :1951][INFO    ][15209] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:27:50.788775 duration_in_ms=88.738
2019-06-25 21:27:50,789 [salt.state       :1780][INFO    ][15209] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:27:50.789620
2019-06-25 21:27:50,790 [salt.state       :1813][INFO    ][15209] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-25 21:27:50,808 [salt.state       :300 ][INFO    ][15209] No changes needed to be made
2019-06-25 21:27:50,809 [salt.state       :1951][INFO    ][15209] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:27:50.808912 duration_in_ms=19.292
2019-06-25 21:27:50,809 [salt.state       :1780][INFO    ][15209] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:27:50.809677
2019-06-25 21:27:50,810 [salt.state       :1813][INFO    ][15209] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-25 21:27:50,838 [salt.state       :300 ][INFO    ][15209] No changes needed to be made
2019-06-25 21:27:50,838 [salt.state       :1951][INFO    ][15209] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:27:50.838616 duration_in_ms=28.939
2019-06-25 21:27:50,839 [salt.state       :1780][INFO    ][15209] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:27:50.839325
2019-06-25 21:27:50,839 [salt.state       :1813][INFO    ][15209] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-25 21:27:50,882 [salt.state       :300 ][INFO    ][15209] No changes needed to be made
2019-06-25 21:27:50,884 [salt.state       :1951][INFO    ][15209] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:27:50.884085 duration_in_ms=44.757
2019-06-25 21:27:50,885 [salt.state       :1780][INFO    ][15209] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:27:50.885915
2019-06-25 21:27:50,886 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-25 21:27:50,905 [salt.state       :300 ][INFO    ][15209] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-25 21:27:50,905 [salt.state       :1951][INFO    ][15209] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:27:50.905622 duration_in_ms=19.707
2019-06-25 21:27:50,909 [salt.state       :1780][INFO    ][15209] Running state [a2enmod headers] at time 21:27:50.909914
2019-06-25 21:27:50,910 [salt.state       :1813][INFO    ][15209] Executing state cmd.run for [a2enmod headers]
2019-06-25 21:27:50,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command 'a2enmod headers' in directory '/root'
2019-06-25 21:27:50,987 [salt.state       :300 ][INFO    ][15209] {'pid': 15228, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-25 21:27:50,988 [salt.state       :1951][INFO    ][15209] Completed state [a2enmod headers] at time 21:27:50.988224 duration_in_ms=78.309
2019-06-25 21:27:50,988 [salt.state       :1780][INFO    ][15209] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:27:50.988796
2019-06-25 21:27:50,989 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-25 21:27:51,007 [salt.state       :300 ][INFO    ][15209] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-25 21:27:51,007 [salt.state       :1951][INFO    ][15209] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:27:51.007775 duration_in_ms=18.979
2019-06-25 21:27:51,008 [salt.state       :1780][INFO    ][15209] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:27:51.008665
2019-06-25 21:27:51,009 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-25 21:27:51,099 [salt.state       :300 ][INFO    ][15209] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-25 21:27:51,100 [salt.state       :1951][INFO    ][15209] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:27:51.100271 duration_in_ms=91.606
2019-06-25 21:27:51,101 [salt.state       :1780][INFO    ][15209] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:27:51.101169
2019-06-25 21:27:51,101 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-25 21:27:51,171 [salt.state       :300 ][INFO    ][15209] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-25 21:27:51,171 [salt.state       :1951][INFO    ][15209] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:27:51.171868 duration_in_ms=70.7
2019-06-25 21:27:51,172 [salt.state       :1780][INFO    ][15209] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:27:51.172528
2019-06-25 21:27:51,172 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-25 21:27:51,249 [salt.state       :300 ][INFO    ][15209] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-25 21:27:51,250 [salt.state       :1951][INFO    ][15209] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:27:51.250033 duration_in_ms=77.505
2019-06-25 21:27:51,250 [salt.state       :1780][INFO    ][15209] Running state [/root/.pgpass] at time 21:27:51.250465
2019-06-25 21:27:51,250 [salt.state       :1813][INFO    ][15209] Executing state file.managed for [/root/.pgpass]
2019-06-25 21:27:51,309 [salt.state       :300 ][INFO    ][15209] File /root/.pgpass is in the correct state
2019-06-25 21:27:51,309 [salt.state       :1951][INFO    ][15209] Completed state [/root/.pgpass] at time 21:27:51.309667 duration_in_ms=59.202
2019-06-25 21:27:51,317 [salt.state       :1780][INFO    ][15209] Running state [maas-region syncdb --noinput] at time 21:27:51.317394
2019-06-25 21:27:51,317 [salt.state       :1813][INFO    ][15209] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-25 21:27:51,318 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-25 21:27:53,378 [salt.state       :300 ][INFO    ][15209] {'pid': 15241, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, contenttypes, sites, auth, metadataserver, piston3, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-25 21:27:53,378 [salt.state       :1951][INFO    ][15209] Completed state [maas-region syncdb --noinput] at time 21:27:53.378691 duration_in_ms=2061.296
2019-06-25 21:27:53,379 [salt.state       :2022][WARNING ][15209] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-25 21:27:53,381 [salt.state       :1780][INFO    ][15209] Running state [maas-regiond] at time 21:27:53.381795
2019-06-25 21:27:53,382 [salt.state       :1813][INFO    ][15209] Executing state service.running for [maas-regiond]
2019-06-25 21:27:53,383 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:53,423 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-25 21:27:53,441 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-25 21:27:53,458 [salt.state       :300 ][INFO    ][15209] The service maas-regiond is already running
2019-06-25 21:27:53,459 [salt.state       :1951][INFO    ][15209] Completed state [maas-regiond] at time 21:27:53.459086 duration_in_ms=77.292
2019-06-25 21:27:53,461 [salt.state       :1780][INFO    ][15209] Running state [bind9] at time 21:27:53.461592
2019-06-25 21:27:53,462 [salt.state       :1813][INFO    ][15209] Executing state service.running for [bind9]
2019-06-25 21:27:53,463 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:53,482 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-25 21:27:53,501 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-25 21:27:53,519 [salt.state       :300 ][INFO    ][15209] The service bind9 is already running
2019-06-25 21:27:53,519 [salt.state       :1951][INFO    ][15209] Completed state [bind9] at time 21:27:53.519799 duration_in_ms=58.207
2019-06-25 21:27:53,522 [salt.state       :1780][INFO    ][15209] Running state [apache2] at time 21:27:53.522686
2019-06-25 21:27:53,523 [salt.state       :1813][INFO    ][15209] Executing state service.running for [apache2]
2019-06-25 21:27:53,524 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-25 21:27:53,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-25 21:27:53,561 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-25 21:27:53,583 [salt.state       :300 ][INFO    ][15209] The service apache2 is already running
2019-06-25 21:27:53,583 [salt.state       :1951][INFO    ][15209] Completed state [apache2] at time 21:27:53.583500 duration_in_ms=60.814
2019-06-25 21:27:53,585 [salt.state       :1780][INFO    ][15209] Running state [maasng.wait_for_http_code] at time 21:27:53.585891
2019-06-25 21:27:53,586 [salt.state       :1813][INFO    ][15209] Executing state module.run for [maasng.wait_for_http_code]
2019-06-25 21:27:53,587 [salt.utils.decorators:613 ][WARNING ][15209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:27:53,712 [salt.state       :300 ][INFO    ][15209] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-25 21:27:53,713 [salt.state       :1951][INFO    ][15209] Completed state [maasng.wait_for_http_code] at time 21:27:53.713401 duration_in_ms=127.51
2019-06-25 21:27:53,714 [salt.state       :1780][INFO    ][15209] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:27:53.714689
2019-06-25 21:27:53,715 [salt.state       :1813][INFO    ][15209] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-25 21:27:53,715 [salt.state       :300 ][INFO    ][15209] /var/lib/maas/.setup_admin exists
2019-06-25 21:27:53,716 [salt.state       :1951][INFO    ][15209] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:27:53.716120 duration_in_ms=1.43
2019-06-25 21:27:53,717 [salt.state       :1780][INFO    ][15209] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:27:53.717116
2019-06-25 21:27:53,717 [salt.state       :1813][INFO    ][15209] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:27:53,718 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15209] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:27:55,099 [salt.state       :300 ][INFO    ][15209] {'pid': 15262, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:27:55,100 [salt.state       :1951][INFO    ][15209] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:27:55.100278 duration_in_ms=1383.163
2019-06-25 21:27:55,103 [salt.state       :1780][INFO    ][15209] Running state [maas_region_boot_source_resources_mirror] at time 21:27:55.103945
2019-06-25 21:27:55,104 [salt.state       :1813][INFO    ][15209] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-25 21:27:55,210 [salt.state       :300 ][INFO    ][15209] {'changes': {}}
2019-06-25 21:27:55,211 [salt.state       :1951][INFO    ][15209] Completed state [maas_region_boot_source_resources_mirror] at time 21:27:55.211061 duration_in_ms=107.114
2019-06-25 21:27:55,212 [salt.state       :1780][INFO    ][15209] Running state [maasng.boot_resources_import] at time 21:27:55.212195
2019-06-25 21:27:55,212 [salt.state       :1813][INFO    ][15209] Executing state module.run for [maasng.boot_resources_import]
2019-06-25 21:27:55,213 [salt.utils.decorators:613 ][WARNING ][15209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:27:58,692 [salt.loaded.ext.module.maasng:1600][INFO    ][15209] Waiting boot-resources import done
sleep for:5s Left:897.0/900s
2019-06-25 21:28:03,754 [salt.loaded.ext.module.maasng:1600][INFO    ][15209] Waiting boot-resources import done
sleep for:5s Left:892.0/900s
2019-06-25 21:28:04,221 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212804209207
2019-06-25 21:28:04,245 [salt.minion      :1432][INFO    ][15288] Starting a new job with PID 15288
2019-06-25 21:28:04,267 [salt.minion      :1711][INFO    ][15288] Returning information for job: 20190625212804209207
2019-06-25 21:28:08,866 [salt.state       :300 ][INFO    ][15209] {'ret': True}
2019-06-25 21:28:08,867 [salt.state       :1951][INFO    ][15209] Completed state [maasng.boot_resources_import] at time 21:28:08.867217 duration_in_ms=13655.021
2019-06-25 21:28:08,868 [salt.state       :1780][INFO    ][15209] Running state [maas_region_boot_sources_selection_xenial] at time 21:28:08.868497
2019-06-25 21:28:08,869 [salt.state       :1813][INFO    ][15209] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-25 21:28:09,081 [salt.state       :300 ][INFO    ][15209] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-25 21:28:09,082 [salt.state       :1951][INFO    ][15209] Completed state [maas_region_boot_sources_selection_xenial] at time 21:28:09.082171 duration_in_ms=213.673
2019-06-25 21:28:09,083 [salt.state       :1780][INFO    ][15209] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:28:09.083628
2019-06-25 21:28:09,084 [salt.state       :1813][INFO    ][15209] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-25 21:28:09,084 [salt.utils.decorators:613 ][WARNING ][15209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:28:09,085 [salt.loaded.ext.module.maasng:1771][INFO    ][15209] boot-sources sync initiated for ALL Rack's
2019-06-25 21:28:10,189 [salt.state       :300 ][INFO    ][15209] {'ret': True}
2019-06-25 21:28:10,190 [salt.state       :1951][INFO    ][15209] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:28:10.190098 duration_in_ms=1106.469
2019-06-25 21:28:10,192 [salt.state       :1780][INFO    ][15209] Running state [maas.process_maas_config] at time 21:28:10.192270
2019-06-25 21:28:10,192 [salt.state       :1813][INFO    ][15209] Executing state module.run for [maas.process_maas_config]
2019-06-25 21:28:10,193 [salt.utils.decorators:613 ][WARNING ][15209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:28:10,194 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=enable_http_proxy value=True
2019-06-25 21:28:10,257 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=upstream_dns value=8.8.8.8
2019-06-25 21:28:10,321 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=commissioning_distro_series value=xenial
2019-06-25 21:28:10,393 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=default_osystem value=ubuntu
2019-06-25 21:28:13,565 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=active_discovery_interval value=600
2019-06-25 21:28:13,638 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=dnssec_validation value=no
2019-06-25 21:28:13,694 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=maas_name value=mas01
2019-06-25 21:28:13,753 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=network_discovery value=enabled
2019-06-25 21:28:13,867 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=enable_third_party_drivers value=True
2019-06-25 21:28:13,926 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=default_storage_layout value=lvm
2019-06-25 21:28:13,986 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=ntp_external_only value=True
2019-06-25 21:28:14,040 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-25 21:28:14,105 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=default_distro_series value=xenial
2019-06-25 21:28:14,190 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-25 21:28:14,324 [salt.state       :300 ][INFO    ][15209] {'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-06-25 21:28:14,324 [salt.state       :1951][INFO    ][15209] Completed state [maas.process_maas_config] at time 21:28:14.324902 duration_in_ms=4132.632
2019-06-25 21:28:14,325 [salt.state       :1780][INFO    ][15209] Running state [pxe_admin] at time 21:28:14.325596
2019-06-25 21:28:14,326 [salt.state       :1813][INFO    ][15209] Executing state maasng.fabric_present for [pxe_admin]
2019-06-25 21:28:14,377 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'gnmcfc', 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-06-25 21:28:14,447 [salt.loaded.ext.module.maasng:1008][WARNING ][15209] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-25 21:28:14,447 [salt.loaded.ext.module.maasng:1011][WARNING ][15209] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-25 21:28:14,525 [salt.state       :300 ][INFO    ][15209] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-25 21:28:14,526 [salt.state       :1951][INFO    ][15209] Completed state [pxe_admin] at time 21:28:14.526259 duration_in_ms=200.662
2019-06-25 21:28:14,526 [salt.state       :1780][INFO    ][15209] Running state [vlan 0] at time 21:28:14.526720
2019-06-25 21:28:14,527 [salt.state       :1813][INFO    ][15209] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-25 21:28:14,590 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'gnmcfc', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-25 21:28:14,728 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'gnmcfc', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-25 21:28:15,031 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'gnmcfc', 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-06-25 21:28:15,127 [salt.state       :300 ][INFO    ][15209] {'new': 'Vlan untagged was updated'}
2019-06-25 21:28:15,127 [salt.state       :1951][INFO    ][15209] Completed state [vlan 0] at time 21:28:15.127569 duration_in_ms=600.849
2019-06-25 21:28:15,129 [salt.state       :1780][INFO    ][15209] Running state [192.168.11.0/24] at time 21:28:15.128964
2019-06-25 21:28:15,129 [salt.state       :1813][INFO    ][15209] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-25 21:28:15,346 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:28:15,346 [salt.loaded.ext.module.maasng:1235][WARNING ][15209] Ignoring parameter vlan:0
2019-06-25 21:28:15,412 [salt.state       :300 ][INFO    ][15209] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-25 21:28:15,412 [salt.state       :1951][INFO    ][15209] Completed state [192.168.11.0/24] at time 21:28:15.412445 duration_in_ms=283.48
2019-06-25 21:28:15,413 [salt.state       :1780][INFO    ][15209] Running state [maas_create_iprange_1] at time 21:28:15.413787
2019-06-25 21:28:15,414 [salt.state       :1813][INFO    ][15209] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-25 21:28:15,467 [salt.state       :300 ][INFO    ][15209] Iprange maas_create_iprange_1 already exist.
2019-06-25 21:28:15,468 [salt.state       :1951][INFO    ][15209] Completed state [maas_create_iprange_1] at time 21:28:15.468165 duration_in_ms=54.378
2019-06-25 21:28:15,468 [salt.state       :1780][INFO    ][15209] Running state [vlan 0] at time 21:28:15.468595
2019-06-25 21:28:15,469 [salt.state       :1813][INFO    ][15209] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-25 21:28:15,522 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'gnmcfc', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:28:15,636 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'gnmcfc', 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'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:28:15,896 [salt.loaded.ext.module.maasng:945 ][INFO    ][15209] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'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'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'gnmcfc', 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'name': u'pxe_admin', u'id': 2}]
2019-06-25 21:28:15,951 [salt.state       :300 ][INFO    ][15209] {'new': 'Vlan untagged was updated'}
2019-06-25 21:28:15,952 [salt.state       :1951][INFO    ][15209] Completed state [vlan 0] at time 21:28:15.952105 duration_in_ms=483.508
2019-06-25 21:28:15,953 [salt.state       :1780][INFO    ][15209] Running state [opnfv] at time 21:28:15.953035
2019-06-25 21:28:15,953 [salt.state       :1813][INFO    ][15209] Executing state maasng.sshkey_present for [opnfv]
2019-06-25 21:28:16,004 [salt.loaded.ext.module.maasng:1903][INFO    ][15209] [{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-06-25 21:28:16,004 [salt.state       :300 ][INFO    ][15209] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-25 21:28:16,005 [salt.state       :1951][INFO    ][15209] Completed state [opnfv] at time 21:28:16.005120 duration_in_ms=52.086
2019-06-25 21:28:16,005 [salt.state       :1780][INFO    ][15209] Running state [maas.process_tags] at time 21:28:16.005547
2019-06-25 21:28:16,005 [salt.state       :1813][INFO    ][15209] Executing state module.run for [maas.process_tags]
2019-06-25 21:28:16,006 [salt.utils.decorators:613 ][WARNING ][15209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:28:16,052 [salt.loaded.ext.module.maas:92  ][INFO    ][15209] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-25 21:28:16,106 [salt.state       :300 ][INFO    ][15209] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-25 21:28:16,107 [salt.state       :1951][INFO    ][15209] Completed state [maas.process_tags] at time 21:28:16.107268 duration_in_ms=101.719
2019-06-25 21:28:16,111 [salt.minion      :1711][INFO    ][15209] Returning information for job: 20190625212749098434
2019-06-25 21:28:16,601 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212816589504
2019-06-25 21:28:16,616 [salt.minion      :1432][INFO    ][15658] Starting a new job with PID 15658
2019-06-25 21:28:20,421 [salt.state       :915 ][INFO    ][15658] Loading fresh modules for state activity
2019-06-25 21:28:20,490 [salt.state       :1780][INFO    ][15658] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:28:20.490637
2019-06-25 21:28:20,490 [salt.state       :1813][INFO    ][15658] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:28:20,492 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15658] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:28:21,928 [salt.state       :300 ][INFO    ][15658] {'pid': 15717, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:28:21,929 [salt.state       :1951][INFO    ][15658] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:28:21.929220 duration_in_ms=1438.584
2019-06-25 21:28:21,930 [salt.state       :1780][INFO    ][15658] Running state [maas.process_machines] at time 21:28:21.930433
2019-06-25 21:28:21,930 [salt.state       :1813][INFO    ][15658] Executing state module.run for [maas.process_machines]
2019-06-25 21:28:21,931 [salt.utils.decorators:613 ][WARNING ][15658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:28:22,751 [salt.loaded.ext.module.maas:412 ][WARNING ][15658] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:28:22,752 [salt.loaded.ext.module.maas:92  ][INFO    ][15658] 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=4hwags architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:28:24,021 [salt.loaded.ext.module.maas:412 ][WARNING ][15658] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:28:24,022 [salt.loaded.ext.module.maas:92  ][INFO    ][15658] 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=e6xmeq architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:28:25,500 [salt.loaded.ext.module.maas:412 ][WARNING ][15658] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:28:25,501 [salt.loaded.ext.module.maas:92  ][INFO    ][15658] machine hostname=odl01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=tkf7sy architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:28:26,811 [salt.loaded.ext.module.maas:412 ][WARNING ][15658] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:28:26,812 [salt.loaded.ext.module.maas:92  ][INFO    ][15658] 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=yteya8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:28:28,002 [salt.loaded.ext.module.maas:412 ][WARNING ][15658] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-25 21:28:28,003 [salt.loaded.ext.module.maas:92  ][INFO    ][15658] 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=gdeqra architecture=amd64/generic power_parameters_power_user=admin
2019-06-25 21:28:29,237 [salt.state       :300 ][INFO    ][15658] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-25 21:28:29,237 [salt.state       :1951][INFO    ][15658] Completed state [maas.process_machines] at time 21:28:29.237839 duration_in_ms=7307.404
2019-06-25 21:28:29,241 [salt.minion      :1711][INFO    ][15658] Returning information for job: 20190625212816589504
2019-06-25 21:29:02,574 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625212902560948
2019-06-25 21:29:02,596 [salt.minion      :1432][INFO    ][15946] Starting a new job with PID 15946
2019-06-25 21:29:06,248 [salt.state       :915 ][INFO    ][15946] Loading fresh modules for state activity
2019-06-25 21:29:06,336 [salt.state       :1780][INFO    ][15946] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:29:06.336749
2019-06-25 21:29:06,337 [salt.state       :1813][INFO    ][15946] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:29:06,339 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15946] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:29:07,801 [salt.state       :300 ][INFO    ][15946] {'pid': 15954, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:29:07,802 [salt.state       :1951][INFO    ][15946] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:29:07.802042 duration_in_ms=1465.294
2019-06-25 21:29:07,803 [salt.state       :1780][INFO    ][15946] Running state [maas.wait_for_machine_status] at time 21:29:07.803585
2019-06-25 21:29:07,803 [salt.state       :1813][INFO    ][15946] Executing state module.run for [maas.wait_for_machine_status]
2019-06-25 21:29:07,804 [salt.utils.decorators:613 ][WARNING ][15946] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:29:08,524 [salt.loaded.ext.module.maas:993 ][INFO    ][15946] Machine 4hwags mark broken
2019-06-25 21:29:09,188 [salt.loaded.ext.module.maas:996 ][INFO    ][15946] Machine 4hwags mark fixed
2019-06-25 21:29:10,522 [salt.loaded.ext.module.maas:684 ][INFO    ][15946] deploymachines hwe_kernel=hwe-16.04 system_id=4hwags distro_series=xenial
2019-06-25 21:29:16,247 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1491.56167197s left)
2019-06-25 21:29:17,649 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212917636366
2019-06-25 21:29:17,674 [salt.minion      :1432][INFO    ][16036] Starting a new job with PID 16036
2019-06-25 21:29:17,699 [salt.minion      :1711][INFO    ][16036] Returning information for job: 20190625212917636366
2019-06-25 21:29:47,700 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625212947687756
2019-06-25 21:29:47,725 [salt.minion      :1432][INFO    ][16089] Starting a new job with PID 16089
2019-06-25 21:29:47,748 [salt.minion      :1711][INFO    ][16089] Returning information for job: 20190625212947687756
2019-06-25 21:29:49,888 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1457.92009401s left)
2019-06-25 21:30:17,830 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213017767377
2019-06-25 21:30:17,851 [salt.minion      :1432][INFO    ][16117] Starting a new job with PID 16117
2019-06-25 21:30:17,872 [salt.minion      :1711][INFO    ][16117] Returning information for job: 20190625213017767377
2019-06-25 21:30:23,469 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1424.33966804s left)
2019-06-25 21:30:47,871 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213047857862
2019-06-25 21:30:47,893 [salt.minion      :1432][INFO    ][16167] Starting a new job with PID 16167
2019-06-25 21:30:47,919 [salt.minion      :1711][INFO    ][16167] Returning information for job: 20190625213047857862
2019-06-25 21:30:56,492 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1391.31635594s left)
2019-06-25 21:31:17,920 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213117906567
2019-06-25 21:31:17,943 [salt.minion      :1432][INFO    ][16243] Starting a new job with PID 16243
2019-06-25 21:31:17,968 [salt.minion      :1711][INFO    ][16243] Returning information for job: 20190625213117906567
2019-06-25 21:31:29,817 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1357.99185991s left)
2019-06-25 21:31:47,976 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213147962821
2019-06-25 21:31:47,998 [salt.minion      :1432][INFO    ][16353] Starting a new job with PID 16353
2019-06-25 21:31:48,023 [salt.minion      :1711][INFO    ][16353] Returning information for job: 20190625213147962821
2019-06-25 21:32:03,460 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1324.34826493s left)
2019-06-25 21:32:18,032 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213218019854
2019-06-25 21:32:18,054 [salt.minion      :1432][INFO    ][16384] Starting a new job with PID 16384
2019-06-25 21:32:18,080 [salt.minion      :1711][INFO    ][16384] Returning information for job: 20190625213218019854
2019-06-25 21:32:37,122 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1290.68663192s left)
2019-06-25 21:32:48,090 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213248078374
2019-06-25 21:32:48,113 [salt.minion      :1432][INFO    ][16529] Starting a new job with PID 16529
2019-06-25 21:32:48,140 [salt.minion      :1711][INFO    ][16529] Returning information for job: 20190625213248078374
2019-06-25 21:33:10,248 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1257.56017303s left)
2019-06-25 21:33:18,159 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213318146254
2019-06-25 21:33:18,181 [salt.minion      :1432][INFO    ][16569] Starting a new job with PID 16569
2019-06-25 21:33:18,208 [salt.minion      :1711][INFO    ][16569] Returning information for job: 20190625213318146254
2019-06-25 21:33:43,672 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1224.13649487s left)
2019-06-25 21:33:48,233 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213348218305
2019-06-25 21:33:48,258 [salt.minion      :1432][INFO    ][16674] Starting a new job with PID 16674
2019-06-25 21:33:48,289 [salt.minion      :1711][INFO    ][16674] Returning information for job: 20190625213348218305
2019-06-25 21:34:17,170 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1190.63832283s left)
2019-06-25 21:34:18,302 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213418289958
2019-06-25 21:34:18,324 [salt.minion      :1432][INFO    ][16708] Starting a new job with PID 16708
2019-06-25 21:34:18,352 [salt.minion      :1711][INFO    ][16708] Returning information for job: 20190625213418289958
2019-06-25 21:34:48,380 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213448368378
2019-06-25 21:34:48,403 [salt.minion      :1432][INFO    ][16848] Starting a new job with PID 16848
2019-06-25 21:34:48,431 [salt.minion      :1711][INFO    ][16848] Returning information for job: 20190625213448368378
2019-06-25 21:34:50,680 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1157.12867904s left)
2019-06-25 21:35:18,460 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213518449421
2019-06-25 21:35:18,476 [salt.minion      :1432][INFO    ][16884] Starting a new job with PID 16884
2019-06-25 21:35:18,503 [salt.minion      :1711][INFO    ][16884] Returning information for job: 20190625213518449421
2019-06-25 21:35:24,417 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1123.39134884s left)
2019-06-25 21:35:48,539 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213548526322
2019-06-25 21:35:48,562 [salt.minion      :1432][INFO    ][16993] Starting a new job with PID 16993
2019-06-25 21:35:48,591 [salt.minion      :1711][INFO    ][16993] Returning information for job: 20190625213548526322
2019-06-25 21:35:57,556 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1090.25257683s left)
2019-06-25 21:36:18,636 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213618624204
2019-06-25 21:36:18,655 [salt.minion      :1432][INFO    ][17048] Starting a new job with PID 17048
2019-06-25 21:36:18,696 [salt.minion      :1711][INFO    ][17048] Returning information for job: 20190625213618624204
2019-06-25 21:36:31,405 [salt.loaded.ext.module.maas:1023][INFO    ][15946] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1056.40360594s left)
2019-06-25 21:36:48,788 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command saltutil.find_job with jid 20190625213648775791
2019-06-25 21:36:48,812 [salt.minion      :1432][INFO    ][17106] Starting a new job with PID 17106
2019-06-25 21:36:48,837 [salt.minion      :1711][INFO    ][17106] Returning information for job: 20190625213648775791
2019-06-25 21:37:04,951 [salt.state       :300 ][INFO    ][15946] {'ret': True}
2019-06-25 21:37:04,952 [salt.state       :1951][INFO    ][15946] Completed state [maas.wait_for_machine_status] at time 21:37:04.952445 duration_in_ms=477148.855
2019-06-25 21:37:04,956 [salt.minion      :1711][INFO    ][15946] Returning information for job: 20190625212902560948
2019-06-25 21:37:05,600 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625213705587605
2019-06-25 21:37:05,623 [salt.minion      :1432][INFO    ][17134] Starting a new job with PID 17134
2019-06-25 21:37:09,380 [salt.state       :915 ][INFO    ][17134] Loading fresh modules for state activity
2019-06-25 21:37:09,527 [salt.state       :1780][INFO    ][17134] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:09.527085
2019-06-25 21:37:09,527 [salt.state       :1813][INFO    ][17134] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:37:09,529 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17134] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:37:10,982 [salt.state       :300 ][INFO    ][17134] {'pid': 17141, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:37:10,982 [salt.state       :1951][INFO    ][17134] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:10.982870 duration_in_ms=1455.785
2019-06-25 21:37:10,984 [salt.state       :1780][INFO    ][17134] Running state [maas_machines_storage_cmp002_lvm] at time 21:37:10.984314
2019-06-25 21:37:10,984 [salt.state       :1813][INFO    ][17134] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-25 21:37:11,697 [salt.state       :300 ][INFO    ][17134] Machine cmp002 is not in Ready state.
2019-06-25 21:37:11,697 [salt.state       :1951][INFO    ][17134] Completed state [maas_machines_storage_cmp002_lvm] at time 21:37:11.697749 duration_in_ms=713.433
2019-06-25 21:37:11,698 [salt.state       :1780][INFO    ][17134] Running state [maas_machines_storage_cmp001_lvm] at time 21:37:11.698336
2019-06-25 21:37:11,698 [salt.state       :1813][INFO    ][17134] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-25 21:37:12,363 [salt.state       :300 ][INFO    ][17134] Machine cmp001 is not in Ready state.
2019-06-25 21:37:12,364 [salt.state       :1951][INFO    ][17134] Completed state [maas_machines_storage_cmp001_lvm] at time 21:37:12.364296 duration_in_ms=665.959
2019-06-25 21:37:12,368 [salt.minion      :1711][INFO    ][17134] Returning information for job: 20190625213705587605
2019-06-25 21:37:12,996 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625213712982439
2019-06-25 21:37:13,018 [salt.minion      :1432][INFO    ][17168] Starting a new job with PID 17168
2019-06-25 21:37:13,760 [salt.state       :915 ][INFO    ][17168] Loading fresh modules for state activity
2019-06-25 21:37:13,851 [salt.state       :1780][INFO    ][17168] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:13.851758
2019-06-25 21:37:13,852 [salt.state       :1813][INFO    ][17168] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:37:13,854 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17168] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:37:15,239 [salt.state       :300 ][INFO    ][17168] {'pid': 17175, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:37:15,240 [salt.state       :1951][INFO    ][17168] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:15.240073 duration_in_ms=1388.316
2019-06-25 21:37:15,241 [salt.state       :1780][INFO    ][17168] Running state [maas.deploy_machines] at time 21:37:15.241202
2019-06-25 21:37:15,241 [salt.state       :1813][INFO    ][17168] Executing state module.run for [maas.deploy_machines]
2019-06-25 21:37:15,241 [salt.utils.decorators:613 ][WARNING ][17168] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:37:15,670 [salt.state       :300 ][INFO    ][17168] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-25 21:37:15,670 [salt.state       :1951][INFO    ][17168] Completed state [maas.deploy_machines] at time 21:37:15.670569 duration_in_ms=429.364
2019-06-25 21:37:15,673 [salt.minion      :1711][INFO    ][17168] Returning information for job: 20190625213712982439
2019-06-25 21:37:16,281 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command state.apply with jid 20190625213716268081
2019-06-25 21:37:16,303 [salt.minion      :1432][INFO    ][17184] Starting a new job with PID 17184
2019-06-25 21:37:17,046 [salt.state       :915 ][INFO    ][17184] Loading fresh modules for state activity
2019-06-25 21:37:17,137 [salt.state       :1780][INFO    ][17184] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:17.137144
2019-06-25 21:37:17,137 [salt.state       :1813][INFO    ][17184] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-25 21:37:17,139 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17184] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-25 21:37:18,691 [salt.state       :300 ][INFO    ][17184] {'pid': 17191, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-25 21:37:18,691 [salt.state       :1951][INFO    ][17184] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:37:18.691870 duration_in_ms=1554.726
2019-06-25 21:37:18,693 [salt.state       :1780][INFO    ][17184] Running state [maas.wait_for_machine_status] at time 21:37:18.693494
2019-06-25 21:37:18,693 [salt.state       :1813][INFO    ][17184] Executing state module.run for [maas.wait_for_machine_status]
2019-06-25 21:37:18,694 [salt.utils.decorators:613 ][WARNING ][17184] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-25 21:37:21,436 [salt.state       :300 ][INFO    ][17184] {'ret': True}
2019-06-25 21:37:21,437 [salt.state       :1951][INFO    ][17184] Completed state [maas.wait_for_machine_status] at time 21:37:21.437377 duration_in_ms=2743.881
2019-06-25 21:37:21,441 [salt.minion      :1711][INFO    ][17184] Returning information for job: 20190625213716268081
2019-06-25 22:08:10,142 [salt.utils.schedule:1377][INFO    ][8189] Running scheduled job: __mine_interval
2019-06-25 22:30:46,192 [salt.minion      :1308][INFO    ][8189] User sudo_ubuntu Executing command cp.push_dir with jid 20190625223046180416
2019-06-25 22:30:46,214 [salt.minion      :1432][INFO    ][21322] Starting a new job with PID 21322
