2019-09-15 02:02:27,063 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-15 02:03:17,114 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-15 02:04:07,167 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-15 02:04:57,216 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-15 02:05:47,262 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-15 02:07:56,151 [salt.utils.decorators:613 ][WARNING ][2713] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 02:07:56,762 [salt.utils.decorators:613 ][WARNING ][2713] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 02:07:58,996 [salt.loaded.int.states.file:2298][WARNING ][2854] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-09-15 02:08:04,270 [salt.state       :2022][WARNING ][2964] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-15 02:08:06,790 [salt.utils.decorators:613 ][WARNING ][2964] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 02:23:12,572 [salt.utils.decorators:613 ][WARNING ][2964] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 02:44:56,545 [salt.utils.decorators:613 ][WARNING ][2964] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:00:01,675 [salt.utils.decorators:613 ][WARNING ][2964] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:00:05,479 [salt.loaded.ext.module.maasng:1008][WARNING ][2964] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-09-15 03:00:05,480 [salt.loaded.ext.module.maasng:1011][WARNING ][2964] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-09-15 03:00:06,102 [salt.loaded.ext.module.maasng:1235][WARNING ][2964] Ignoring parameter vlan:0
2019-09-15 03:00:08,686 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31769] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-15 03:00:08,714 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31769] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-09-15 03:00:08,735 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-09-15 03:00:09,673 [salt.cli.daemons :293 ][INFO    ][31844] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-09-15 03:00:09,752 [salt.cli.daemons :82  ][INFO    ][31844] Starting up the Salt Minion
2019-09-15 03:00:09,752 [salt.utils.event :1017][INFO    ][31844] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-09-15 03:00:10,571 [salt.minion      :976 ][INFO    ][31844] Creating minion process manager
2019-09-15 03:00:12,083 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][31844] Executing command ['date', '+%z'] in directory '/root'
2019-09-15 03:00:12,121 [salt.utils.schedule:568 ][INFO    ][31844] Updating job settings for scheduled job: __mine_interval
2019-09-15 03:00:12,122 [salt.minion      :1108][INFO    ][31844] Added mine.update to scheduler
2019-09-15 03:00:12,126 [salt.minion      :1975][INFO    ][31844] Minion is starting as user 'root'
2019-09-15 03:00:12,135 [salt.minion      :2336][INFO    ][31844] Minion is ready to receive requests!
2019-09-15 03:00:12,323 [salt.utils.decorators:613 ][WARNING ][31779] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:00:12,380 [salt.loaded.ext.module.maas:412 ][WARNING ][31779] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:00:17,393 [salt.loaded.ext.module.maas:412 ][WARNING ][31779] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:00:22,046 [salt.loaded.ext.module.maas:412 ][WARNING ][31779] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:00:22,556 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030022544255
2019-09-15 03:00:22,575 [salt.minion      :1432][INFO    ][32046] Starting a new job with PID 32046
2019-09-15 03:00:22,600 [salt.minion      :1711][INFO    ][32046] Returning information for job: 20190915030022544255
2019-09-15 03:00:27,022 [salt.loaded.ext.module.maas:412 ][WARNING ][31779] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:00:31,620 [salt.loaded.ext.module.maas:412 ][WARNING ][31779] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:01:07,396 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915030107382700
2019-09-15 03:01:07,418 [salt.minion      :1432][INFO    ][32271] Starting a new job with PID 32271
2019-09-15 03:01:10,966 [salt.state       :915 ][INFO    ][32271] Loading fresh modules for state activity
2019-09-15 03:01:11,003 [salt.fileclient  :1219][INFO    ][32271] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-09-15 03:01:11,040 [salt.state       :1780][INFO    ][32271] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:11.040498
2019-09-15 03:01:11,040 [salt.state       :1813][INFO    ][32271] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:01:11,042 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32271] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:01:12,282 [salt.state       :300 ][INFO    ][32271] {'pid': 32278, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:01:12,283 [salt.state       :1951][INFO    ][32271] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:12.283640 duration_in_ms=1243.142
2019-09-15 03:01:12,286 [salt.state       :1780][INFO    ][32271] Running state [maas.wait_for_machine_status] at time 03:01:12.286651
2019-09-15 03:01:12,287 [salt.state       :1813][INFO    ][32271] Executing state module.run for [maas.wait_for_machine_status]
2019-09-15 03:01:12,287 [salt.utils.decorators:613 ][WARNING ][32271] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:01:13,042 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.25547504s left)
2019-09-15 03:01:22,473 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030122460704
2019-09-15 03:01:22,496 [salt.minion      :1432][INFO    ][32291] Starting a new job with PID 32291
2019-09-15 03:01:22,519 [salt.minion      :1711][INFO    ][32291] Returning information for job: 20190915030122460704
2019-09-15 03:01:44,036 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.26155901s left)
2019-09-15 03:01:52,525 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030152512579
2019-09-15 03:01:52,548 [salt.minion      :1432][INFO    ][32310] Starting a new job with PID 32310
2019-09-15 03:01:52,570 [salt.minion      :1711][INFO    ][32310] Returning information for job: 20190915030152512579
2019-09-15 03:02:15,249 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.04812813s left)
2019-09-15 03:02:22,589 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030222576235
2019-09-15 03:02:22,612 [salt.minion      :1432][INFO    ][32507] Starting a new job with PID 32507
2019-09-15 03:02:22,635 [salt.minion      :1711][INFO    ][32507] Returning information for job: 20190915030222576235
2019-09-15 03:02:46,619 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.67804813s left)
2019-09-15 03:02:52,639 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030252625946
2019-09-15 03:02:52,661 [salt.minion      :1432][INFO    ][32628] Starting a new job with PID 32628
2019-09-15 03:02:52,685 [salt.minion      :1711][INFO    ][32628] Returning information for job: 20190915030252625946
2019-09-15 03:03:18,133 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.16429901s left)
2019-09-15 03:03:22,683 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030322674197
2019-09-15 03:03:22,702 [salt.minion      :1432][INFO    ][898] Starting a new job with PID 898
2019-09-15 03:03:22,715 [salt.minion      :1711][INFO    ][898] Returning information for job: 20190915030322674197
2019-09-15 03:03:50,134 [salt.loaded.ext.module.maas:1023][INFO    ][32271] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.16286111s left)
2019-09-15 03:03:52,717 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030352705577
2019-09-15 03:03:52,740 [salt.minion      :1432][INFO    ][978] Starting a new job with PID 978
2019-09-15 03:03:52,764 [salt.minion      :1711][INFO    ][978] Returning information for job: 20190915030352705577
2019-09-15 03:04:22,770 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030422762765
2019-09-15 03:04:22,783 [salt.minion      :1432][INFO    ][1173] Starting a new job with PID 1173
2019-09-15 03:04:22,797 [salt.minion      :1711][INFO    ][1173] Returning information for job: 20190915030422762765
2019-09-15 03:04:24,434 [salt.state       :300 ][INFO    ][32271] {'ret': True}
2019-09-15 03:04:24,434 [salt.state       :1951][INFO    ][32271] Completed state [maas.wait_for_machine_status] at time 03:04:24.434753 duration_in_ms=192148.101
2019-09-15 03:04:24,438 [salt.minion      :1711][INFO    ][32271] Returning information for job: 20190915030107382700
2019-09-15 03:04:24,952 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915030424938826
2019-09-15 03:04:24,969 [salt.minion      :1432][INFO    ][1218] Starting a new job with PID 1218
2019-09-15 03:04:29,584 [salt.state       :915 ][INFO    ][1218] Loading fresh modules for state activity
2019-09-15 03:04:29,616 [salt.fileclient  :1219][INFO    ][1218] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-09-15 03:04:29,680 [salt.state       :1780][INFO    ][1218] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:04:29.680157
2019-09-15 03:04:29,680 [salt.state       :1813][INFO    ][1218] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:04:29,681 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1218] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:04:31,000 [salt.state       :300 ][INFO    ][1218] {'pid': 1227, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:04:31,001 [salt.state       :1951][INFO    ][1218] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:04:31.001386 duration_in_ms=1321.23
2019-09-15 03:04:31,003 [salt.state       :1780][INFO    ][1218] Running state [maas_machines_storage_cmp002_lvm] at time 03:04:31.002989
2019-09-15 03:04:31,003 [salt.state       :1813][INFO    ][1218] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-15 03:04:31,974 [salt.loaded.ext.module.maasng:610 ][INFO    ][1218] s7nc37
2019-09-15 03:04:31,975 [salt.loaded.ext.module.maasng:626 ][INFO    ][1218] sda
2019-09-15 03:04:32,481 [salt.loaded.ext.module.maasng:361 ][INFO    ][1218] s7nc37
2019-09-15 03:04:32,595 [salt.loaded.ext.module.maasng:367 ][INFO    ][1218] [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'id': 4, u'system_id': u's7nc37', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'e7b07b45-2a62-43c8-8759-fbc7bde23c02', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u's7nc37', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b696ba57-2d19-43cc-b5e3-ffde6e865ad6', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/partition/5'}]}, {u'size': 2397988454400, u'available_size': 0, u'uuid': u'0441bc0c-8b80-4816-b86a-d2418fb5ef01', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/10/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'id': 10, u'system_id': u's7nc37', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'fd54c1e1-f068-4760-831d-0505668b102d', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'partitions': []}]
2019-09-15 03:04:32,595 [salt.loaded.ext.module.maasng:632 ][INFO    ][1218] vgroot
2019-09-15 03:04:32,595 [salt.loaded.ext.module.maasng:635 ][INFO    ][1218] lvroot
2019-09-15 03:04:32,595 [salt.loaded.ext.module.maasng:639 ][INFO    ][1218] 107374182400
2019-09-15 03:04:33,196 [salt.loaded.ext.module.maasng:645 ][INFO    ][1218] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', 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'id': 31, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', 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:6a', u'parents': [], u'params': u'', u'system_id': u's7nc37', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/interfaces/4/'}, u'fqdn': u'cmp002.maas', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u's7nc37', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'd5a8bb54-1bcd-4a19-9f23-76c3ec0180f7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u's7nc37', u'filesystem': {u'uuid': u'973322c8-c0a2-4824-a413-e7fc2367ee9c', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}]}, u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'resource_uri': u'/MAAS/api/2.0/machines/s7nc37/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u's7nc37', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.40'], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u's7nc37', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'd5a8bb54-1bcd-4a19-9f23-76c3ec0180f7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u's7nc37', u'filesystem': {u'uuid': u'973322c8-c0a2-4824-a413-e7fc2367ee9c', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}]}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/11/', u'type': u'virtual', u'tags': [], u'uuid': u'e2fb0a89-77cc-4ddb-9daf-b949308c0d32', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u's7nc37', u'partition_table_type': None, u'filesystem': {u'uuid': u'1a752d06-1a68-4cbc-93ca-26752efc4b9a', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u's7nc37', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u's7nc37', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'd5a8bb54-1bcd-4a19-9f23-76c3ec0180f7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u's7nc37', u'filesystem': {u'uuid': u'973322c8-c0a2-4824-a413-e7fc2367ee9c', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}]}], u'netboot': True, u'osystem': u'', u'node_type': 0, u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/blockdevices/11/', u'type': u'virtual', u'tags': [], u'uuid': u'e2fb0a89-77cc-4ddb-9daf-b949308c0d32', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u's7nc37', u'partition_table_type': None, u'filesystem': {u'uuid': u'1a752d06-1a68-4cbc-93ca-26752efc4b9a', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', 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'id': 31, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', 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:6a', u'parents': [], u'params': u'', u'system_id': u's7nc37', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/interfaces/4/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 34, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'params': u'', u'system_id': u's7nc37', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'params': u'', u'system_id': u's7nc37', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/interfaces/19/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'params': u'', u'system_id': u's7nc37', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/s7nc37/interfaces/20/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-09-15 03:04:33,199 [salt.state       :300 ][INFO    ][1218] {'new': {'storage_layout': 'lvm'}}
2019-09-15 03:04:33,200 [salt.state       :1951][INFO    ][1218] Completed state [maas_machines_storage_cmp002_lvm] at time 03:04:33.200108 duration_in_ms=2197.116
2019-09-15 03:04:33,201 [salt.state       :1780][INFO    ][1218] Running state [maas_machines_storage_cmp001_lvm] at time 03:04:33.200909
2019-09-15 03:04:33,201 [salt.state       :1813][INFO    ][1218] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-15 03:04:34,428 [salt.loaded.ext.module.maasng:610 ][INFO    ][1218] rrasen
2019-09-15 03:04:34,428 [salt.loaded.ext.module.maasng:626 ][INFO    ][1218] sda
2019-09-15 03:04:34,967 [salt.loaded.ext.module.maasng:361 ][INFO    ][1218] rrasen
2019-09-15 03:04:35,053 [salt.loaded.ext.module.maasng:367 ][INFO    ][1218] [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'id': 1, u'system_id': u'rrasen', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'2c0e2227-239a-4ca6-9fe7-87b88d3c18ad', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrasen', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'43eed303-a272-4ac2-9b50-3e3ac06e00b0', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/partition/1'}]}, {u'size': 2397988454400, u'available_size': 0, u'uuid': u'd43d1833-19b2-4888-b34e-e385b134af3b', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/6/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'id': 6, u'system_id': u'rrasen', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'8ceb4027-23b5-4f37-9399-3f6d52999900', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'partitions': []}]
2019-09-15 03:04:35,054 [salt.loaded.ext.module.maasng:632 ][INFO    ][1218] vgroot
2019-09-15 03:04:35,054 [salt.loaded.ext.module.maasng:635 ][INFO    ][1218] lvroot
2019-09-15 03:04:35,055 [salt.loaded.ext.module.maasng:639 ][INFO    ][1218] 107374182400
2019-09-15 03:04:35,804 [salt.loaded.ext.module.maasng:645 ][INFO    ][1218] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'system_id': u'rrasen', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/interfaces/5/'}, u'fqdn': u'cmp001.maas', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrasen', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'e7a072ba-c3a3-4433-b005-3384f46562fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrasen', u'filesystem': {u'uuid': u'415929f1-a5bc-492e-9549-58e8c0a372e6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/partition/7', u'type': u'partition', u'id': 7, u'device_id': 1}]}, u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'resource_uri': u'/MAAS/api/2.0/machines/rrasen/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'rrasen', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.38'], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrasen', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'e7a072ba-c3a3-4433-b005-3384f46562fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrasen', u'filesystem': {u'uuid': u'415929f1-a5bc-492e-9549-58e8c0a372e6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/partition/7', u'type': u'partition', u'id': 7, u'device_id': 1}]}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'ef6c8162-f5c4-4f58-a487-e583fe2ae393', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rrasen', u'partition_table_type': None, u'filesystem': {u'uuid': u'97dd6461-2031-41e1-a377-98144affb3a9', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'rrasen', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrasen', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'e7a072ba-c3a3-4433-b005-3384f46562fa', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrasen', u'filesystem': {u'uuid': u'415929f1-a5bc-492e-9549-58e8c0a372e6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/1/partition/7', u'type': u'partition', u'id': 7, u'device_id': 1}]}], u'netboot': True, u'osystem': u'', u'node_type': 0, u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'ef6c8162-f5c4-4f58-a487-e583fe2ae393', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rrasen', u'partition_table_type': None, u'filesystem': {u'uuid': u'97dd6461-2031-41e1-a377-98144affb3a9', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'system_id': u'rrasen', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'params': u'', u'system_id': u'rrasen', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/interfaces/9/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'params': u'', u'system_id': u'rrasen', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/interfaces/10/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'params': u'', u'system_id': u'rrasen', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/rrasen/interfaces/11/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-09-15 03:04:35,807 [salt.state       :300 ][INFO    ][1218] {'new': {'storage_layout': 'lvm'}}
2019-09-15 03:04:35,808 [salt.state       :1951][INFO    ][1218] Completed state [maas_machines_storage_cmp001_lvm] at time 03:04:35.808074 duration_in_ms=2607.164
2019-09-15 03:04:35,812 [salt.minion      :1711][INFO    ][1218] Returning information for job: 20190915030424938826
2019-09-15 03:04:36,382 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915030436375070
2019-09-15 03:04:36,400 [salt.minion      :1432][INFO    ][1259] Starting a new job with PID 1259
2019-09-15 03:04:37,139 [salt.state       :915 ][INFO    ][1259] Loading fresh modules for state activity
2019-09-15 03:04:37,167 [salt.fileclient  :1219][INFO    ][1259] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-09-15 03:04:37,194 [salt.state       :1780][INFO    ][1259] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:04:37.194175
2019-09-15 03:04:37,194 [salt.state       :1813][INFO    ][1259] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:04:37,195 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1259] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:04:38,445 [salt.state       :300 ][INFO    ][1259] {'pid': 1266, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:04:38,445 [salt.state       :1951][INFO    ][1259] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:04:38.445539 duration_in_ms=1251.364
2019-09-15 03:04:38,447 [salt.state       :1780][INFO    ][1259] Running state [maas.deploy_machines] at time 03:04:38.447456
2019-09-15 03:04:38,447 [salt.state       :1813][INFO    ][1259] Executing state module.run for [maas.deploy_machines]
2019-09-15 03:04:38,448 [salt.utils.decorators:613 ][WARNING ][1259] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:04:38,882 [salt.loaded.ext.module.maas:684 ][INFO    ][1259] deploymachines hwe_kernel=ga-16.04 system_id=s7nc37 distro_series=xenial
2019-09-15 03:04:43,755 [salt.loaded.ext.module.maas:684 ][INFO    ][1259] deploymachines hwe_kernel=ga-16.04 system_id=rrasen distro_series=xenial
2019-09-15 03:04:50,564 [salt.loaded.ext.module.maas:684 ][INFO    ][1259] deploymachines hwe_kernel=ga-16.04 system_id=prfp3h distro_series=xenial
2019-09-15 03:04:51,409 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030451402028
2019-09-15 03:04:51,422 [salt.minion      :1432][INFO    ][1387] Starting a new job with PID 1387
2019-09-15 03:04:51,434 [salt.minion      :1711][INFO    ][1387] Returning information for job: 20190915030451402028
2019-09-15 03:04:55,527 [salt.loaded.ext.module.maas:684 ][INFO    ][1259] deploymachines hwe_kernel=ga-16.04 system_id=a7khd8 distro_series=xenial
2019-09-15 03:05:01,736 [salt.loaded.ext.module.maas:684 ][INFO    ][1259] deploymachines hwe_kernel=ga-16.04 system_id=wkqe7f distro_series=xenial
2019-09-15 03:05:07,578 [salt.state       :300 ][INFO    ][1259] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-09-15 03:05:07,579 [salt.state       :1951][INFO    ][1259] Completed state [maas.deploy_machines] at time 03:05:07.579074 duration_in_ms=29131.617
2019-09-15 03:05:07,582 [salt.minion      :1711][INFO    ][1259] Returning information for job: 20190915030436375070
2019-09-15 03:05:08,176 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915030508163542
2019-09-15 03:05:08,198 [salt.minion      :1432][INFO    ][1607] Starting a new job with PID 1607
2019-09-15 03:05:11,660 [salt.state       :915 ][INFO    ][1607] Loading fresh modules for state activity
2019-09-15 03:05:11,699 [salt.fileclient  :1219][INFO    ][1607] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-09-15 03:05:11,733 [salt.state       :1780][INFO    ][1607] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:05:11.733829
2019-09-15 03:05:11,734 [salt.state       :1813][INFO    ][1607] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:05:11,735 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1607] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:05:13,024 [salt.state       :300 ][INFO    ][1607] {'pid': 1615, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:05:13,025 [salt.state       :1951][INFO    ][1607] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:05:13.025548 duration_in_ms=1291.718
2019-09-15 03:05:13,027 [salt.state       :1780][INFO    ][1607] Running state [maas.wait_for_machine_status] at time 03:05:13.027758
2019-09-15 03:05:13,028 [salt.state       :1813][INFO    ][1607] Executing state module.run for [maas.wait_for_machine_status]
2019-09-15 03:05:13,028 [salt.utils.decorators:613 ][WARNING ][1607] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:05:15,961 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.07432604s left)
2019-09-15 03:05:23,284 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030523271074
2019-09-15 03:05:23,304 [salt.minion      :1432][INFO    ][1637] Starting a new job with PID 1637
2019-09-15 03:05:23,327 [salt.minion      :1711][INFO    ][1637] Returning information for job: 20190915030523271074
2019-09-15 03:05:48,573 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.46184301s left)
2019-09-15 03:05:53,351 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030553336843
2019-09-15 03:05:53,372 [salt.minion      :1432][INFO    ][1671] Starting a new job with PID 1671
2019-09-15 03:05:53,397 [salt.minion      :1711][INFO    ][1671] Returning information for job: 20190915030553336843
2019-09-15 03:06:22,496 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.53927422s left)
2019-09-15 03:06:23,450 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030623437357
2019-09-15 03:06:23,471 [salt.minion      :1432][INFO    ][1749] Starting a new job with PID 1749
2019-09-15 03:06:23,487 [salt.minion      :1711][INFO    ][1749] Returning information for job: 20190915030623437357
2019-09-15 03:06:53,664 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030653656997
2019-09-15 03:06:53,679 [salt.minion      :1432][INFO    ][1932] Starting a new job with PID 1932
2019-09-15 03:06:53,692 [salt.minion      :1711][INFO    ][1932] Returning information for job: 20190915030653656997
2019-09-15 03:06:56,777 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.25813103s left)
2019-09-15 03:07:23,707 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030723695176
2019-09-15 03:07:23,728 [salt.minion      :1432][INFO    ][2512] Starting a new job with PID 2512
2019-09-15 03:07:23,751 [salt.minion      :1711][INFO    ][2512] Returning information for job: 20190915030723695176
2019-09-15 03:07:30,163 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.87169313s left)
2019-09-15 03:07:53,762 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030753749409
2019-09-15 03:07:53,782 [salt.minion      :1432][INFO    ][2556] Starting a new job with PID 2556
2019-09-15 03:07:53,803 [salt.minion      :1711][INFO    ][2556] Returning information for job: 20190915030753749409
2019-09-15 03:08:03,923 [salt.loaded.ext.module.maas:1023][INFO    ][1607] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.11220217s left)
2019-09-15 03:08:23,815 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030823803717
2019-09-15 03:08:23,832 [salt.minion      :1432][INFO    ][3260] Starting a new job with PID 3260
2019-09-15 03:08:23,847 [salt.minion      :1711][INFO    ][3260] Returning information for job: 20190915030823803717
2019-09-15 03:08:53,880 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030853868698
2019-09-15 03:08:53,898 [salt.minion      :1432][INFO    ][3320] Starting a new job with PID 3320
2019-09-15 03:08:53,916 [salt.minion      :1711][INFO    ][3320] Returning information for job: 20190915030853868698
2019-09-15 03:09:23,965 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030923952293
2019-09-15 03:09:23,988 [salt.minion      :1432][INFO    ][3546] Starting a new job with PID 3546
2019-09-15 03:09:24,012 [salt.minion      :1711][INFO    ][3546] Returning information for job: 20190915030923952293
2019-09-15 03:09:54,057 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915030954044164
2019-09-15 03:09:54,079 [salt.minion      :1432][INFO    ][3589] Starting a new job with PID 3589
2019-09-15 03:09:54,103 [salt.minion      :1711][INFO    ][3589] Returning information for job: 20190915030954044164
2019-09-15 03:10:24,156 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031024145517
2019-09-15 03:10:24,175 [salt.minion      :1432][INFO    ][3762] Starting a new job with PID 3762
2019-09-15 03:10:24,192 [salt.minion      :1711][INFO    ][3762] Returning information for job: 20190915031024145517
2019-09-15 03:10:54,245 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031054233225
2019-09-15 03:10:54,263 [salt.minion      :1432][INFO    ][3800] Starting a new job with PID 3800
2019-09-15 03:10:54,281 [salt.minion      :1711][INFO    ][3800] Returning information for job: 20190915031054233225
2019-09-15 03:11:24,344 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031124331851
2019-09-15 03:11:24,367 [salt.minion      :1432][INFO    ][3940] Starting a new job with PID 3940
2019-09-15 03:11:24,391 [salt.minion      :1711][INFO    ][3940] Returning information for job: 20190915031124331851
2019-09-15 03:11:54,468 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031154455449
2019-09-15 03:11:54,486 [salt.minion      :1432][INFO    ][3974] Starting a new job with PID 3974
2019-09-15 03:11:54,510 [salt.minion      :1711][INFO    ][3974] Returning information for job: 20190915031154455449
2019-09-15 03:12:24,575 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031224562388
2019-09-15 03:12:24,598 [salt.minion      :1432][INFO    ][4066] Starting a new job with PID 4066
2019-09-15 03:12:24,618 [salt.minion      :1711][INFO    ][4066] Returning information for job: 20190915031224562388
2019-09-15 03:12:54,702 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031254685792
2019-09-15 03:12:54,727 [salt.minion      :1432][INFO    ][4129] Starting a new job with PID 4129
2019-09-15 03:12:54,752 [salt.minion      :1711][INFO    ][4129] Returning information for job: 20190915031254685792
2019-09-15 03:13:24,816 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031324806978
2019-09-15 03:13:24,835 [salt.minion      :1432][INFO    ][4182] Starting a new job with PID 4182
2019-09-15 03:13:24,852 [salt.minion      :1711][INFO    ][4182] Returning information for job: 20190915031324806978
2019-09-15 03:13:54,930 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031354916263
2019-09-15 03:13:54,953 [salt.minion      :1432][INFO    ][4220] Starting a new job with PID 4220
2019-09-15 03:13:54,978 [salt.minion      :1711][INFO    ][4220] Returning information for job: 20190915031354916263
2019-09-15 03:14:25,064 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031425054017
2019-09-15 03:14:25,084 [salt.minion      :1432][INFO    ][4258] Starting a new job with PID 4258
2019-09-15 03:14:25,109 [salt.minion      :1711][INFO    ][4258] Returning information for job: 20190915031425054017
2019-09-15 03:14:39,563 [salt.state       :302 ][ERROR   ][1607] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-09-15 03:14:39,564 [salt.state       :1951][INFO    ][1607] Completed state [maas.wait_for_machine_status] at time 03:14:39.563943 duration_in_ms=566536.183
2019-09-15 03:14:39,568 [salt.minion      :1711][INFO    ][1607] Returning information for job: 20190915030508163542
2019-09-15 03:14:50,249 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command pillar.get with jid 20190915031450237448
2019-09-15 03:14:50,270 [salt.minion      :1432][INFO    ][4495] Starting a new job with PID 4495
2019-09-15 03:14:50,278 [salt.minion      :1711][INFO    ][4495] Returning information for job: 20190915031450237448
2019-09-15 03:14:50,777 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command service.status with jid 20190915031450765524
2019-09-15 03:14:50,800 [salt.minion      :1432][INFO    ][4500] Starting a new job with PID 4500
2019-09-15 03:14:51,170 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4500] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-15 03:14:51,204 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4500] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-15 03:14:51,220 [salt.minion      :1711][INFO    ][4500] Returning information for job: 20190915031450765524
2019-09-15 03:14:51,744 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915031451736948
2019-09-15 03:14:51,765 [salt.minion      :1432][INFO    ][4512] Starting a new job with PID 4512
2019-09-15 03:14:55,465 [salt.state       :915 ][INFO    ][4512] Loading fresh modules for state activity
2019-09-15 03:14:55,903 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:14:56,258 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:14:57,235 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:14:57,587 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:14:58,968 [salt.state       :1780][INFO    ][4512] Running state [salt-minion] at time 03:14:58.968550
2019-09-15 03:14:58,968 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [salt-minion]
2019-09-15 03:14:58,969 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:14:59,049 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,049 [salt.state       :1951][INFO    ][4512] Completed state [salt-minion] at time 03:14:59.049724 duration_in_ms=81.174
2019-09-15 03:14:59,050 [salt.state       :1780][INFO    ][4512] Running state [salt_minion_dependency_packages] at time 03:14:59.050028
2019-09-15 03:14:59,050 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-15 03:14:59,055 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,056 [salt.state       :1951][INFO    ][4512] Completed state [salt_minion_dependency_packages] at time 03:14:59.056116 duration_in_ms=6.088
2019-09-15 03:14:59,058 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/minion.d/minion.conf] at time 03:14:59.058898
2019-09-15 03:14:59,059 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-15 03:14:59,248 [salt.state       :300 ][INFO    ][4512] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-15 03:14:59,248 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/minion.d/minion.conf] at time 03:14:59.248600 duration_in_ms=189.702
2019-09-15 03:14:59,248 [salt.state       :1780][INFO    ][4512] Running state [python-netaddr] at time 03:14:59.248837
2019-09-15 03:14:59,249 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [python-netaddr]
2019-09-15 03:14:59,254 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,254 [salt.state       :1951][INFO    ][4512] Completed state [python-netaddr] at time 03:14:59.254430 duration_in_ms=5.593
2019-09-15 03:14:59,256 [salt.state       :1780][INFO    ][4512] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:14:59.256929
2019-09-15 03:14:59,257 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-15 03:14:59,266 [salt.state       :300 ][INFO    ][4512] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-15 03:14:59,266 [salt.state       :1951][INFO    ][4512] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:14:59.266657 duration_in_ms=9.728
2019-09-15 03:14:59,267 [salt.state       :1780][INFO    ][4512] Running state [salt-minion] at time 03:14:59.267336
2019-09-15 03:14:59,267 [salt.state       :1813][INFO    ][4512] Executing state service.running for [salt-minion]
2019-09-15 03:14:59,268 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-15 03:14:59,304 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-15 03:14:59,320 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-15 03:14:59,338 [salt.state       :300 ][INFO    ][4512] The service salt-minion is already running
2019-09-15 03:14:59,338 [salt.state       :1951][INFO    ][4512] Completed state [salt-minion] at time 03:14:59.338387 duration_in_ms=71.051
2019-09-15 03:14:59,339 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains.d] at time 03:14:59.339732
2019-09-15 03:14:59,340 [salt.state       :1813][INFO    ][4512] Executing state file.directory for [/etc/salt/grains.d]
2019-09-15 03:14:59,340 [salt.state       :300 ][INFO    ][4512] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-15 03:14:59,341 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains.d] at time 03:14:59.341107 duration_in_ms=1.375
2019-09-15 03:14:59,341 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains] at time 03:14:59.341755
2019-09-15 03:14:59,342 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/grains]
2019-09-15 03:14:59,342 [salt.state       :300 ][INFO    ][4512] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-15 03:14:59,342 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains] at time 03:14:59.342753 duration_in_ms=0.998
2019-09-15 03:14:59,343 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains.d/placeholder] at time 03:14:59.343173
2019-09-15 03:14:59,343 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-15 03:14:59,343 [salt.state       :300 ][INFO    ][4512] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-15 03:14:59,344 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains.d/placeholder] at time 03:14:59.344128 duration_in_ms=0.955
2019-09-15 03:14:59,344 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains.d/sphinx] at time 03:14:59.344554
2019-09-15 03:14:59,344 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-15 03:14:59,356 [salt.state       :300 ][INFO    ][4512] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-15 03:14:59,356 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains.d/sphinx] at time 03:14:59.356260 duration_in_ms=11.705
2019-09-15 03:14:59,358 [salt.state       :1780][INFO    ][4512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.357993
2019-09-15 03:14:59,358 [salt.state       :1813][INFO    ][4512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:14:59,358 [salt.state       :300 ][INFO    ][4512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:14:59,358 [salt.state       :1951][INFO    ][4512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.358677 duration_in_ms=0.683
2019-09-15 03:14:59,359 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains.d/dns_records] at time 03:14:59.359054
2019-09-15 03:14:59,359 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-15 03:14:59,367 [salt.state       :300 ][INFO    ][4512] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-15 03:14:59,368 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains.d/dns_records] at time 03:14:59.368012 duration_in_ms=8.958
2019-09-15 03:14:59,368 [salt.state       :1780][INFO    ][4512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.368699
2019-09-15 03:14:59,368 [salt.state       :1813][INFO    ][4512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:14:59,369 [salt.state       :300 ][INFO    ][4512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:14:59,369 [salt.state       :1951][INFO    ][4512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.369355 duration_in_ms=0.656
2019-09-15 03:14:59,369 [salt.state       :1780][INFO    ][4512] Running state [/etc/salt/grains.d/salt] at time 03:14:59.369739
2019-09-15 03:14:59,369 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-15 03:14:59,379 [salt.state       :300 ][INFO    ][4512] File /etc/salt/grains.d/salt is in the correct state
2019-09-15 03:14:59,380 [salt.state       :1951][INFO    ][4512] Completed state [/etc/salt/grains.d/salt] at time 03:14:59.379959 duration_in_ms=10.22
2019-09-15 03:14:59,380 [salt.state       :1780][INFO    ][4512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.380658
2019-09-15 03:14:59,380 [salt.state       :1813][INFO    ][4512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:14:59,381 [salt.state       :300 ][INFO    ][4512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:14:59,381 [salt.state       :1951][INFO    ][4512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:14:59.381332 duration_in_ms=0.674
2019-09-15 03:14:59,382 [salt.state       :1780][INFO    ][4512] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:14:59.382644
2019-09-15 03:14:59,382 [salt.state       :1813][INFO    ][4512] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-15 03:14:59,383 [salt.state       :300 ][INFO    ][4512] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-15 03:14:59,383 [salt.state       :1951][INFO    ][4512] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:14:59.383328 duration_in_ms=0.684
2019-09-15 03:14:59,383 [salt.state       :1780][INFO    ][4512] Running state [mine.update] at time 03:14:59.383863
2019-09-15 03:14:59,384 [salt.state       :1813][INFO    ][4512] Executing state module.wait for [mine.update]
2019-09-15 03:14:59,384 [salt.state       :300 ][INFO    ][4512] No changes made for mine.update
2019-09-15 03:14:59,384 [salt.state       :1951][INFO    ][4512] Completed state [mine.update] at time 03:14:59.384509 duration_in_ms=0.646
2019-09-15 03:14:59,384 [salt.state       :1780][INFO    ][4512] Running state [ca-certificates] at time 03:14:59.384729
2019-09-15 03:14:59,384 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [ca-certificates]
2019-09-15 03:14:59,389 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,390 [salt.state       :1951][INFO    ][4512] Completed state [ca-certificates] at time 03:14:59.390145 duration_in_ms=5.415
2019-09-15 03:14:59,390 [salt.state       :1780][INFO    ][4512] Running state [update-ca-certificates] at time 03:14:59.390695
2019-09-15 03:14:59,390 [salt.state       :1813][INFO    ][4512] Executing state cmd.wait for [update-ca-certificates]
2019-09-15 03:14:59,391 [salt.state       :300 ][INFO    ][4512] No changes made for update-ca-certificates
2019-09-15 03:14:59,391 [salt.state       :1951][INFO    ][4512] Completed state [update-ca-certificates] at time 03:14:59.391370 duration_in_ms=0.675
2019-09-15 03:14:59,391 [salt.state       :1780][INFO    ][4512] Running state [iptables] at time 03:14:59.391588
2019-09-15 03:14:59,391 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [iptables]
2019-09-15 03:14:59,396 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,396 [salt.state       :1951][INFO    ][4512] Completed state [iptables] at time 03:14:59.396572 duration_in_ms=4.984
2019-09-15 03:14:59,396 [salt.state       :1780][INFO    ][4512] Running state [iptables-persistent] at time 03:14:59.396778
2019-09-15 03:14:59,396 [salt.state       :1813][INFO    ][4512] Executing state pkg.installed for [iptables-persistent]
2019-09-15 03:14:59,401 [salt.state       :300 ][INFO    ][4512] All specified packages are already installed
2019-09-15 03:14:59,401 [salt.state       :1951][INFO    ][4512] Completed state [iptables-persistent] at time 03:14:59.401732 duration_in_ms=4.954
2019-09-15 03:14:59,402 [salt.state       :1780][INFO    ][4512] Running state [iptables_modules_v4_load] at time 03:14:59.402501
2019-09-15 03:14:59,402 [salt.state       :1813][INFO    ][4512] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-15 03:14:59,403 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'lsmod' in directory '/root'
2019-09-15 03:14:59,426 [salt.state       :300 ][INFO    ][4512] Kernel modules iptable_filter, ip_tables are already present
2019-09-15 03:14:59,426 [salt.state       :1951][INFO    ][4512] Completed state [iptables_modules_v4_load] at time 03:14:59.426792 duration_in_ms=24.292
2019-09-15 03:14:59,427 [salt.state       :1780][INFO    ][4512] Running state [/etc/iptables/rules.v4] at time 03:14:59.427290
2019-09-15 03:14:59,427 [salt.state       :1813][INFO    ][4512] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-15 03:14:59,505 [salt.state       :300 ][INFO    ][4512] File /etc/iptables/rules.v4 is in the correct state
2019-09-15 03:14:59,506 [salt.state       :1951][INFO    ][4512] Completed state [/etc/iptables/rules.v4] at time 03:14:59.505983 duration_in_ms=78.693
2019-09-15 03:14:59,506 [salt.state       :1780][INFO    ][4512] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:14:59.506810
2019-09-15 03:14:59,507 [salt.state       :1813][INFO    ][4512] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-15 03:14:59,507 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-15 03:14:59,526 [salt.state       :300 ][INFO    ][4512] onlyif execution failed
2019-09-15 03:14:59,526 [salt.state       :1951][INFO    ][4512] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:14:59.526509 duration_in_ms=19.699
2019-09-15 03:14:59,527 [salt.state       :1780][INFO    ][4512] Running state [netfilter-persistent] at time 03:14:59.527239
2019-09-15 03:14:59,527 [salt.state       :1813][INFO    ][4512] Executing state service.running for [netfilter-persistent]
2019-09-15 03:14:59,528 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-15 03:14:59,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-15 03:14:59,564 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-15 03:14:59,580 [salt.state       :300 ][INFO    ][4512] The service netfilter-persistent is already running
2019-09-15 03:14:59,581 [salt.state       :1951][INFO    ][4512] Completed state [netfilter-persistent] at time 03:14:59.581180 duration_in_ms=53.94
2019-09-15 03:14:59,581 [salt.state       :1780][INFO    ][4512] Running state [iptables_extra.remove_stale_tables] at time 03:14:59.581902
2019-09-15 03:14:59,582 [salt.state       :1813][INFO    ][4512] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-15 03:14:59,582 [salt.state       :300 ][INFO    ][4512] No changes made for iptables_extra.remove_stale_tables
2019-09-15 03:14:59,582 [salt.state       :1951][INFO    ][4512] Completed state [iptables_extra.remove_stale_tables] at time 03:14:59.582787 duration_in_ms=0.885
2019-09-15 03:14:59,583 [salt.state       :1780][INFO    ][4512] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:14:59.583040
2019-09-15 03:14:59,583 [salt.state       :1813][INFO    ][4512] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-15 03:14:59,583 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4512] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-15 03:14:59,598 [salt.state       :300 ][INFO    ][4512] onlyif execution failed
2019-09-15 03:14:59,598 [salt.state       :1951][INFO    ][4512] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:14:59.598783 duration_in_ms=15.742
2019-09-15 03:14:59,599 [salt.state       :1780][INFO    ][4512] Running state [/etc/iptables/rules.v6] at time 03:14:59.599611
2019-09-15 03:14:59,599 [salt.state       :1813][INFO    ][4512] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-15 03:14:59,600 [salt.state       :300 ][INFO    ][4512] File /etc/iptables/rules.v6 is not present
2019-09-15 03:14:59,600 [salt.state       :1951][INFO    ][4512] Completed state [/etc/iptables/rules.v6] at time 03:14:59.600503 duration_in_ms=0.891
2019-09-15 03:14:59,601 [salt.state       :1780][INFO    ][4512] Running state [iptables_extra.flush_all] at time 03:14:59.601045
2019-09-15 03:14:59,601 [salt.state       :1813][INFO    ][4512] Executing state module.wait for [iptables_extra.flush_all]
2019-09-15 03:14:59,601 [salt.state       :300 ][INFO    ][4512] No changes made for iptables_extra.flush_all
2019-09-15 03:14:59,601 [salt.state       :1951][INFO    ][4512] Completed state [iptables_extra.flush_all] at time 03:14:59.601753 duration_in_ms=0.708
2019-09-15 03:14:59,604 [salt.minion      :1711][INFO    ][4512] Returning information for job: 20190915031451736948
2019-09-15 03:15:00,204 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915031500191513
2019-09-15 03:15:00,225 [salt.minion      :1432][INFO    ][4587] Starting a new job with PID 4587
2019-09-15 03:15:00,935 [salt.state       :915 ][INFO    ][4587] Loading fresh modules for state activity
2019-09-15 03:15:01,453 [salt.state       :1780][INFO    ][4587] Running state [maas-rack-controller] at time 03:15:01.453497
2019-09-15 03:15:01,453 [salt.state       :1813][INFO    ][4587] Executing state pkg.installed for [maas-rack-controller]
2019-09-15 03:15:01,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4587] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:15:01,534 [salt.state       :300 ][INFO    ][4587] All specified packages are already installed
2019-09-15 03:15:01,534 [salt.state       :1951][INFO    ][4587] Completed state [maas-rack-controller] at time 03:15:01.534823 duration_in_ms=81.327
2019-09-15 03:15:01,535 [salt.state       :1780][INFO    ][4587] Running state [ipmitool] at time 03:15:01.535093
2019-09-15 03:15:01,535 [salt.state       :1813][INFO    ][4587] Executing state pkg.installed for [ipmitool]
2019-09-15 03:15:01,540 [salt.state       :300 ][INFO    ][4587] All specified packages are already installed
2019-09-15 03:15:01,540 [salt.state       :1951][INFO    ][4587] Completed state [ipmitool] at time 03:15:01.540596 duration_in_ms=5.502
2019-09-15 03:15:01,543 [salt.state       :1780][INFO    ][4587] Running state [/etc/maas/rackd.conf] at time 03:15:01.543051
2019-09-15 03:15:01,543 [salt.state       :1813][INFO    ][4587] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-15 03:15:01,544 [salt.state       :300 ][INFO    ][4587] No changes needed to be made
2019-09-15 03:15:01,544 [salt.state       :1951][INFO    ][4587] Completed state [/etc/maas/rackd.conf] at time 03:15:01.544311 duration_in_ms=1.26
2019-09-15 03:15:01,544 [salt.state       :1780][INFO    ][4587] Running state [/etc/maas/rackd.conf] at time 03:15:01.544506
2019-09-15 03:15:01,544 [salt.state       :1813][INFO    ][4587] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-15 03:15:01,544 [salt.loaded.int.states.file:2298][WARNING ][4587] 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-09-15 03:15:01,545 [salt.state       :300 ][INFO    ][4587] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-15 03:15:01,545 [salt.state       :1951][INFO    ][4587] Completed state [/etc/maas/rackd.conf] at time 03:15:01.545478 duration_in_ms=0.972
2019-09-15 03:15:01,546 [salt.state       :1780][INFO    ][4587] Running state [maas-rackd] at time 03:15:01.546252
2019-09-15 03:15:01,546 [salt.state       :1813][INFO    ][4587] Executing state service.running for [maas-rackd]
2019-09-15 03:15:01,546 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4587] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-15 03:15:01,575 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4587] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-15 03:15:01,589 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4587] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-15 03:15:01,602 [salt.state       :300 ][INFO    ][4587] The service maas-rackd is already running
2019-09-15 03:15:01,602 [salt.state       :1951][INFO    ][4587] Completed state [maas-rackd] at time 03:15:01.602478 duration_in_ms=56.226
2019-09-15 03:15:01,603 [salt.minion      :1711][INFO    ][4587] Returning information for job: 20190915031500191513
2019-09-15 03:15:02,221 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915031502207698
2019-09-15 03:15:02,242 [salt.minion      :1432][INFO    ][4658] Starting a new job with PID 4658
2019-09-15 03:15:02,975 [salt.state       :915 ][INFO    ][4658] Loading fresh modules for state activity
2019-09-15 03:15:03,667 [salt.state       :1780][INFO    ][4658] Running state [maas-region-controller] at time 03:15:03.667025
2019-09-15 03:15:03,667 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [maas-region-controller]
2019-09-15 03:15:03,667 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:15:03,780 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-09-15 03:15:03,780 [salt.state       :1951][INFO    ][4658] Completed state [maas-region-controller] at time 03:15:03.780638 duration_in_ms=113.613
2019-09-15 03:15:03,781 [salt.state       :1780][INFO    ][4658] Running state [python-oauth] at time 03:15:03.781066
2019-09-15 03:15:03,781 [salt.state       :1813][INFO    ][4658] Executing state pkg.installed for [python-oauth]
2019-09-15 03:15:03,789 [salt.state       :300 ][INFO    ][4658] All specified packages are already installed
2019-09-15 03:15:03,790 [salt.state       :1951][INFO    ][4658] Completed state [python-oauth] at time 03:15:03.790123 duration_in_ms=9.058
2019-09-15 03:15:03,794 [salt.state       :1780][INFO    ][4658] Running state [/etc/maas/regiond.conf] at time 03:15:03.794137
2019-09-15 03:15:03,794 [salt.state       :1813][INFO    ][4658] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-15 03:15:03,893 [salt.state       :300 ][INFO    ][4658] No changes needed to be made
2019-09-15 03:15:03,894 [salt.state       :1951][INFO    ][4658] Completed state [/etc/maas/regiond.conf] at time 03:15:03.894310 duration_in_ms=100.172
2019-09-15 03:15:03,895 [salt.state       :1780][INFO    ][4658] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:15:03.895091
2019-09-15 03:15:03,895 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-15 03:15:03,976 [salt.state       :300 ][INFO    ][4658] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-15 03:15:03,977 [salt.state       :1951][INFO    ][4658] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:15:03.977136 duration_in_ms=82.046
2019-09-15 03:15:03,977 [salt.state       :1780][INFO    ][4658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:15:03.977803
2019-09-15 03:15:03,978 [salt.state       :1813][INFO    ][4658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-15 03:15:03,996 [salt.state       :300 ][INFO    ][4658] No changes needed to be made
2019-09-15 03:15:03,996 [salt.state       :1951][INFO    ][4658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:15:03.996862 duration_in_ms=19.058
2019-09-15 03:15:03,997 [salt.state       :1780][INFO    ][4658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:15:03.997504
2019-09-15 03:15:03,997 [salt.state       :1813][INFO    ][4658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-15 03:15:04,020 [salt.state       :300 ][INFO    ][4658] No changes needed to be made
2019-09-15 03:15:04,020 [salt.state       :1951][INFO    ][4658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:15:04.020864 duration_in_ms=23.359
2019-09-15 03:15:04,021 [salt.state       :1780][INFO    ][4658] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:15:04.021502
2019-09-15 03:15:04,021 [salt.state       :1813][INFO    ][4658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-15 03:15:04,058 [salt.state       :300 ][INFO    ][4658] No changes needed to be made
2019-09-15 03:15:04,060 [salt.state       :1951][INFO    ][4658] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:15:04.060113 duration_in_ms=38.61
2019-09-15 03:15:04,062 [salt.state       :1780][INFO    ][4658] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:15:04.061977
2019-09-15 03:15:04,062 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-15 03:15:04,082 [salt.state       :300 ][INFO    ][4658] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-15 03:15:04,082 [salt.state       :1951][INFO    ][4658] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:15:04.082503 duration_in_ms=20.526
2019-09-15 03:15:04,088 [salt.state       :1780][INFO    ][4658] Running state [a2enmod headers] at time 03:15:04.088467
2019-09-15 03:15:04,088 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [a2enmod headers]
2019-09-15 03:15:04,090 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'a2enmod headers' in directory '/root'
2019-09-15 03:15:04,167 [salt.state       :300 ][INFO    ][4658] {'pid': 4678, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-15 03:15:04,168 [salt.state       :1951][INFO    ][4658] Completed state [a2enmod headers] at time 03:15:04.167889 duration_in_ms=79.421
2019-09-15 03:15:04,168 [salt.state       :1780][INFO    ][4658] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:15:04.168509
2019-09-15 03:15:04,169 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-15 03:15:04,188 [salt.state       :300 ][INFO    ][4658] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-15 03:15:04,188 [salt.state       :1951][INFO    ][4658] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:15:04.188874 duration_in_ms=20.364
2019-09-15 03:15:04,189 [salt.state       :1780][INFO    ][4658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:15:04.189823
2019-09-15 03:15:04,190 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-15 03:15:04,276 [salt.state       :300 ][INFO    ][4658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-15 03:15:04,276 [salt.state       :1951][INFO    ][4658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:15:04.276811 duration_in_ms=86.988
2019-09-15 03:15:04,277 [salt.state       :1780][INFO    ][4658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:15:04.277470
2019-09-15 03:15:04,277 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-15 03:15:04,342 [salt.state       :300 ][INFO    ][4658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-15 03:15:04,342 [salt.state       :1951][INFO    ][4658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:15:04.342454 duration_in_ms=64.984
2019-09-15 03:15:04,343 [salt.state       :1780][INFO    ][4658] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:15:04.343049
2019-09-15 03:15:04,343 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-15 03:15:04,408 [salt.state       :300 ][INFO    ][4658] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-15 03:15:04,408 [salt.state       :1951][INFO    ][4658] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:15:04.408262 duration_in_ms=65.213
2019-09-15 03:15:04,408 [salt.state       :1780][INFO    ][4658] Running state [/root/.pgpass] at time 03:15:04.408592
2019-09-15 03:15:04,408 [salt.state       :1813][INFO    ][4658] Executing state file.managed for [/root/.pgpass]
2019-09-15 03:15:04,462 [salt.state       :300 ][INFO    ][4658] File /root/.pgpass is in the correct state
2019-09-15 03:15:04,463 [salt.state       :1951][INFO    ][4658] Completed state [/root/.pgpass] at time 03:15:04.462904 duration_in_ms=54.311
2019-09-15 03:15:04,471 [salt.state       :1780][INFO    ][4658] Running state [maas-region syncdb --noinput] at time 03:15:04.471116
2019-09-15 03:15:04,471 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-15 03:15:04,472 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-15 03:15:06,769 [salt.state       :300 ][INFO    ][4658] {'pid': 4698, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: contenttypes, maasserver, piston3, metadataserver, auth, sessions, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-09-15 03:15:06,769 [salt.state       :1951][INFO    ][4658] Completed state [maas-region syncdb --noinput] at time 03:15:06.769632 duration_in_ms=2298.517
2019-09-15 03:15:06,769 [salt.state       :2022][WARNING ][4658] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-15 03:15:06,770 [salt.state       :1780][INFO    ][4658] Running state [maas-regiond] at time 03:15:06.770921
2019-09-15 03:15:06,771 [salt.state       :1813][INFO    ][4658] Executing state service.running for [maas-regiond]
2019-09-15 03:15:06,771 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-15 03:15:06,792 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-15 03:15:06,803 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-15 03:15:06,814 [salt.state       :300 ][INFO    ][4658] The service maas-regiond is already running
2019-09-15 03:15:06,814 [salt.state       :1951][INFO    ][4658] Completed state [maas-regiond] at time 03:15:06.814540 duration_in_ms=43.618
2019-09-15 03:15:06,816 [salt.state       :1780][INFO    ][4658] Running state [bind9] at time 03:15:06.816268
2019-09-15 03:15:06,816 [salt.state       :1813][INFO    ][4658] Executing state service.running for [bind9]
2019-09-15 03:15:06,817 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-15 03:15:06,831 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-15 03:15:06,843 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-15 03:15:06,854 [salt.state       :300 ][INFO    ][4658] The service bind9 is already running
2019-09-15 03:15:06,855 [salt.state       :1951][INFO    ][4658] Completed state [bind9] at time 03:15:06.855173 duration_in_ms=38.905
2019-09-15 03:15:06,856 [salt.state       :1780][INFO    ][4658] Running state [apache2] at time 03:15:06.856273
2019-09-15 03:15:06,856 [salt.state       :1813][INFO    ][4658] Executing state service.running for [apache2]
2019-09-15 03:15:06,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-15 03:15:06,869 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-15 03:15:06,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-15 03:15:06,898 [salt.state       :300 ][INFO    ][4658] The service apache2 is already running
2019-09-15 03:15:06,898 [salt.state       :1951][INFO    ][4658] Completed state [apache2] at time 03:15:06.898593 duration_in_ms=42.319
2019-09-15 03:15:06,899 [salt.state       :1780][INFO    ][4658] Running state [maasng.wait_for_http_code] at time 03:15:06.899600
2019-09-15 03:15:06,899 [salt.state       :1813][INFO    ][4658] Executing state module.run for [maasng.wait_for_http_code]
2019-09-15 03:15:06,900 [salt.utils.decorators:613 ][WARNING ][4658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:15:06,904 [salt.state       :300 ][INFO    ][4658] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-15 03:15:06,905 [salt.state       :1951][INFO    ][4658] Completed state [maasng.wait_for_http_code] at time 03:15:06.905140 duration_in_ms=5.539
2019-09-15 03:15:06,905 [salt.state       :1780][INFO    ][4658] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:15:06.905697
2019-09-15 03:15:06,905 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-15 03:15:06,906 [salt.state       :300 ][INFO    ][4658] /var/lib/maas/.setup_admin exists
2019-09-15 03:15:06,906 [salt.state       :1951][INFO    ][4658] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:15:06.906338 duration_in_ms=0.642
2019-09-15 03:15:06,906 [salt.state       :1780][INFO    ][4658] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:15:06.906811
2019-09-15 03:15:06,907 [salt.state       :1813][INFO    ][4658] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:15:06,907 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4658] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:15:08,081 [salt.state       :300 ][INFO    ][4658] {'pid': 4821, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:15:08,082 [salt.state       :1951][INFO    ][4658] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:15:08.082159 duration_in_ms=1175.347
2019-09-15 03:15:08,089 [salt.state       :1780][INFO    ][4658] Running state [maas_region_boot_source_resources_mirror] at time 03:15:08.089186
2019-09-15 03:15:08,089 [salt.state       :1813][INFO    ][4658] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-15 03:15:08,183 [salt.state       :300 ][INFO    ][4658] {'changes': {}}
2019-09-15 03:15:08,183 [salt.state       :1951][INFO    ][4658] Completed state [maas_region_boot_source_resources_mirror] at time 03:15:08.183366 duration_in_ms=94.18
2019-09-15 03:15:08,184 [salt.state       :1780][INFO    ][4658] Running state [maasng.boot_resources_import] at time 03:15:08.184355
2019-09-15 03:15:08,184 [salt.state       :1813][INFO    ][4658] Executing state module.run for [maasng.boot_resources_import]
2019-09-15 03:15:08,185 [salt.utils.decorators:613 ][WARNING ][4658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:15:08,290 [salt.loaded.ext.module.maasng:1600][INFO    ][4658] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-15 03:15:13,350 [salt.loaded.ext.module.maasng:1600][INFO    ][4658] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-15 03:15:17,247 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031517234387
2019-09-15 03:15:17,270 [salt.minion      :1432][INFO    ][4942] Starting a new job with PID 4942
2019-09-15 03:15:17,287 [salt.minion      :1711][INFO    ][4942] Returning information for job: 20190915031517234387
2019-09-15 03:15:18,410 [salt.loaded.ext.module.maasng:1600][INFO    ][4658] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-15 03:15:23,523 [salt.state       :300 ][INFO    ][4658] {'ret': True}
2019-09-15 03:15:23,523 [salt.state       :1951][INFO    ][4658] Completed state [maasng.boot_resources_import] at time 03:15:23.523768 duration_in_ms=15339.41
2019-09-15 03:15:23,525 [salt.state       :1780][INFO    ][4658] Running state [maas_region_boot_sources_selection_xenial] at time 03:15:23.525235
2019-09-15 03:15:23,525 [salt.state       :1813][INFO    ][4658] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-15 03:15:23,739 [salt.state       :300 ][INFO    ][4658] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-15 03:15:23,740 [salt.state       :1951][INFO    ][4658] Completed state [maas_region_boot_sources_selection_xenial] at time 03:15:23.740125 duration_in_ms=214.889
2019-09-15 03:15:23,741 [salt.state       :1780][INFO    ][4658] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:15:23.741598
2019-09-15 03:15:23,742 [salt.state       :1813][INFO    ][4658] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-15 03:15:23,742 [salt.utils.decorators:613 ][WARNING ][4658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:15:23,743 [salt.loaded.ext.module.maasng:1771][INFO    ][4658] boot-sources sync initiated for ALL Rack's
2019-09-15 03:15:24,679 [salt.state       :300 ][INFO    ][4658] {'ret': True}
2019-09-15 03:15:24,680 [salt.state       :1951][INFO    ][4658] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:15:24.680023 duration_in_ms=938.425
2019-09-15 03:15:24,681 [salt.state       :1780][INFO    ][4658] Running state [maas.process_maas_config] at time 03:15:24.681300
2019-09-15 03:15:24,681 [salt.state       :1813][INFO    ][4658] Executing state module.run for [maas.process_maas_config]
2019-09-15 03:15:24,681 [salt.utils.decorators:613 ][WARNING ][4658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:15:24,682 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=enable_http_proxy value=True
2019-09-15 03:15:24,742 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=upstream_dns value=8.8.8.8
2019-09-15 03:15:24,831 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=commissioning_distro_series value=xenial
2019-09-15 03:15:24,901 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=default_osystem value=ubuntu
2019-09-15 03:15:24,967 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=active_discovery_interval value=600
2019-09-15 03:15:25,027 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=dnssec_validation value=no
2019-09-15 03:15:25,087 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=maas_name value=mas01
2019-09-15 03:15:25,141 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=network_discovery value=enabled
2019-09-15 03:15:25,255 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=enable_third_party_drivers value=True
2019-09-15 03:15:25,315 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=default_storage_layout value=lvm
2019-09-15 03:15:27,718 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=ntp_external_only value=True
2019-09-15 03:15:27,778 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-15 03:15:27,836 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=default_distro_series value=xenial
2019-09-15 03:15:27,902 [salt.loaded.ext.module.maas:92  ][INFO    ][4658] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-09-15 03:15:28,034 [salt.state       :300 ][INFO    ][4658] {'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-09-15 03:15:28,034 [salt.state       :1951][INFO    ][4658] Completed state [maas.process_maas_config] at time 03:15:28.034616 duration_in_ms=3353.315
2019-09-15 03:15:28,035 [salt.state       :1780][INFO    ][4658] Running state [pxe_admin] at time 03:15:28.035527
2019-09-15 03:15:28,036 [salt.state       :1813][INFO    ][4658] Executing state maasng.fabric_present for [pxe_admin]
2019-09-15 03:15:28,097 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:15:28,163 [salt.loaded.ext.module.maasng:1008][WARNING ][4658] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-15 03:15:28,164 [salt.loaded.ext.module.maasng:1011][WARNING ][4658] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-15 03:15:28,237 [salt.state       :300 ][INFO    ][4658] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-15 03:15:28,237 [salt.state       :1951][INFO    ][4658] Completed state [pxe_admin] at time 03:15:28.237391 duration_in_ms=201.863
2019-09-15 03:15:28,237 [salt.state       :1780][INFO    ][4658] Running state [vlan 0] at time 03:15:28.237906
2019-09-15 03:15:28,238 [salt.state       :1813][INFO    ][4658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-15 03:15:28,301 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:15:28,433 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-09-15 03:15:28,746 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:15:28,843 [salt.state       :300 ][INFO    ][4658] {'new': 'Vlan untagged was updated'}
2019-09-15 03:15:28,843 [salt.state       :1951][INFO    ][4658] Completed state [vlan 0] at time 03:15:28.843599 duration_in_ms=605.691
2019-09-15 03:15:28,845 [salt.state       :1780][INFO    ][4658] Running state [192.168.11.0/24] at time 03:15:28.845536
2019-09-15 03:15:28,846 [salt.state       :1813][INFO    ][4658] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-15 03:15:29,040 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-09-15 03:15:29,040 [salt.loaded.ext.module.maasng:1235][WARNING ][4658] Ignoring parameter vlan:0
2019-09-15 03:15:29,110 [salt.state       :300 ][INFO    ][4658] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-15 03:15:29,110 [salt.state       :1951][INFO    ][4658] Completed state [192.168.11.0/24] at time 03:15:29.110824 duration_in_ms=265.287
2019-09-15 03:15:29,112 [salt.state       :1780][INFO    ][4658] Running state [maas_create_iprange_1] at time 03:15:29.112187
2019-09-15 03:15:29,112 [salt.state       :1813][INFO    ][4658] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-15 03:15:29,182 [salt.state       :300 ][INFO    ][4658] Iprange maas_create_iprange_1 already exist.
2019-09-15 03:15:29,183 [salt.state       :1951][INFO    ][4658] Completed state [maas_create_iprange_1] at time 03:15:29.183204 duration_in_ms=71.017
2019-09-15 03:15:29,183 [salt.state       :1780][INFO    ][4658] Running state [vlan 0] at time 03:15:29.183521
2019-09-15 03:15:29,183 [salt.state       :1813][INFO    ][4658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-15 03:15:29,229 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-09-15 03:15:29,319 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:15:29,566 [salt.loaded.ext.module.maasng:945 ][INFO    ][4658] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:15:29,651 [salt.state       :300 ][INFO    ][4658] {'new': 'Vlan untagged was updated'}
2019-09-15 03:15:29,651 [salt.state       :1951][INFO    ][4658] Completed state [vlan 0] at time 03:15:29.651297 duration_in_ms=467.775
2019-09-15 03:15:29,652 [salt.state       :1780][INFO    ][4658] Running state [opnfv] at time 03:15:29.651991
2019-09-15 03:15:29,652 [salt.state       :1813][INFO    ][4658] Executing state maasng.sshkey_present for [opnfv]
2019-09-15 03:15:29,705 [salt.loaded.ext.module.maasng:1903][INFO    ][4658] [{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-09-15 03:15:29,705 [salt.state       :300 ][INFO    ][4658] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-15 03:15:29,705 [salt.state       :1951][INFO    ][4658] Completed state [opnfv] at time 03:15:29.705720 duration_in_ms=53.728
2019-09-15 03:15:29,709 [salt.minion      :1711][INFO    ][4658] Returning information for job: 20190915031502207698
2019-09-15 03:15:30,323 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915031530313611
2019-09-15 03:15:30,338 [salt.minion      :1432][INFO    ][5302] Starting a new job with PID 5302
2019-09-15 03:15:33,638 [salt.state       :915 ][INFO    ][5302] Loading fresh modules for state activity
2019-09-15 03:15:33,729 [salt.state       :1780][INFO    ][5302] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:15:33.729164
2019-09-15 03:15:33,729 [salt.state       :1813][INFO    ][5302] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:15:33,731 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5302] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:15:35,195 [salt.state       :300 ][INFO    ][5302] {'pid': 5328, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:15:35,196 [salt.state       :1951][INFO    ][5302] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:15:35.196138 duration_in_ms=1466.975
2019-09-15 03:15:35,197 [salt.state       :1780][INFO    ][5302] Running state [maas.process_machines] at time 03:15:35.197344
2019-09-15 03:15:35,197 [salt.state       :1813][INFO    ][5302] Executing state module.run for [maas.process_machines]
2019-09-15 03:15:35,198 [salt.utils.decorators:613 ][WARNING ][5302] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:15:35,692 [salt.loaded.ext.module.maas:412 ][WARNING ][5302] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:15:35,693 [salt.loaded.ext.module.maas:92  ][INFO    ][5302] 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=s7nc37 architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:15:37,024 [salt.loaded.ext.module.maas:412 ][WARNING ][5302] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:15:37,025 [salt.loaded.ext.module.maas:92  ][INFO    ][5302] 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=rrasen architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:15:38,358 [salt.loaded.ext.module.maas:412 ][WARNING ][5302] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:15:38,358 [salt.loaded.ext.module.maas:92  ][INFO    ][5302] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=prfp3h architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:15:39,699 [salt.loaded.ext.module.maas:412 ][WARNING ][5302] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:15:39,700 [salt.loaded.ext.module.maas:92  ][INFO    ][5302] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=a7khd8 architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:15:40,982 [salt.loaded.ext.module.maas:412 ][WARNING ][5302] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:15:40,983 [salt.loaded.ext.module.maas:92  ][INFO    ][5302] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=wkqe7f architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:15:42,360 [salt.state       :300 ][INFO    ][5302] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-15 03:15:42,361 [salt.state       :1951][INFO    ][5302] Completed state [maas.process_machines] at time 03:15:42.361437 duration_in_ms=7164.091
2019-09-15 03:15:42,365 [salt.minion      :1711][INFO    ][5302] Returning information for job: 20190915031530313611
2019-09-15 03:16:13,145 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915031613137103
2019-09-15 03:16:13,163 [salt.minion      :1432][INFO    ][5753] Starting a new job with PID 5753
2019-09-15 03:16:16,960 [salt.state       :915 ][INFO    ][5753] Loading fresh modules for state activity
2019-09-15 03:16:17,050 [salt.state       :1780][INFO    ][5753] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:16:17.050337
2019-09-15 03:16:17,050 [salt.state       :1813][INFO    ][5753] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:16:17,052 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5753] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:16:18,682 [salt.state       :300 ][INFO    ][5753] {'pid': 5762, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:16:18,683 [salt.state       :1951][INFO    ][5753] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:16:18.682994 duration_in_ms=1632.657
2019-09-15 03:16:18,686 [salt.state       :1780][INFO    ][5753] Running state [maas.wait_for_machine_status] at time 03:16:18.686381
2019-09-15 03:16:18,687 [salt.state       :1813][INFO    ][5753] Executing state module.run for [maas.wait_for_machine_status]
2019-09-15 03:16:18,687 [salt.utils.decorators:613 ][WARNING ][5753] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:16:22,389 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1496.3089788s left)
2019-09-15 03:16:28,245 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031628232199
2019-09-15 03:16:28,268 [salt.minion      :1432][INFO    ][5794] Starting a new job with PID 5794
2019-09-15 03:16:28,293 [salt.minion      :1711][INFO    ][5794] Returning information for job: 20190915031628232199
2019-09-15 03:16:55,937 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1462.76124287s left)
2019-09-15 03:16:58,465 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031658452374
2019-09-15 03:16:58,488 [salt.minion      :1432][INFO    ][5834] Starting a new job with PID 5834
2019-09-15 03:16:58,513 [salt.minion      :1711][INFO    ][5834] Returning information for job: 20190915031658452374
2019-09-15 03:17:28,599 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031728586402
2019-09-15 03:17:28,621 [salt.minion      :1432][INFO    ][6243] Starting a new job with PID 6243
2019-09-15 03:17:28,646 [salt.minion      :1711][INFO    ][6243] Returning information for job: 20190915031728586402
2019-09-15 03:17:29,728 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1428.97020984s left)
2019-09-15 03:17:58,651 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031758638266
2019-09-15 03:17:58,673 [salt.minion      :1432][INFO    ][6259] Starting a new job with PID 6259
2019-09-15 03:17:58,698 [salt.minion      :1711][INFO    ][6259] Returning information for job: 20190915031758638266
2019-09-15 03:18:03,260 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1395.43780279s left)
2019-09-15 03:18:28,706 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031828692456
2019-09-15 03:18:28,729 [salt.minion      :1432][INFO    ][6376] Starting a new job with PID 6376
2019-09-15 03:18:28,753 [salt.minion      :1711][INFO    ][6376] Returning information for job: 20190915031828692456
2019-09-15 03:18:36,794 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1361.90376377s left)
2019-09-15 03:18:58,891 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031858878078
2019-09-15 03:18:58,914 [salt.minion      :1432][INFO    ][6468] Starting a new job with PID 6468
2019-09-15 03:18:58,940 [salt.minion      :1711][INFO    ][6468] Returning information for job: 20190915031858878078
2019-09-15 03:19:09,832 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1328.86539698s left)
2019-09-15 03:19:28,963 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031928950740
2019-09-15 03:19:28,987 [salt.minion      :1432][INFO    ][6689] Starting a new job with PID 6689
2019-09-15 03:19:29,011 [salt.minion      :1711][INFO    ][6689] Returning information for job: 20190915031928950740
2019-09-15 03:19:43,461 [salt.loaded.ext.module.maas:1023][INFO    ][5753] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1295.23717284s left)
2019-09-15 03:19:59,026 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915031959013709
2019-09-15 03:19:59,049 [salt.minion      :1432][INFO    ][6722] Starting a new job with PID 6722
2019-09-15 03:19:59,074 [salt.minion      :1711][INFO    ][6722] Returning information for job: 20190915031959013709
2019-09-15 03:20:14,228 [salt.loaded.ext.module.maas:993 ][INFO    ][5753] Machine s7nc37 mark broken
2019-09-15 03:20:14,762 [salt.loaded.ext.module.maas:996 ][INFO    ][5753] Machine s7nc37 mark fixed
2019-09-15 03:20:15,845 [salt.loaded.ext.module.maas:684 ][INFO    ][5753] deploymachines hwe_kernel=ga-16.04 system_id=s7nc37 distro_series=xenial
2019-09-15 03:20:18,457 [salt.loaded.ext.module.maas:160 ][ERROR   ][5753] Failed for object cmp002 reason Unable to change power state to 'cycle' for node cmp002: another action is already in progress for that node.
2019-09-15 03:20:18,458 [salt.state       :302 ][ERROR   ][5753] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {'cmp002': "Unable to change power state to 'cycle' for node cmp002: another action is already in progress for that node."}, 'success': []}
2019-09-15 03:20:18,458 [salt.state       :1951][INFO    ][5753] Completed state [maas.wait_for_machine_status] at time 03:20:18.458780 duration_in_ms=239772.398
2019-09-15 03:20:18,462 [salt.minion      :1711][INFO    ][5753] Returning information for job: 20190915031613137103
2019-09-15 03:20:29,137 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command pillar.get with jid 20190915032029125211
2019-09-15 03:20:29,152 [salt.minion      :1432][INFO    ][7077] Starting a new job with PID 7077
2019-09-15 03:20:29,160 [salt.minion      :1711][INFO    ][7077] Returning information for job: 20190915032029125211
2019-09-15 03:20:29,641 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command service.status with jid 20190915032029629561
2019-09-15 03:20:29,658 [salt.minion      :1432][INFO    ][7082] Starting a new job with PID 7082
2019-09-15 03:20:30,001 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7082] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:30,033 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7082] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-15 03:20:30,046 [salt.minion      :1711][INFO    ][7082] Returning information for job: 20190915032029629561
2019-09-15 03:20:30,517 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915032030504656
2019-09-15 03:20:30,537 [salt.minion      :1432][INFO    ][7100] Starting a new job with PID 7100
2019-09-15 03:20:34,321 [salt.state       :915 ][INFO    ][7100] Loading fresh modules for state activity
2019-09-15 03:20:34,731 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:20:35,102 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:20:35,944 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:20:36,231 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'salt-minion --version' in directory '/root'
2019-09-15 03:20:37,518 [salt.state       :1780][INFO    ][7100] Running state [salt-minion] at time 03:20:37.518585
2019-09-15 03:20:37,518 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [salt-minion]
2019-09-15 03:20:37,519 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:20:37,614 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:37,614 [salt.state       :1951][INFO    ][7100] Completed state [salt-minion] at time 03:20:37.614657 duration_in_ms=96.071
2019-09-15 03:20:37,615 [salt.state       :1780][INFO    ][7100] Running state [salt_minion_dependency_packages] at time 03:20:37.615056
2019-09-15 03:20:37,615 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-15 03:20:37,622 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:37,623 [salt.state       :1951][INFO    ][7100] Completed state [salt_minion_dependency_packages] at time 03:20:37.623131 duration_in_ms=8.075
2019-09-15 03:20:37,626 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/minion.d/minion.conf] at time 03:20:37.626726
2019-09-15 03:20:37,627 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-15 03:20:37,829 [salt.state       :300 ][INFO    ][7100] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-15 03:20:37,830 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/minion.d/minion.conf] at time 03:20:37.830121 duration_in_ms=203.395
2019-09-15 03:20:37,830 [salt.state       :1780][INFO    ][7100] Running state [python-netaddr] at time 03:20:37.830408
2019-09-15 03:20:37,830 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [python-netaddr]
2019-09-15 03:20:37,835 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:37,835 [salt.state       :1951][INFO    ][7100] Completed state [python-netaddr] at time 03:20:37.835351 duration_in_ms=4.943
2019-09-15 03:20:37,837 [salt.state       :1780][INFO    ][7100] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:20:37.837516
2019-09-15 03:20:37,837 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-15 03:20:37,847 [salt.state       :300 ][INFO    ][7100] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-15 03:20:37,847 [salt.state       :1951][INFO    ][7100] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:20:37.847410 duration_in_ms=9.895
2019-09-15 03:20:37,848 [salt.state       :1780][INFO    ][7100] Running state [salt-minion] at time 03:20:37.848097
2019-09-15 03:20:37,848 [salt.state       :1813][INFO    ][7100] Executing state service.running for [salt-minion]
2019-09-15 03:20:37,848 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:37,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-15 03:20:37,900 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-15 03:20:37,916 [salt.state       :300 ][INFO    ][7100] The service salt-minion is already running
2019-09-15 03:20:37,916 [salt.state       :1951][INFO    ][7100] Completed state [salt-minion] at time 03:20:37.916683 duration_in_ms=68.586
2019-09-15 03:20:37,918 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains.d] at time 03:20:37.918054
2019-09-15 03:20:37,918 [salt.state       :1813][INFO    ][7100] Executing state file.directory for [/etc/salt/grains.d]
2019-09-15 03:20:37,919 [salt.state       :300 ][INFO    ][7100] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-15 03:20:37,919 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains.d] at time 03:20:37.919453 duration_in_ms=1.399
2019-09-15 03:20:37,920 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains] at time 03:20:37.920070
2019-09-15 03:20:37,920 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/grains]
2019-09-15 03:20:37,920 [salt.state       :300 ][INFO    ][7100] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-15 03:20:37,921 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains] at time 03:20:37.921043 duration_in_ms=0.972
2019-09-15 03:20:37,921 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains.d/placeholder] at time 03:20:37.921455
2019-09-15 03:20:37,921 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-15 03:20:37,922 [salt.state       :300 ][INFO    ][7100] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-15 03:20:37,922 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains.d/placeholder] at time 03:20:37.922406 duration_in_ms=0.951
2019-09-15 03:20:37,922 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains.d/sphinx] at time 03:20:37.922842
2019-09-15 03:20:37,923 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-15 03:20:37,937 [salt.state       :300 ][INFO    ][7100] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-15 03:20:37,938 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains.d/sphinx] at time 03:20:37.938037 duration_in_ms=15.195
2019-09-15 03:20:37,940 [salt.state       :1780][INFO    ][7100] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.940207
2019-09-15 03:20:37,940 [salt.state       :1813][INFO    ][7100] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:20:37,940 [salt.state       :300 ][INFO    ][7100] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:20:37,941 [salt.state       :1951][INFO    ][7100] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.941072 duration_in_ms=0.865
2019-09-15 03:20:37,941 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains.d/dns_records] at time 03:20:37.941540
2019-09-15 03:20:37,941 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-15 03:20:37,955 [salt.state       :300 ][INFO    ][7100] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-15 03:20:37,955 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains.d/dns_records] at time 03:20:37.955892 duration_in_ms=14.352
2019-09-15 03:20:37,956 [salt.state       :1780][INFO    ][7100] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.956848
2019-09-15 03:20:37,957 [salt.state       :1813][INFO    ][7100] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:20:37,957 [salt.state       :300 ][INFO    ][7100] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:20:37,957 [salt.state       :1951][INFO    ][7100] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.957739 duration_in_ms=0.891
2019-09-15 03:20:37,958 [salt.state       :1780][INFO    ][7100] Running state [/etc/salt/grains.d/salt] at time 03:20:37.958221
2019-09-15 03:20:37,958 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-15 03:20:37,973 [salt.state       :300 ][INFO    ][7100] File /etc/salt/grains.d/salt is in the correct state
2019-09-15 03:20:37,973 [salt.state       :1951][INFO    ][7100] Completed state [/etc/salt/grains.d/salt] at time 03:20:37.973825 duration_in_ms=15.603
2019-09-15 03:20:37,974 [salt.state       :1780][INFO    ][7100] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.974722
2019-09-15 03:20:37,975 [salt.state       :1813][INFO    ][7100] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-15 03:20:37,975 [salt.state       :300 ][INFO    ][7100] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-15 03:20:37,975 [salt.state       :1951][INFO    ][7100] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:20:37.975610 duration_in_ms=0.888
2019-09-15 03:20:37,977 [salt.state       :1780][INFO    ][7100] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:20:37.977513
2019-09-15 03:20:37,977 [salt.state       :1813][INFO    ][7100] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-15 03:20:37,978 [salt.state       :300 ][INFO    ][7100] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-15 03:20:37,978 [salt.state       :1951][INFO    ][7100] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:20:37.978387 duration_in_ms=0.873
2019-09-15 03:20:37,979 [salt.state       :1780][INFO    ][7100] Running state [mine.update] at time 03:20:37.979089
2019-09-15 03:20:37,979 [salt.state       :1813][INFO    ][7100] Executing state module.wait for [mine.update]
2019-09-15 03:20:37,979 [salt.state       :300 ][INFO    ][7100] No changes made for mine.update
2019-09-15 03:20:37,979 [salt.state       :1951][INFO    ][7100] Completed state [mine.update] at time 03:20:37.979907 duration_in_ms=0.819
2019-09-15 03:20:37,980 [salt.state       :1780][INFO    ][7100] Running state [ca-certificates] at time 03:20:37.980154
2019-09-15 03:20:37,980 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [ca-certificates]
2019-09-15 03:20:37,987 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:37,988 [salt.state       :1951][INFO    ][7100] Completed state [ca-certificates] at time 03:20:37.987982 duration_in_ms=7.827
2019-09-15 03:20:37,988 [salt.state       :1780][INFO    ][7100] Running state [update-ca-certificates] at time 03:20:37.988655
2019-09-15 03:20:37,988 [salt.state       :1813][INFO    ][7100] Executing state cmd.wait for [update-ca-certificates]
2019-09-15 03:20:37,989 [salt.state       :300 ][INFO    ][7100] No changes made for update-ca-certificates
2019-09-15 03:20:37,989 [salt.state       :1951][INFO    ][7100] Completed state [update-ca-certificates] at time 03:20:37.989446 duration_in_ms=0.791
2019-09-15 03:20:37,989 [salt.state       :1780][INFO    ][7100] Running state [iptables] at time 03:20:37.989711
2019-09-15 03:20:37,989 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [iptables]
2019-09-15 03:20:37,996 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:37,996 [salt.state       :1951][INFO    ][7100] Completed state [iptables] at time 03:20:37.996816 duration_in_ms=7.105
2019-09-15 03:20:37,997 [salt.state       :1780][INFO    ][7100] Running state [iptables-persistent] at time 03:20:37.997057
2019-09-15 03:20:37,997 [salt.state       :1813][INFO    ][7100] Executing state pkg.installed for [iptables-persistent]
2019-09-15 03:20:38,003 [salt.state       :300 ][INFO    ][7100] All specified packages are already installed
2019-09-15 03:20:38,003 [salt.state       :1951][INFO    ][7100] Completed state [iptables-persistent] at time 03:20:38.003942 duration_in_ms=6.884
2019-09-15 03:20:38,004 [salt.state       :1780][INFO    ][7100] Running state [iptables_modules_v4_load] at time 03:20:38.004908
2019-09-15 03:20:38,005 [salt.state       :1813][INFO    ][7100] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-15 03:20:38,005 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'lsmod' in directory '/root'
2019-09-15 03:20:38,029 [salt.state       :300 ][INFO    ][7100] Kernel modules iptable_filter, ip_tables are already present
2019-09-15 03:20:38,029 [salt.state       :1951][INFO    ][7100] Completed state [iptables_modules_v4_load] at time 03:20:38.029388 duration_in_ms=24.48
2019-09-15 03:20:38,030 [salt.state       :1780][INFO    ][7100] Running state [/etc/iptables/rules.v4] at time 03:20:38.030163
2019-09-15 03:20:38,030 [salt.state       :1813][INFO    ][7100] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-15 03:20:38,129 [salt.state       :300 ][INFO    ][7100] File /etc/iptables/rules.v4 is in the correct state
2019-09-15 03:20:38,129 [salt.state       :1951][INFO    ][7100] Completed state [/etc/iptables/rules.v4] at time 03:20:38.129878 duration_in_ms=99.715
2019-09-15 03:20:38,130 [salt.state       :1780][INFO    ][7100] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:20:38.130896
2019-09-15 03:20:38,131 [salt.state       :1813][INFO    ][7100] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-15 03:20:38,131 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-15 03:20:38,150 [salt.state       :300 ][INFO    ][7100] onlyif execution failed
2019-09-15 03:20:38,151 [salt.state       :1951][INFO    ][7100] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:20:38.151067 duration_in_ms=20.171
2019-09-15 03:20:38,152 [salt.state       :1780][INFO    ][7100] Running state [netfilter-persistent] at time 03:20:38.152001
2019-09-15 03:20:38,152 [salt.state       :1813][INFO    ][7100] Executing state service.running for [netfilter-persistent]
2019-09-15 03:20:38,153 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:38,172 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-15 03:20:38,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-15 03:20:38,205 [salt.state       :300 ][INFO    ][7100] The service netfilter-persistent is already running
2019-09-15 03:20:38,205 [salt.state       :1951][INFO    ][7100] Completed state [netfilter-persistent] at time 03:20:38.205370 duration_in_ms=53.369
2019-09-15 03:20:38,206 [salt.state       :1780][INFO    ][7100] Running state [iptables_extra.remove_stale_tables] at time 03:20:38.206218
2019-09-15 03:20:38,206 [salt.state       :1813][INFO    ][7100] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-15 03:20:38,206 [salt.state       :300 ][INFO    ][7100] No changes made for iptables_extra.remove_stale_tables
2019-09-15 03:20:38,207 [salt.state       :1951][INFO    ][7100] Completed state [iptables_extra.remove_stale_tables] at time 03:20:38.207124 duration_in_ms=0.906
2019-09-15 03:20:38,207 [salt.state       :1780][INFO    ][7100] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:20:38.207375
2019-09-15 03:20:38,207 [salt.state       :1813][INFO    ][7100] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-15 03:20:38,208 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7100] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-15 03:20:38,221 [salt.state       :300 ][INFO    ][7100] onlyif execution failed
2019-09-15 03:20:38,222 [salt.state       :1951][INFO    ][7100] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:20:38.221982 duration_in_ms=14.607
2019-09-15 03:20:38,222 [salt.state       :1780][INFO    ][7100] Running state [/etc/iptables/rules.v6] at time 03:20:38.222853
2019-09-15 03:20:38,223 [salt.state       :1813][INFO    ][7100] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-15 03:20:38,223 [salt.state       :300 ][INFO    ][7100] File /etc/iptables/rules.v6 is not present
2019-09-15 03:20:38,223 [salt.state       :1951][INFO    ][7100] Completed state [/etc/iptables/rules.v6] at time 03:20:38.223817 duration_in_ms=0.964
2019-09-15 03:20:38,224 [salt.state       :1780][INFO    ][7100] Running state [iptables_extra.flush_all] at time 03:20:38.224424
2019-09-15 03:20:38,224 [salt.state       :1813][INFO    ][7100] Executing state module.wait for [iptables_extra.flush_all]
2019-09-15 03:20:38,225 [salt.state       :300 ][INFO    ][7100] No changes made for iptables_extra.flush_all
2019-09-15 03:20:38,225 [salt.state       :1951][INFO    ][7100] Completed state [iptables_extra.flush_all] at time 03:20:38.225178 duration_in_ms=0.755
2019-09-15 03:20:38,228 [salt.minion      :1711][INFO    ][7100] Returning information for job: 20190915032030504656
2019-09-15 03:20:38,850 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915032038836598
2019-09-15 03:20:38,872 [salt.minion      :1432][INFO    ][7177] Starting a new job with PID 7177
2019-09-15 03:20:39,639 [salt.state       :915 ][INFO    ][7177] Loading fresh modules for state activity
2019-09-15 03:20:40,256 [salt.state       :1780][INFO    ][7177] Running state [maas-rack-controller] at time 03:20:40.256419
2019-09-15 03:20:40,256 [salt.state       :1813][INFO    ][7177] Executing state pkg.installed for [maas-rack-controller]
2019-09-15 03:20:40,257 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7177] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:20:40,348 [salt.state       :300 ][INFO    ][7177] All specified packages are already installed
2019-09-15 03:20:40,348 [salt.state       :1951][INFO    ][7177] Completed state [maas-rack-controller] at time 03:20:40.348589 duration_in_ms=92.17
2019-09-15 03:20:40,348 [salt.state       :1780][INFO    ][7177] Running state [ipmitool] at time 03:20:40.348878
2019-09-15 03:20:40,349 [salt.state       :1813][INFO    ][7177] Executing state pkg.installed for [ipmitool]
2019-09-15 03:20:40,354 [salt.state       :300 ][INFO    ][7177] All specified packages are already installed
2019-09-15 03:20:40,354 [salt.state       :1951][INFO    ][7177] Completed state [ipmitool] at time 03:20:40.354805 duration_in_ms=5.927
2019-09-15 03:20:40,357 [salt.state       :1780][INFO    ][7177] Running state [/etc/maas/rackd.conf] at time 03:20:40.357495
2019-09-15 03:20:40,357 [salt.state       :1813][INFO    ][7177] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-15 03:20:40,358 [salt.state       :300 ][INFO    ][7177] No changes needed to be made
2019-09-15 03:20:40,358 [salt.state       :1951][INFO    ][7177] Completed state [/etc/maas/rackd.conf] at time 03:20:40.358838 duration_in_ms=1.343
2019-09-15 03:20:40,359 [salt.state       :1780][INFO    ][7177] Running state [/etc/maas/rackd.conf] at time 03:20:40.359037
2019-09-15 03:20:40,359 [salt.state       :1813][INFO    ][7177] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-15 03:20:40,359 [salt.loaded.int.states.file:2298][WARNING ][7177] 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-09-15 03:20:40,359 [salt.state       :300 ][INFO    ][7177] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-15 03:20:40,360 [salt.state       :1951][INFO    ][7177] Completed state [/etc/maas/rackd.conf] at time 03:20:40.360115 duration_in_ms=1.078
2019-09-15 03:20:40,360 [salt.state       :1780][INFO    ][7177] Running state [maas-rackd] at time 03:20:40.360939
2019-09-15 03:20:40,361 [salt.state       :1813][INFO    ][7177] Executing state service.running for [maas-rackd]
2019-09-15 03:20:40,361 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7177] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:40,393 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7177] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-15 03:20:40,408 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7177] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-15 03:20:40,423 [salt.state       :300 ][INFO    ][7177] The service maas-rackd is already running
2019-09-15 03:20:40,423 [salt.state       :1951][INFO    ][7177] Completed state [maas-rackd] at time 03:20:40.423442 duration_in_ms=62.503
2019-09-15 03:20:40,424 [salt.minion      :1711][INFO    ][7177] Returning information for job: 20190915032038836598
2019-09-15 03:20:41,016 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915032041003435
2019-09-15 03:20:41,039 [salt.minion      :1432][INFO    ][7200] Starting a new job with PID 7200
2019-09-15 03:20:41,805 [salt.state       :915 ][INFO    ][7200] Loading fresh modules for state activity
2019-09-15 03:20:42,488 [salt.state       :1780][INFO    ][7200] Running state [maas-region-controller] at time 03:20:42.488284
2019-09-15 03:20:42,488 [salt.state       :1813][INFO    ][7200] Executing state pkg.installed for [maas-region-controller]
2019-09-15 03:20:42,489 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-15 03:20:42,563 [salt.state       :300 ][INFO    ][7200] All specified packages are already installed
2019-09-15 03:20:42,563 [salt.state       :1951][INFO    ][7200] Completed state [maas-region-controller] at time 03:20:42.563593 duration_in_ms=75.31
2019-09-15 03:20:42,563 [salt.state       :1780][INFO    ][7200] Running state [python-oauth] at time 03:20:42.563842
2019-09-15 03:20:42,564 [salt.state       :1813][INFO    ][7200] Executing state pkg.installed for [python-oauth]
2019-09-15 03:20:42,568 [salt.state       :300 ][INFO    ][7200] All specified packages are already installed
2019-09-15 03:20:42,568 [salt.state       :1951][INFO    ][7200] Completed state [python-oauth] at time 03:20:42.568644 duration_in_ms=4.803
2019-09-15 03:20:42,570 [salt.state       :1780][INFO    ][7200] Running state [/etc/maas/regiond.conf] at time 03:20:42.570908
2019-09-15 03:20:42,571 [salt.state       :1813][INFO    ][7200] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-15 03:20:42,615 [salt.state       :300 ][INFO    ][7200] No changes needed to be made
2019-09-15 03:20:42,615 [salt.state       :1951][INFO    ][7200] Completed state [/etc/maas/regiond.conf] at time 03:20:42.615506 duration_in_ms=44.598
2019-09-15 03:20:42,616 [salt.state       :1780][INFO    ][7200] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:20:42.615997
2019-09-15 03:20:42,616 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-15 03:20:42,692 [salt.state       :300 ][INFO    ][7200] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-15 03:20:42,693 [salt.state       :1951][INFO    ][7200] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:20:42.693057 duration_in_ms=77.059
2019-09-15 03:20:42,693 [salt.state       :1780][INFO    ][7200] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:42.693797
2019-09-15 03:20:42,694 [salt.state       :1813][INFO    ][7200] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-15 03:20:42,712 [salt.state       :300 ][INFO    ][7200] No changes needed to be made
2019-09-15 03:20:42,713 [salt.state       :1951][INFO    ][7200] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:42.712940 duration_in_ms=19.144
2019-09-15 03:20:42,713 [salt.state       :1780][INFO    ][7200] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:42.713615
2019-09-15 03:20:42,714 [salt.state       :1813][INFO    ][7200] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-15 03:20:42,736 [salt.state       :300 ][INFO    ][7200] No changes needed to be made
2019-09-15 03:20:42,736 [salt.state       :1951][INFO    ][7200] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:42.736767 duration_in_ms=23.151
2019-09-15 03:20:42,737 [salt.state       :1780][INFO    ][7200] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:20:42.737426
2019-09-15 03:20:42,737 [salt.state       :1813][INFO    ][7200] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-15 03:20:42,767 [salt.state       :300 ][INFO    ][7200] No changes needed to be made
2019-09-15 03:20:42,768 [salt.state       :1951][INFO    ][7200] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:20:42.768123 duration_in_ms=30.698
2019-09-15 03:20:42,768 [salt.state       :1780][INFO    ][7200] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:20:42.768704
2019-09-15 03:20:42,769 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-15 03:20:42,781 [salt.state       :300 ][INFO    ][7200] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-15 03:20:42,782 [salt.state       :1951][INFO    ][7200] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:20:42.782116 duration_in_ms=13.412
2019-09-15 03:20:42,783 [salt.state       :1780][INFO    ][7200] Running state [a2enmod headers] at time 03:20:42.783641
2019-09-15 03:20:42,784 [salt.state       :1813][INFO    ][7200] Executing state cmd.run for [a2enmod headers]
2019-09-15 03:20:42,784 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command 'a2enmod headers' in directory '/root'
2019-09-15 03:20:42,859 [salt.state       :300 ][INFO    ][7200] {'pid': 7219, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-15 03:20:42,860 [salt.state       :1951][INFO    ][7200] Completed state [a2enmod headers] at time 03:20:42.860313 duration_in_ms=76.671
2019-09-15 03:20:42,860 [salt.state       :1780][INFO    ][7200] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:20:42.860906
2019-09-15 03:20:42,861 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-15 03:20:42,886 [salt.state       :300 ][INFO    ][7200] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-15 03:20:42,888 [salt.state       :1951][INFO    ][7200] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:20:42.888569 duration_in_ms=27.661
2019-09-15 03:20:42,890 [salt.state       :1780][INFO    ][7200] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:20:42.890750
2019-09-15 03:20:42,891 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-15 03:20:42,980 [salt.state       :300 ][INFO    ][7200] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-15 03:20:42,980 [salt.state       :1951][INFO    ][7200] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:20:42.980699 duration_in_ms=89.949
2019-09-15 03:20:42,981 [salt.state       :1780][INFO    ][7200] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:42.981333
2019-09-15 03:20:42,981 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-15 03:20:43,058 [salt.state       :300 ][INFO    ][7200] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-15 03:20:43,058 [salt.state       :1951][INFO    ][7200] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:43.058833 duration_in_ms=77.499
2019-09-15 03:20:43,059 [salt.state       :1780][INFO    ][7200] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:43.059688
2019-09-15 03:20:43,060 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-15 03:20:43,136 [salt.state       :300 ][INFO    ][7200] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-15 03:20:43,136 [salt.state       :1951][INFO    ][7200] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:43.136381 duration_in_ms=76.693
2019-09-15 03:20:43,136 [salt.state       :1780][INFO    ][7200] Running state [/root/.pgpass] at time 03:20:43.136773
2019-09-15 03:20:43,137 [salt.state       :1813][INFO    ][7200] Executing state file.managed for [/root/.pgpass]
2019-09-15 03:20:43,195 [salt.state       :300 ][INFO    ][7200] File /root/.pgpass is in the correct state
2019-09-15 03:20:43,196 [salt.state       :1951][INFO    ][7200] Completed state [/root/.pgpass] at time 03:20:43.196122 duration_in_ms=59.349
2019-09-15 03:20:43,203 [salt.state       :1780][INFO    ][7200] Running state [maas-region syncdb --noinput] at time 03:20:43.203797
2019-09-15 03:20:43,204 [salt.state       :1813][INFO    ][7200] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-15 03:20:43,205 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-15 03:20:45,265 [salt.state       :300 ][INFO    ][7200] {'pid': 7233, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, contenttypes, sites, auth, metadataserver, 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-09-15 03:20:45,265 [salt.state       :1951][INFO    ][7200] Completed state [maas-region syncdb --noinput] at time 03:20:45.265633 duration_in_ms=2061.835
2019-09-15 03:20:45,266 [salt.state       :2022][WARNING ][7200] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-15 03:20:45,268 [salt.state       :1780][INFO    ][7200] Running state [maas-regiond] at time 03:20:45.268590
2019-09-15 03:20:45,269 [salt.state       :1813][INFO    ][7200] Executing state service.running for [maas-regiond]
2019-09-15 03:20:45,270 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:45,312 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-15 03:20:45,331 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-15 03:20:45,349 [salt.state       :300 ][INFO    ][7200] The service maas-regiond is already running
2019-09-15 03:20:45,350 [salt.state       :1951][INFO    ][7200] Completed state [maas-regiond] at time 03:20:45.350034 duration_in_ms=81.442
2019-09-15 03:20:45,352 [salt.state       :1780][INFO    ][7200] Running state [bind9] at time 03:20:45.352294
2019-09-15 03:20:45,352 [salt.state       :1813][INFO    ][7200] Executing state service.running for [bind9]
2019-09-15 03:20:45,353 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:45,373 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-15 03:20:45,390 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-15 03:20:45,408 [salt.state       :300 ][INFO    ][7200] The service bind9 is already running
2019-09-15 03:20:45,409 [salt.state       :1951][INFO    ][7200] Completed state [bind9] at time 03:20:45.409273 duration_in_ms=56.978
2019-09-15 03:20:45,412 [salt.state       :1780][INFO    ][7200] Running state [apache2] at time 03:20:45.411998
2019-09-15 03:20:45,412 [salt.state       :1813][INFO    ][7200] Executing state service.running for [apache2]
2019-09-15 03:20:45,413 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-15 03:20:45,433 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-15 03:20:45,451 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-15 03:20:45,473 [salt.state       :300 ][INFO    ][7200] The service apache2 is already running
2019-09-15 03:20:45,474 [salt.state       :1951][INFO    ][7200] Completed state [apache2] at time 03:20:45.474280 duration_in_ms=62.282
2019-09-15 03:20:45,476 [salt.state       :1780][INFO    ][7200] Running state [maasng.wait_for_http_code] at time 03:20:45.476400
2019-09-15 03:20:45,476 [salt.state       :1813][INFO    ][7200] Executing state module.run for [maasng.wait_for_http_code]
2019-09-15 03:20:45,477 [salt.utils.decorators:613 ][WARNING ][7200] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:20:45,487 [salt.state       :300 ][INFO    ][7200] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-15 03:20:45,488 [salt.state       :1951][INFO    ][7200] Completed state [maasng.wait_for_http_code] at time 03:20:45.488340 duration_in_ms=11.94
2019-09-15 03:20:45,489 [salt.state       :1780][INFO    ][7200] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:45.489703
2019-09-15 03:20:45,490 [salt.state       :1813][INFO    ][7200] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-15 03:20:45,490 [salt.state       :300 ][INFO    ][7200] /var/lib/maas/.setup_admin exists
2019-09-15 03:20:45,491 [salt.state       :1951][INFO    ][7200] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:45.491227 duration_in_ms=1.524
2019-09-15 03:20:45,492 [salt.state       :1780][INFO    ][7200] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:45.492345
2019-09-15 03:20:45,492 [salt.state       :1813][INFO    ][7200] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:20:45,493 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7200] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:20:46,939 [salt.state       :300 ][INFO    ][7200] {'pid': 7253, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:20:46,940 [salt.state       :1951][INFO    ][7200] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:46.940333 duration_in_ms=1447.988
2019-09-15 03:20:46,949 [salt.state       :1780][INFO    ][7200] Running state [maas_region_boot_source_resources_mirror] at time 03:20:46.949099
2019-09-15 03:20:46,949 [salt.state       :1813][INFO    ][7200] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-15 03:20:47,067 [salt.state       :300 ][INFO    ][7200] {'changes': {}}
2019-09-15 03:20:47,068 [salt.state       :1951][INFO    ][7200] Completed state [maas_region_boot_source_resources_mirror] at time 03:20:47.068003 duration_in_ms=118.903
2019-09-15 03:20:47,069 [salt.state       :1780][INFO    ][7200] Running state [maasng.boot_resources_import] at time 03:20:47.069100
2019-09-15 03:20:47,069 [salt.state       :1813][INFO    ][7200] Executing state module.run for [maasng.boot_resources_import]
2019-09-15 03:20:47,070 [salt.utils.decorators:613 ][WARNING ][7200] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:20:47,195 [salt.loaded.ext.module.maasng:1600][INFO    ][7200] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-15 03:20:52,249 [salt.loaded.ext.module.maasng:1600][INFO    ][7200] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-15 03:20:56,080 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032056067462
2019-09-15 03:20:56,105 [salt.minion      :1432][INFO    ][7281] Starting a new job with PID 7281
2019-09-15 03:20:56,128 [salt.minion      :1711][INFO    ][7281] Returning information for job: 20190915032056067462
2019-09-15 03:20:57,316 [salt.loaded.ext.module.maasng:1600][INFO    ][7200] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-15 03:21:02,435 [salt.state       :300 ][INFO    ][7200] {'ret': True}
2019-09-15 03:21:02,436 [salt.state       :1951][INFO    ][7200] Completed state [maasng.boot_resources_import] at time 03:21:02.436034 duration_in_ms=15366.934
2019-09-15 03:21:02,437 [salt.state       :1780][INFO    ][7200] Running state [maas_region_boot_sources_selection_xenial] at time 03:21:02.437148
2019-09-15 03:21:02,437 [salt.state       :1813][INFO    ][7200] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-15 03:21:02,645 [salt.state       :300 ][INFO    ][7200] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-15 03:21:02,645 [salt.state       :1951][INFO    ][7200] Completed state [maas_region_boot_sources_selection_xenial] at time 03:21:02.645562 duration_in_ms=208.412
2019-09-15 03:21:02,647 [salt.state       :1780][INFO    ][7200] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:21:02.647029
2019-09-15 03:21:02,647 [salt.state       :1813][INFO    ][7200] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-15 03:21:02,648 [salt.utils.decorators:613 ][WARNING ][7200] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:21:02,648 [salt.loaded.ext.module.maasng:1771][INFO    ][7200] boot-sources sync initiated for ALL Rack's
2019-09-15 03:21:03,748 [salt.state       :300 ][INFO    ][7200] {'ret': True}
2019-09-15 03:21:03,749 [salt.state       :1951][INFO    ][7200] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:21:03.749070 duration_in_ms=1102.04
2019-09-15 03:21:03,751 [salt.state       :1780][INFO    ][7200] Running state [maas.process_maas_config] at time 03:21:03.751122
2019-09-15 03:21:03,751 [salt.state       :1813][INFO    ][7200] Executing state module.run for [maas.process_maas_config]
2019-09-15 03:21:03,752 [salt.utils.decorators:613 ][WARNING ][7200] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:21:03,753 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=enable_http_proxy value=True
2019-09-15 03:21:03,816 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=upstream_dns value=8.8.8.8
2019-09-15 03:21:03,885 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=commissioning_distro_series value=xenial
2019-09-15 03:21:03,950 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=default_osystem value=ubuntu
2019-09-15 03:21:06,877 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=active_discovery_interval value=600
2019-09-15 03:21:06,953 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=dnssec_validation value=no
2019-09-15 03:21:07,012 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=maas_name value=mas01
2019-09-15 03:21:07,072 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=network_discovery value=enabled
2019-09-15 03:21:07,171 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=enable_third_party_drivers value=True
2019-09-15 03:21:07,232 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=default_storage_layout value=lvm
2019-09-15 03:21:07,299 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=ntp_external_only value=True
2019-09-15 03:21:07,352 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-15 03:21:07,406 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=default_distro_series value=xenial
2019-09-15 03:21:07,484 [salt.loaded.ext.module.maas:92  ][INFO    ][7200] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-09-15 03:21:07,603 [salt.state       :300 ][INFO    ][7200] {'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-09-15 03:21:07,604 [salt.state       :1951][INFO    ][7200] Completed state [maas.process_maas_config] at time 03:21:07.604355 duration_in_ms=3853.231
2019-09-15 03:21:07,605 [salt.state       :1780][INFO    ][7200] Running state [pxe_admin] at time 03:21:07.605606
2019-09-15 03:21:07,606 [salt.state       :1813][INFO    ][7200] Executing state maasng.fabric_present for [pxe_admin]
2019-09-15 03:21:07,676 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-09-15 03:21:07,753 [salt.loaded.ext.module.maasng:1008][WARNING ][7200] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-15 03:21:07,753 [salt.loaded.ext.module.maasng:1011][WARNING ][7200] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-15 03:21:07,838 [salt.state       :300 ][INFO    ][7200] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-15 03:21:07,839 [salt.state       :1951][INFO    ][7200] Completed state [pxe_admin] at time 03:21:07.839227 duration_in_ms=233.62
2019-09-15 03:21:07,839 [salt.state       :1780][INFO    ][7200] Running state [vlan 0] at time 03:21:07.839791
2019-09-15 03:21:07,840 [salt.state       :1813][INFO    ][7200] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-15 03:21:07,902 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:21:08,028 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-09-15 03:21:08,321 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:21:08,436 [salt.state       :300 ][INFO    ][7200] {'new': 'Vlan untagged was updated'}
2019-09-15 03:21:08,437 [salt.state       :1951][INFO    ][7200] Completed state [vlan 0] at time 03:21:08.437282 duration_in_ms=597.491
2019-09-15 03:21:08,439 [salt.state       :1780][INFO    ][7200] Running state [192.168.11.0/24] at time 03:21:08.438921
2019-09-15 03:21:08,439 [salt.state       :1813][INFO    ][7200] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-15 03:21:08,663 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:21:08,664 [salt.loaded.ext.module.maasng:1235][WARNING ][7200] Ignoring parameter vlan:0
2019-09-15 03:21:08,747 [salt.state       :300 ][INFO    ][7200] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-15 03:21:08,748 [salt.state       :1951][INFO    ][7200] Completed state [192.168.11.0/24] at time 03:21:08.748008 duration_in_ms=309.087
2019-09-15 03:21:08,749 [salt.state       :1780][INFO    ][7200] Running state [maas_create_iprange_1] at time 03:21:08.749316
2019-09-15 03:21:08,749 [salt.state       :1813][INFO    ][7200] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-15 03:21:08,800 [salt.state       :300 ][INFO    ][7200] Iprange maas_create_iprange_1 already exist.
2019-09-15 03:21:08,801 [salt.state       :1951][INFO    ][7200] Completed state [maas_create_iprange_1] at time 03:21:08.801317 duration_in_ms=52.002
2019-09-15 03:21:08,801 [salt.state       :1780][INFO    ][7200] Running state [vlan 0] at time 03:21:08.801747
2019-09-15 03:21:08,802 [salt.state       :1813][INFO    ][7200] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-15 03:21:08,860 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fefcww', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-09-15 03:21:08,975 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fefcww', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:21:09,268 [salt.loaded.ext.module.maasng:945 ][INFO    ][7200] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fefcww', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-09-15 03:21:09,358 [salt.state       :300 ][INFO    ][7200] {'new': 'Vlan untagged was updated'}
2019-09-15 03:21:09,359 [salt.state       :1951][INFO    ][7200] Completed state [vlan 0] at time 03:21:09.358930 duration_in_ms=557.183
2019-09-15 03:21:09,359 [salt.state       :1780][INFO    ][7200] Running state [opnfv] at time 03:21:09.359703
2019-09-15 03:21:09,360 [salt.state       :1813][INFO    ][7200] Executing state maasng.sshkey_present for [opnfv]
2019-09-15 03:21:09,405 [salt.loaded.ext.module.maasng:1903][INFO    ][7200] [{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-09-15 03:21:09,406 [salt.state       :300 ][INFO    ][7200] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-15 03:21:09,406 [salt.state       :1951][INFO    ][7200] Completed state [opnfv] at time 03:21:09.406208 duration_in_ms=46.506
2019-09-15 03:21:09,408 [salt.minion      :1711][INFO    ][7200] Returning information for job: 20190915032041003435
2019-09-15 03:21:09,960 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915032109947007
2019-09-15 03:21:09,982 [salt.minion      :1432][INFO    ][7680] Starting a new job with PID 7680
2019-09-15 03:21:13,745 [salt.state       :915 ][INFO    ][7680] Loading fresh modules for state activity
2019-09-15 03:21:13,843 [salt.state       :1780][INFO    ][7680] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:13.843877
2019-09-15 03:21:13,844 [salt.state       :1813][INFO    ][7680] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:21:13,846 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7680] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:21:15,393 [salt.state       :300 ][INFO    ][7680] {'pid': 7706, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:21:15,394 [salt.state       :1951][INFO    ][7680] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:15.394775 duration_in_ms=1550.899
2019-09-15 03:21:15,397 [salt.state       :1780][INFO    ][7680] Running state [maas.process_machines] at time 03:21:15.397456
2019-09-15 03:21:15,398 [salt.state       :1813][INFO    ][7680] Executing state module.run for [maas.process_machines]
2019-09-15 03:21:15,399 [salt.utils.decorators:613 ][WARNING ][7680] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:21:16,118 [salt.loaded.ext.module.maas:412 ][WARNING ][7680] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:21:16,119 [salt.loaded.ext.module.maas:92  ][INFO    ][7680] 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=s7nc37 architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:21:17,233 [salt.loaded.ext.module.maas:412 ][WARNING ][7680] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:21:17,234 [salt.loaded.ext.module.maas:92  ][INFO    ][7680] 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=rrasen architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:21:18,554 [salt.loaded.ext.module.maas:412 ][WARNING ][7680] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:21:18,555 [salt.loaded.ext.module.maas:92  ][INFO    ][7680] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=prfp3h architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:21:19,910 [salt.loaded.ext.module.maas:412 ][WARNING ][7680] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:21:19,911 [salt.loaded.ext.module.maas:92  ][INFO    ][7680] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=a7khd8 architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:21:21,240 [salt.loaded.ext.module.maas:412 ][WARNING ][7680] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-15 03:21:21,241 [salt.loaded.ext.module.maas:92  ][INFO    ][7680] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=wkqe7f architecture=amd64/generic power_parameters_power_user=admin
2019-09-15 03:21:22,576 [salt.state       :300 ][INFO    ][7680] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-15 03:21:22,576 [salt.state       :1951][INFO    ][7680] Completed state [maas.process_machines] at time 03:21:22.576649 duration_in_ms=7179.192
2019-09-15 03:21:22,580 [salt.minion      :1711][INFO    ][7680] Returning information for job: 20190915032109947007
2019-09-15 03:21:55,863 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915032155850055
2019-09-15 03:21:55,886 [salt.minion      :1432][INFO    ][7934] Starting a new job with PID 7934
2019-09-15 03:21:59,595 [salt.state       :915 ][INFO    ][7934] Loading fresh modules for state activity
2019-09-15 03:21:59,685 [salt.state       :1780][INFO    ][7934] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:59.685788
2019-09-15 03:21:59,686 [salt.state       :1813][INFO    ][7934] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:21:59,688 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7934] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:22:01,089 [salt.state       :300 ][INFO    ][7934] {'pid': 7941, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:22:01,089 [salt.state       :1951][INFO    ][7934] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:22:01.089866 duration_in_ms=1404.078
2019-09-15 03:22:01,090 [salt.state       :1780][INFO    ][7934] Running state [maas.wait_for_machine_status] at time 03:22:01.090939
2019-09-15 03:22:01,091 [salt.state       :1813][INFO    ][7934] Executing state module.run for [maas.wait_for_machine_status]
2019-09-15 03:22:01,091 [salt.utils.decorators:613 ][WARNING ][7934] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:22:01,763 [salt.loaded.ext.module.maas:993 ][INFO    ][7934] Machine s7nc37 mark broken
2019-09-15 03:22:02,360 [salt.loaded.ext.module.maas:996 ][INFO    ][7934] Machine s7nc37 mark fixed
2019-09-15 03:22:03,754 [salt.loaded.ext.module.maas:684 ][INFO    ][7934] deploymachines hwe_kernel=ga-16.04 system_id=s7nc37 distro_series=xenial
2019-09-15 03:22:08,968 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1492.1273849s left)
2019-09-15 03:22:10,885 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032210871141
2019-09-15 03:22:10,907 [salt.minion      :1432][INFO    ][8051] Starting a new job with PID 8051
2019-09-15 03:22:10,934 [salt.minion      :1711][INFO    ][8051] Returning information for job: 20190915032210871141
2019-09-15 03:22:40,934 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032240922644
2019-09-15 03:22:40,949 [salt.minion      :1432][INFO    ][8072] Starting a new job with PID 8072
2019-09-15 03:22:40,971 [salt.minion      :1711][INFO    ][8072] Returning information for job: 20190915032240922644
2019-09-15 03:22:41,863 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1459.23256087s left)
2019-09-15 03:23:10,993 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032310943274
2019-09-15 03:23:11,016 [salt.minion      :1432][INFO    ][8133] Starting a new job with PID 8133
2019-09-15 03:23:11,038 [salt.minion      :1711][INFO    ][8133] Returning information for job: 20190915032310943274
2019-09-15 03:23:15,623 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1425.47218299s left)
2019-09-15 03:23:41,038 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032341025568
2019-09-15 03:23:41,061 [salt.minion      :1432][INFO    ][8156] Starting a new job with PID 8156
2019-09-15 03:23:41,087 [salt.minion      :1711][INFO    ][8156] Returning information for job: 20190915032341025568
2019-09-15 03:23:49,186 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1391.90966988s left)
2019-09-15 03:24:11,096 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032411083406
2019-09-15 03:24:11,118 [salt.minion      :1432][INFO    ][8229] Starting a new job with PID 8229
2019-09-15 03:24:11,143 [salt.minion      :1711][INFO    ][8229] Returning information for job: 20190915032411083406
2019-09-15 03:24:22,893 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1358.20264697s left)
2019-09-15 03:24:41,153 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032441139902
2019-09-15 03:24:41,176 [salt.minion      :1432][INFO    ][8282] Starting a new job with PID 8282
2019-09-15 03:24:41,203 [salt.minion      :1711][INFO    ][8282] Returning information for job: 20190915032441139902
2019-09-15 03:24:56,468 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1324.62739491s left)
2019-09-15 03:25:11,216 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032511203632
2019-09-15 03:25:11,239 [salt.minion      :1432][INFO    ][8492] Starting a new job with PID 8492
2019-09-15 03:25:11,265 [salt.minion      :1711][INFO    ][8492] Returning information for job: 20190915032511203632
2019-09-15 03:25:30,085 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1291.01100898s left)
2019-09-15 03:25:41,279 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032541266429
2019-09-15 03:25:41,302 [salt.minion      :1432][INFO    ][8513] Starting a new job with PID 8513
2019-09-15 03:25:41,330 [salt.minion      :1711][INFO    ][8513] Returning information for job: 20190915032541266429
2019-09-15 03:26:03,664 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1257.43193698s left)
2019-09-15 03:26:11,344 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032611331963
2019-09-15 03:26:11,367 [salt.minion      :1432][INFO    ][8572] Starting a new job with PID 8572
2019-09-15 03:26:11,393 [salt.minion      :1711][INFO    ][8572] Returning information for job: 20190915032611331963
2019-09-15 03:26:37,043 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1224.05279589s left)
2019-09-15 03:26:41,414 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032641402124
2019-09-15 03:26:41,438 [salt.minion      :1432][INFO    ][8596] Starting a new job with PID 8596
2019-09-15 03:26:41,465 [salt.minion      :1711][INFO    ][8596] Returning information for job: 20190915032641402124
2019-09-15 03:27:10,430 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1190.66542983s left)
2019-09-15 03:27:11,495 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032711482625
2019-09-15 03:27:11,517 [salt.minion      :1432][INFO    ][8734] Starting a new job with PID 8734
2019-09-15 03:27:11,543 [salt.minion      :1711][INFO    ][8734] Returning information for job: 20190915032711482625
2019-09-15 03:27:41,585 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032741566887
2019-09-15 03:27:41,608 [salt.minion      :1432][INFO    ][8752] Starting a new job with PID 8752
2019-09-15 03:27:41,634 [salt.minion      :1711][INFO    ][8752] Returning information for job: 20190915032741566887
2019-09-15 03:27:44,069 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1157.02701998s left)
2019-09-15 03:28:11,669 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032811656244
2019-09-15 03:28:11,692 [salt.minion      :1432][INFO    ][8850] Starting a new job with PID 8850
2019-09-15 03:28:11,719 [salt.minion      :1711][INFO    ][8850] Returning information for job: 20190915032811656244
2019-09-15 03:28:18,013 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1123.08283591s left)
2019-09-15 03:28:41,760 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032841747750
2019-09-15 03:28:41,783 [salt.minion      :1432][INFO    ][8885] Starting a new job with PID 8885
2019-09-15 03:28:41,809 [salt.minion      :1711][INFO    ][8885] Returning information for job: 20190915032841747750
2019-09-15 03:28:51,584 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1089.51139498s left)
2019-09-15 03:29:11,857 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032911844988
2019-09-15 03:29:11,881 [salt.minion      :1432][INFO    ][9011] Starting a new job with PID 9011
2019-09-15 03:29:11,906 [salt.minion      :1711][INFO    ][9011] Returning information for job: 20190915032911844988
2019-09-15 03:29:25,189 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1055.90625691s left)
2019-09-15 03:29:41,958 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915032941944863
2019-09-15 03:29:41,983 [salt.minion      :1432][INFO    ][9032] Starting a new job with PID 9032
2019-09-15 03:29:42,011 [salt.minion      :1711][INFO    ][9032] Returning information for job: 20190915032941944863
2019-09-15 03:29:58,822 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1022.27406383s left)
2019-09-15 03:30:12,071 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915033012058596
2019-09-15 03:30:12,095 [salt.minion      :1432][INFO    ][9089] Starting a new job with PID 9089
2019-09-15 03:30:12,124 [salt.minion      :1711][INFO    ][9089] Returning information for job: 20190915033012058596
2019-09-15 03:30:32,162 [salt.loaded.ext.module.maas:1023][INFO    ][7934] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (988.933863878s left)
2019-09-15 03:30:42,258 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command saltutil.find_job with jid 20190915033042245653
2019-09-15 03:30:42,279 [salt.minion      :1432][INFO    ][9142] Starting a new job with PID 9142
2019-09-15 03:30:42,308 [salt.minion      :1711][INFO    ][9142] Returning information for job: 20190915033042245653
2019-09-15 03:31:05,766 [salt.state       :300 ][INFO    ][7934] {'ret': True}
2019-09-15 03:31:05,766 [salt.state       :1951][INFO    ][7934] Completed state [maas.wait_for_machine_status] at time 03:31:05.766424 duration_in_ms=544675.481
2019-09-15 03:31:05,770 [salt.minion      :1711][INFO    ][7934] Returning information for job: 20190915032155850055
2019-09-15 03:31:06,401 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915033106392146
2019-09-15 03:31:06,419 [salt.minion      :1432][INFO    ][9206] Starting a new job with PID 9206
2019-09-15 03:31:09,906 [salt.state       :915 ][INFO    ][9206] Loading fresh modules for state activity
2019-09-15 03:31:10,029 [salt.state       :1780][INFO    ][9206] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:10.029870
2019-09-15 03:31:10,030 [salt.state       :1813][INFO    ][9206] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:31:10,031 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9206] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:31:11,403 [salt.state       :300 ][INFO    ][9206] {'pid': 9312, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:31:11,404 [salt.state       :1951][INFO    ][9206] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:11.404616 duration_in_ms=1374.746
2019-09-15 03:31:11,407 [salt.state       :1780][INFO    ][9206] Running state [maas_machines_storage_cmp002_lvm] at time 03:31:11.407673
2019-09-15 03:31:11,408 [salt.state       :1813][INFO    ][9206] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-15 03:31:12,054 [salt.state       :300 ][INFO    ][9206] Machine cmp002 is not in Ready state.
2019-09-15 03:31:12,054 [salt.state       :1951][INFO    ][9206] Completed state [maas_machines_storage_cmp002_lvm] at time 03:31:12.054527 duration_in_ms=646.852
2019-09-15 03:31:12,055 [salt.state       :1780][INFO    ][9206] Running state [maas_machines_storage_cmp001_lvm] at time 03:31:12.055330
2019-09-15 03:31:12,055 [salt.state       :1813][INFO    ][9206] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-15 03:31:12,872 [salt.state       :300 ][INFO    ][9206] Machine cmp001 is not in Ready state.
2019-09-15 03:31:12,872 [salt.state       :1951][INFO    ][9206] Completed state [maas_machines_storage_cmp001_lvm] at time 03:31:12.872723 duration_in_ms=817.392
2019-09-15 03:31:12,876 [salt.minion      :1711][INFO    ][9206] Returning information for job: 20190915033106392146
2019-09-15 03:31:13,337 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915033113325218
2019-09-15 03:31:13,356 [salt.minion      :1432][INFO    ][9323] Starting a new job with PID 9323
2019-09-15 03:31:13,979 [salt.state       :915 ][INFO    ][9323] Loading fresh modules for state activity
2019-09-15 03:31:14,047 [salt.state       :1780][INFO    ][9323] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:14.047553
2019-09-15 03:31:14,047 [salt.state       :1813][INFO    ][9323] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:31:14,049 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9323] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:31:15,519 [salt.state       :300 ][INFO    ][9323] {'pid': 9330, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:31:15,520 [salt.state       :1951][INFO    ][9323] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:15.520221 duration_in_ms=1472.668
2019-09-15 03:31:15,521 [salt.state       :1780][INFO    ][9323] Running state [maas.deploy_machines] at time 03:31:15.521398
2019-09-15 03:31:15,521 [salt.state       :1813][INFO    ][9323] Executing state module.run for [maas.deploy_machines]
2019-09-15 03:31:15,522 [salt.utils.decorators:613 ][WARNING ][9323] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:31:16,117 [salt.state       :300 ][INFO    ][9323] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-15 03:31:16,118 [salt.state       :1951][INFO    ][9323] Completed state [maas.deploy_machines] at time 03:31:16.118145 duration_in_ms=596.745
2019-09-15 03:31:16,121 [salt.minion      :1711][INFO    ][9323] Returning information for job: 20190915033113325218
2019-09-15 03:31:16,758 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command state.apply with jid 20190915033116744248
2019-09-15 03:31:16,781 [salt.minion      :1432][INFO    ][9340] Starting a new job with PID 9340
2019-09-15 03:31:17,533 [salt.state       :915 ][INFO    ][9340] Loading fresh modules for state activity
2019-09-15 03:31:17,625 [salt.state       :1780][INFO    ][9340] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:17.625160
2019-09-15 03:31:17,625 [salt.state       :1813][INFO    ][9340] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-15 03:31:17,627 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9340] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-15 03:31:19,075 [salt.state       :300 ][INFO    ][9340] {'pid': 9347, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-15 03:31:19,076 [salt.state       :1951][INFO    ][9340] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:31:19.076155 duration_in_ms=1450.997
2019-09-15 03:31:19,077 [salt.state       :1780][INFO    ][9340] Running state [maas.wait_for_machine_status] at time 03:31:19.077724
2019-09-15 03:31:19,077 [salt.state       :1813][INFO    ][9340] Executing state module.run for [maas.wait_for_machine_status]
2019-09-15 03:31:19,078 [salt.utils.decorators:613 ][WARNING ][9340] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-15 03:31:22,238 [salt.state       :300 ][INFO    ][9340] {'ret': True}
2019-09-15 03:31:22,238 [salt.state       :1951][INFO    ][9340] Completed state [maas.wait_for_machine_status] at time 03:31:22.238562 duration_in_ms=3160.836
2019-09-15 03:31:22,242 [salt.minion      :1711][INFO    ][9340] Returning information for job: 20190915033116744248
2019-09-15 04:00:13,137 [salt.utils.schedule:1377][INFO    ][31844] Running scheduled job: __mine_interval
2019-09-15 05:00:13,137 [salt.utils.schedule:1377][INFO    ][31844] Running scheduled job: __mine_interval
2019-09-15 05:00:40,848 [salt.minion      :1308][INFO    ][31844] User sudo_ubuntu Executing command cp.push_dir with jid 20190915050040835773
2019-09-15 05:00:40,869 [salt.minion      :1432][INFO    ][15504] Starting a new job with PID 15504
