2019-07-31 05:07:52,352 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-31 05:08:42,399 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-31 05:09:32,446 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-31 05:10:22,490 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-31 05:11:12,535 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-07-31 05:13:21,890 [salt.utils.decorators:613 ][WARNING ][2831] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 05:13:22,429 [salt.utils.decorators:613 ][WARNING ][2831] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 05:13:24,459 [salt.loaded.int.states.file:2298][WARNING ][2973] 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-07-31 05:13:30,005 [salt.state       :2022][WARNING ][3080] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-31 05:13:32,556 [salt.utils.decorators:613 ][WARNING ][3080] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 05:28:39,474 [salt.utils.decorators:613 ][WARNING ][3080] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 05:58:50,069 [salt.utils.decorators:613 ][WARNING ][3080] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:13:54,225 [salt.utils.decorators:613 ][WARNING ][3080] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:13:58,000 [salt.loaded.ext.module.maasng:1008][WARNING ][3080] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-07-31 06:13:58,000 [salt.loaded.ext.module.maasng:1011][WARNING ][3080] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-07-31 06:13:58,641 [salt.loaded.ext.module.maasng:1235][WARNING ][3080] Ignoring parameter vlan:0
2019-07-31 06:13:59,628 [salt.utils.decorators:613 ][WARNING ][3080] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:14:01,945 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19556] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-31 06:14:01,979 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19556] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-07-31 06:14:02,002 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-07-31 06:14:02,910 [salt.cli.daemons :293 ][INFO    ][19616] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-07-31 06:14:02,987 [salt.cli.daemons :82  ][INFO    ][19616] Starting up the Salt Minion
2019-07-31 06:14:02,987 [salt.utils.event :1017][INFO    ][19616] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-07-31 06:14:03,667 [salt.minion      :976 ][INFO    ][19616] Creating minion process manager
2019-07-31 06:14:04,918 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][19616] Executing command ['date', '+%z'] in directory '/root'
2019-07-31 06:14:04,946 [salt.utils.schedule:568 ][INFO    ][19616] Updating job settings for scheduled job: __mine_interval
2019-07-31 06:14:04,948 [salt.minion      :1108][INFO    ][19616] Added mine.update to scheduler
2019-07-31 06:14:04,953 [salt.minion      :1975][INFO    ][19616] Minion is starting as user 'root'
2019-07-31 06:14:04,967 [salt.minion      :2336][INFO    ][19616] Minion is ready to receive requests!
2019-07-31 06:14:05,568 [salt.utils.decorators:613 ][WARNING ][19555] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:14:05,628 [salt.loaded.ext.module.maas:412 ][WARNING ][19555] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:14:09,128 [salt.loaded.ext.module.maas:412 ][WARNING ][19555] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:14:12,537 [salt.loaded.ext.module.maas:412 ][WARNING ][19555] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:14:15,498 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061415487713
2019-07-31 06:14:15,518 [salt.minion      :1432][INFO    ][19935] Starting a new job with PID 19935
2019-07-31 06:14:15,541 [salt.minion      :1711][INFO    ][19935] Returning information for job: 20190731061415487713
2019-07-31 06:14:16,259 [salt.loaded.ext.module.maas:412 ][WARNING ][19555] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:14:20,166 [salt.loaded.ext.module.maas:412 ][WARNING ][19555] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:14:54,807 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731061454794964
2019-07-31 06:14:54,826 [salt.minion      :1432][INFO    ][20313] Starting a new job with PID 20313
2019-07-31 06:14:58,591 [salt.state       :915 ][INFO    ][20313] Loading fresh modules for state activity
2019-07-31 06:14:58,641 [salt.fileclient  :1219][INFO    ][20313] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-07-31 06:14:58,686 [salt.state       :1780][INFO    ][20313] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:58.686507
2019-07-31 06:14:58,686 [salt.state       :1813][INFO    ][20313] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:14:58,689 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20313] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:14:59,976 [salt.state       :300 ][INFO    ][20313] {'pid': 20347, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:14:59,977 [salt.state       :1951][INFO    ][20313] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:14:59.976864 duration_in_ms=1290.356
2019-07-31 06:14:59,980 [salt.state       :1780][INFO    ][20313] Running state [maas.wait_for_machine_status] at time 06:14:59.980281
2019-07-31 06:14:59,980 [salt.state       :1813][INFO    ][20313] Executing state module.run for [maas.wait_for_machine_status]
2019-07-31 06:14:59,981 [salt.utils.decorators:613 ][WARNING ][20313] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:15:00,823 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.16910481s left)
2019-07-31 06:15:09,870 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061509860431
2019-07-31 06:15:09,889 [salt.minion      :1432][INFO    ][20415] Starting a new job with PID 20415
2019-07-31 06:15:09,911 [salt.minion      :1711][INFO    ][20415] Returning information for job: 20190731061509860431
2019-07-31 06:15:31,818 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.17385101s left)
2019-07-31 06:15:39,942 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061539928980
2019-07-31 06:15:39,962 [salt.minion      :1432][INFO    ][20626] Starting a new job with PID 20626
2019-07-31 06:15:39,977 [salt.minion      :1711][INFO    ][20626] Returning information for job: 20190731061539928980
2019-07-31 06:16:03,036 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.95559382s left)
2019-07-31 06:16:10,165 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061610152551
2019-07-31 06:16:10,187 [salt.minion      :1432][INFO    ][20918] Starting a new job with PID 20918
2019-07-31 06:16:10,208 [salt.minion      :1711][INFO    ][20918] Returning information for job: 20190731061610152551
2019-07-31 06:16:33,886 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.10628295s left)
2019-07-31 06:16:40,222 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061640208222
2019-07-31 06:16:40,240 [salt.minion      :1432][INFO    ][21559] Starting a new job with PID 21559
2019-07-31 06:16:40,256 [salt.minion      :1711][INFO    ][21559] Returning information for job: 20190731061640208222
2019-07-31 06:17:05,464 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.52802491s left)
2019-07-31 06:17:10,285 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061710271650
2019-07-31 06:17:10,308 [salt.minion      :1432][INFO    ][21895] Starting a new job with PID 21895
2019-07-31 06:17:10,332 [salt.minion      :1711][INFO    ][21895] Returning information for job: 20190731061710271650
2019-07-31 06:17:37,006 [salt.loaded.ext.module.maas:1023][INFO    ][20313] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.98583794s left)
2019-07-31 06:17:40,346 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061740332189
2019-07-31 06:17:40,367 [salt.minion      :1432][INFO    ][22365] Starting a new job with PID 22365
2019-07-31 06:17:40,383 [salt.minion      :1711][INFO    ][22365] Returning information for job: 20190731061740332189
2019-07-31 06:18:10,422 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061810409941
2019-07-31 06:18:10,442 [salt.minion      :1432][INFO    ][22741] Starting a new job with PID 22741
2019-07-31 06:18:10,465 [salt.minion      :1711][INFO    ][22741] Returning information for job: 20190731061810409941
2019-07-31 06:18:10,604 [salt.state       :300 ][INFO    ][20313] {'ret': True}
2019-07-31 06:18:10,604 [salt.state       :1951][INFO    ][20313] Completed state [maas.wait_for_machine_status] at time 06:18:10.604725 duration_in_ms=190624.444
2019-07-31 06:18:10,607 [salt.minion      :1711][INFO    ][20313] Returning information for job: 20190731061454794964
2019-07-31 06:18:11,172 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731061811165029
2019-07-31 06:18:11,190 [salt.minion      :1432][INFO    ][22753] Starting a new job with PID 22753
2019-07-31 06:18:14,774 [salt.state       :915 ][INFO    ][22753] Loading fresh modules for state activity
2019-07-31 06:18:14,825 [salt.fileclient  :1219][INFO    ][22753] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-07-31 06:18:14,913 [salt.state       :1780][INFO    ][22753] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:14.913764
2019-07-31 06:18:14,914 [salt.state       :1813][INFO    ][22753] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:18:14,915 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22753] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:18:16,250 [salt.state       :300 ][INFO    ][22753] {'pid': 22788, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:18:16,251 [salt.state       :1951][INFO    ][22753] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:16.251509 duration_in_ms=1337.744
2019-07-31 06:18:16,254 [salt.state       :1780][INFO    ][22753] Running state [maas_machines_storage_cmp002_lvm] at time 06:18:16.254545
2019-07-31 06:18:16,255 [salt.state       :1813][INFO    ][22753] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-07-31 06:18:17,616 [salt.loaded.ext.module.maasng:610 ][INFO    ][22753] 4mca4c
2019-07-31 06:18:17,616 [salt.loaded.ext.module.maasng:626 ][INFO    ][22753] sda
2019-07-31 06:18:18,270 [salt.loaded.ext.module.maasng:361 ][INFO    ][22753] 4mca4c
2019-07-31 06:18:18,403 [salt.loaded.ext.module.maasng:367 ][INFO    ][22753] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'a1b9d331-a6ff-4d1e-bdbe-7058ea45f94d', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/partition/3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4mca4c', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'b43bb304-ff0e-45f5-9f6a-af69f57e2e3a', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 3, u'device_id': 3}], u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'4mca4c', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 3, u'uuid': None}, {u'size': 2397988454400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/8/', u'used_size': 2397988454400, u'partitions': [], u'tags': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'1ab1b1bc-bb71-4717-b55b-669c6b10fa26', u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4mca4c', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 8, u'uuid': u'bdea972e-6c4b-45e9-9f31-53181c86fc19'}]
2019-07-31 06:18:18,403 [salt.loaded.ext.module.maasng:632 ][INFO    ][22753] vgroot
2019-07-31 06:18:18,404 [salt.loaded.ext.module.maasng:635 ][INFO    ][22753] lvroot
2019-07-31 06:18:18,404 [salt.loaded.ext.module.maasng:639 ][INFO    ][22753] 107374182400
2019-07-31 06:18:19,112 [salt.loaded.ext.module.maasng:645 ][INFO    ][22753] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.40'], u'cpu_count': 16, u'owner_data': {}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 26}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'system_id': u'4mca4c', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/interfaces/4/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/4mca4c/', u'disable_ipv4': False, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'4mca4c', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'available_size': 0, u'uuid': u'11cde31c-880d-4e65-85ae-199393125037', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4mca4c', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'8056bc83-868f-4c80-b207-9bcecfe6133d', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/11/', u'used_size': 107374182400, u'id': 11, u'size': 107374182400}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'4819e391-4a19-426a-8d73-b180a19ef578', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4mca4c', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'92449c25-7630-4c65-8be9-66193845aa90', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'4mca4c', 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': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/'}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'uuid': u'11cde31c-880d-4e65-85ae-199393125037', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4mca4c', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'8056bc83-868f-4c80-b207-9bcecfe6133d', u'fstype': u'ext4', 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'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/11/'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'4819e391-4a19-426a-8d73-b180a19ef578', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4mca4c', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'92449c25-7630-4c65-8be9-66193845aa90', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'4mca4c', 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'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'4mca4c', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'4819e391-4a19-426a-8d73-b180a19ef578', u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4mca4c', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'92449c25-7630-4c65-8be9-66193845aa90', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 3}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'4mca4c', 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'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'size': 2397998940160}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'current_commissioning_result_id': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 26}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'system_id': u'4mca4c', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/interfaces/4/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 17, u'discovered': None, u'system_id': u'4mca4c', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/interfaces/17/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 28}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 15, u'discovered': None, u'system_id': u'4mca4c', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/interfaces/15/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 29}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 16, u'discovered': None, u'system_id': u'4mca4c', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4mca4c/interfaces/16/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-07-31 06:18:19,115 [salt.state       :300 ][INFO    ][22753] {'new': {'storage_layout': 'lvm'}}
2019-07-31 06:18:19,115 [salt.state       :1951][INFO    ][22753] Completed state [maas_machines_storage_cmp002_lvm] at time 06:18:19.115439 duration_in_ms=2860.893
2019-07-31 06:18:19,116 [salt.state       :1780][INFO    ][22753] Running state [maas_machines_storage_cmp001_lvm] at time 06:18:19.116012
2019-07-31 06:18:19,116 [salt.state       :1813][INFO    ][22753] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-07-31 06:18:20,736 [salt.loaded.ext.module.maasng:610 ][INFO    ][22753] ynackt
2019-07-31 06:18:20,736 [salt.loaded.ext.module.maasng:626 ][INFO    ][22753] sda
2019-07-31 06:18:21,342 [salt.loaded.ext.module.maasng:361 ][INFO    ][22753] ynackt
2019-07-31 06:18:21,486 [salt.loaded.ext.module.maasng:367 ][INFO    ][22753] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'53b37014-1244-4bf1-9901-3fb6de9ab2b7', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/partition/1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ynackt', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'cdf8551c-989d-4482-8b17-8f3799d569af', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 1, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'ynackt', 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'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/'}, {u'size': 2397988454400, u'model': None, u'available_size': 0, u'uuid': u'27783745-f9d7-40a4-8131-7c555be5b872', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'ynackt', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'7c0613ca-e1bc-4a6e-b3cf-7e00bc32c55d', u'fstype': u'ext4', 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': 2397988454400, u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/6/'}]
2019-07-31 06:18:21,486 [salt.loaded.ext.module.maasng:632 ][INFO    ][22753] vgroot
2019-07-31 06:18:21,487 [salt.loaded.ext.module.maasng:635 ][INFO    ][22753] lvroot
2019-07-31 06:18:21,487 [salt.loaded.ext.module.maasng:639 ][INFO    ][22753] 107374182400
2019-07-31 06:18:21,821 [salt.loaded.ext.module.maasng:645 ][INFO    ][22753] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'ynackt', 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'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'9751ce72-7161-4862-9661-9f70f82ed446', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ynackt', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'0e6a1fdc-810a-4362-af7b-da941fef0123', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'ynackt', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 1, u'uuid': None}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/12/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'a924f1e9-9d0e-430e-a02f-3da302d502c7', u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'ynackt', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 12, u'uuid': u'00fb4f77-8d15-4f0a-9372-4fdbec083d3d'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'9751ce72-7161-4862-9661-9f70f82ed446', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ynackt', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'0e6a1fdc-810a-4362-af7b-da941fef0123', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'ynackt', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 1, u'uuid': None}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'ynackt', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'ynackt', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'ynackt', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'ynackt', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'ynackt', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/12/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'a924f1e9-9d0e-430e-a02f-3da302d502c7', u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'ynackt', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 12, u'uuid': u'00fb4f77-8d15-4f0a-9372-4fdbec083d3d'}], u'ip_addresses': [u'192.168.11.38'], u'architecture': u'amd64/generic', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'ynackt', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/interfaces/5/'}, u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'9751ce72-7161-4862-9661-9f70f82ed446', u'resource_uri': u'/MAAS/api/2.0/nodes/ynackt/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ynackt', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'0e6a1fdc-810a-4362-af7b-da941fef0123', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'ynackt', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 1, u'uuid': None}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/ynackt/', u'distro_series': u'', u'memory_test_status': -1}
2019-07-31 06:18:21,822 [salt.state       :300 ][INFO    ][22753] {'new': {'storage_layout': 'lvm'}}
2019-07-31 06:18:21,823 [salt.state       :1951][INFO    ][22753] Completed state [maas_machines_storage_cmp001_lvm] at time 06:18:21.823011 duration_in_ms=2706.998
2019-07-31 06:18:21,825 [salt.minion      :1711][INFO    ][22753] Returning information for job: 20190731061811165029
2019-07-31 06:18:22,297 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731061822285162
2019-07-31 06:18:22,314 [salt.minion      :1432][INFO    ][22882] Starting a new job with PID 22882
2019-07-31 06:18:22,998 [salt.state       :915 ][INFO    ][22882] Loading fresh modules for state activity
2019-07-31 06:18:23,048 [salt.fileclient  :1219][INFO    ][22882] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-07-31 06:18:23,082 [salt.state       :1780][INFO    ][22882] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:23.082824
2019-07-31 06:18:23,083 [salt.state       :1813][INFO    ][22882] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:18:23,085 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22882] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:18:24,600 [salt.state       :300 ][INFO    ][22882] {'pid': 22893, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:18:24,601 [salt.state       :1951][INFO    ][22882] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:24.600952 duration_in_ms=1518.126
2019-07-31 06:18:24,603 [salt.state       :1780][INFO    ][22882] Running state [maas.deploy_machines] at time 06:18:24.603755
2019-07-31 06:18:24,604 [salt.state       :1813][INFO    ][22882] Executing state module.run for [maas.deploy_machines]
2019-07-31 06:18:24,605 [salt.utils.decorators:613 ][WARNING ][22882] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:18:25,105 [salt.loaded.ext.module.maas:684 ][INFO    ][22882] deploymachines hwe_kernel=hwe-16.04 system_id=4mca4c distro_series=xenial
2019-07-31 06:18:31,392 [salt.loaded.ext.module.maas:684 ][INFO    ][22882] deploymachines hwe_kernel=hwe-16.04 system_id=ynackt distro_series=xenial
2019-07-31 06:18:36,799 [salt.loaded.ext.module.maas:684 ][INFO    ][22882] deploymachines hwe_kernel=hwe-16.04 system_id=4bnsan distro_series=xenial
2019-07-31 06:18:37,367 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061837356524
2019-07-31 06:18:37,383 [salt.minion      :1432][INFO    ][23158] Starting a new job with PID 23158
2019-07-31 06:18:37,394 [salt.minion      :1711][INFO    ][23158] Returning information for job: 20190731061837356524
2019-07-31 06:18:41,183 [salt.loaded.ext.module.maas:684 ][INFO    ][22882] deploymachines hwe_kernel=hwe-16.04 system_id=kq4fqa distro_series=xenial
2019-07-31 06:18:45,941 [salt.loaded.ext.module.maas:684 ][INFO    ][22882] deploymachines hwe_kernel=hwe-16.04 system_id=8xer3x distro_series=xenial
2019-07-31 06:18:50,284 [salt.state       :300 ][INFO    ][22882] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-07-31 06:18:50,285 [salt.state       :1951][INFO    ][22882] Completed state [maas.deploy_machines] at time 06:18:50.285173 duration_in_ms=25681.417
2019-07-31 06:18:50,288 [salt.minion      :1711][INFO    ][22882] Returning information for job: 20190731061822285162
2019-07-31 06:18:50,837 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731061850826429
2019-07-31 06:18:50,855 [salt.minion      :1432][INFO    ][23400] Starting a new job with PID 23400
2019-07-31 06:18:54,404 [salt.state       :915 ][INFO    ][23400] Loading fresh modules for state activity
2019-07-31 06:18:54,434 [salt.fileclient  :1219][INFO    ][23400] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-07-31 06:18:54,460 [salt.state       :1780][INFO    ][23400] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:54.460364
2019-07-31 06:18:54,460 [salt.state       :1813][INFO    ][23400] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:18:54,461 [salt.loaded.int.module.cmdmod:395 ][INFO    ][23400] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:18:55,688 [salt.state       :300 ][INFO    ][23400] {'pid': 23427, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:18:55,688 [salt.state       :1951][INFO    ][23400] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:55.688624 duration_in_ms=1228.261
2019-07-31 06:18:55,690 [salt.state       :1780][INFO    ][23400] Running state [maas.wait_for_machine_status] at time 06:18:55.689993
2019-07-31 06:18:55,690 [salt.state       :1813][INFO    ][23400] Executing state module.run for [maas.wait_for_machine_status]
2019-07-31 06:18:55,690 [salt.utils.decorators:613 ][WARNING ][23400] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:18:58,826 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.86907315s left)
2019-07-31 06:19:05,922 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061905909031
2019-07-31 06:19:05,939 [salt.minion      :1432][INFO    ][23520] Starting a new job with PID 23520
2019-07-31 06:19:05,955 [salt.minion      :1711][INFO    ][23520] Returning information for job: 20190731061905909031
2019-07-31 06:19:32,125 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.56983495s left)
2019-07-31 06:19:35,962 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731061935950163
2019-07-31 06:19:35,986 [salt.minion      :1432][INFO    ][23920] Starting a new job with PID 23920
2019-07-31 06:19:36,007 [salt.minion      :1711][INFO    ][23920] Returning information for job: 20190731061935950163
2019-07-31 06:20:05,914 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.781317s left)
2019-07-31 06:20:06,062 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062006049130
2019-07-31 06:20:06,084 [salt.minion      :1432][INFO    ][24135] Starting a new job with PID 24135
2019-07-31 06:20:06,107 [salt.minion      :1711][INFO    ][24135] Returning information for job: 20190731062006049130
2019-07-31 06:20:36,117 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062036104404
2019-07-31 06:20:36,138 [salt.minion      :1432][INFO    ][24524] Starting a new job with PID 24524
2019-07-31 06:20:36,161 [salt.minion      :1711][INFO    ][24524] Returning information for job: 20190731062036104404
2019-07-31 06:20:38,790 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.90506506s left)
2019-07-31 06:21:06,176 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062106162523
2019-07-31 06:21:06,197 [salt.minion      :1432][INFO    ][24853] Starting a new job with PID 24853
2019-07-31 06:21:06,222 [salt.minion      :1711][INFO    ][24853] Returning information for job: 20190731062106162523
2019-07-31 06:21:11,980 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.71538615s left)
2019-07-31 06:21:36,227 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062136216888
2019-07-31 06:21:36,239 [salt.minion      :1432][INFO    ][25596] Starting a new job with PID 25596
2019-07-31 06:21:36,250 [salt.minion      :1711][INFO    ][25596] Returning information for job: 20190731062136216888
2019-07-31 06:21:45,727 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.96784496s left)
2019-07-31 06:22:06,259 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062206247087
2019-07-31 06:22:06,279 [salt.minion      :1432][INFO    ][25995] Starting a new job with PID 25995
2019-07-31 06:22:06,301 [salt.minion      :1711][INFO    ][25995] Returning information for job: 20190731062206247087
2019-07-31 06:22:19,561 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.13428712s left)
2019-07-31 06:22:36,321 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062236308760
2019-07-31 06:22:36,343 [salt.minion      :1432][INFO    ][26286] Starting a new job with PID 26286
2019-07-31 06:22:36,366 [salt.minion      :1711][INFO    ][26286] Returning information for job: 20190731062236308760
2019-07-31 06:22:52,692 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.00294805s left)
2019-07-31 06:23:06,406 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062306394039
2019-07-31 06:23:06,432 [salt.minion      :1432][INFO    ][26490] Starting a new job with PID 26490
2019-07-31 06:23:06,456 [salt.minion      :1711][INFO    ][26490] Returning information for job: 20190731062306394039
2019-07-31 06:23:25,821 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.87383509s left)
2019-07-31 06:23:36,473 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062336466948
2019-07-31 06:23:36,485 [salt.minion      :1432][INFO    ][27233] Starting a new job with PID 27233
2019-07-31 06:23:36,497 [salt.minion      :1711][INFO    ][27233] Returning information for job: 20190731062336466948
2019-07-31 06:23:58,919 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.77639914s left)
2019-07-31 06:24:06,531 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062406519453
2019-07-31 06:24:06,552 [salt.minion      :1432][INFO    ][27517] Starting a new job with PID 27517
2019-07-31 06:24:06,572 [salt.minion      :1711][INFO    ][27517] Returning information for job: 20190731062406519453
2019-07-31 06:24:32,271 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.42467809s left)
2019-07-31 06:24:36,620 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062436607013
2019-07-31 06:24:36,642 [salt.minion      :1432][INFO    ][28057] Starting a new job with PID 28057
2019-07-31 06:24:36,664 [salt.minion      :1711][INFO    ][28057] Returning information for job: 20190731062436607013
2019-07-31 06:25:05,455 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.23994398s left)
2019-07-31 06:25:06,694 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062506681601
2019-07-31 06:25:06,712 [salt.minion      :1432][INFO    ][28326] Starting a new job with PID 28326
2019-07-31 06:25:06,735 [salt.minion      :1711][INFO    ][28326] Returning information for job: 20190731062506681601
2019-07-31 06:25:36,779 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062536767032
2019-07-31 06:25:36,799 [salt.minion      :1432][INFO    ][28545] Starting a new job with PID 28545
2019-07-31 06:25:36,821 [salt.minion      :1711][INFO    ][28545] Returning information for job: 20190731062536767032
2019-07-31 06:25:38,702 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.9931941s left)
2019-07-31 06:26:06,969 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062606960129
2019-07-31 06:26:06,988 [salt.minion      :1432][INFO    ][28861] Starting a new job with PID 28861
2019-07-31 06:26:07,004 [salt.minion      :1711][INFO    ][28861] Returning information for job: 20190731062606960129
2019-07-31 06:26:12,490 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.20561004s left)
2019-07-31 06:26:37,150 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062637138416
2019-07-31 06:26:37,171 [salt.minion      :1432][INFO    ][29609] Starting a new job with PID 29609
2019-07-31 06:26:37,187 [salt.minion      :1711][INFO    ][29609] Returning information for job: 20190731062637138416
2019-07-31 06:26:46,095 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1779.60029101s left)
2019-07-31 06:27:07,271 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062707258381
2019-07-31 06:27:07,291 [salt.minion      :1432][INFO    ][29775] Starting a new job with PID 29775
2019-07-31 06:27:07,315 [salt.minion      :1711][INFO    ][29775] Returning information for job: 20190731062707258381
2019-07-31 06:27:19,616 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1746.07888913s left)
2019-07-31 06:27:37,417 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062737404428
2019-07-31 06:27:37,438 [salt.minion      :1432][INFO    ][29984] Starting a new job with PID 29984
2019-07-31 06:27:37,462 [salt.minion      :1711][INFO    ][29984] Returning information for job: 20190731062737404428
2019-07-31 06:27:53,384 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1712.31115508s left)
2019-07-31 06:28:07,556 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062807543533
2019-07-31 06:28:07,578 [salt.minion      :1432][INFO    ][30160] Starting a new job with PID 30160
2019-07-31 06:28:07,601 [salt.minion      :1711][INFO    ][30160] Returning information for job: 20190731062807543533
2019-07-31 06:28:26,665 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1679.03005505s left)
2019-07-31 06:28:37,679 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062837668425
2019-07-31 06:28:37,700 [salt.minion      :1432][INFO    ][30275] Starting a new job with PID 30275
2019-07-31 06:28:37,720 [salt.minion      :1711][INFO    ][30275] Returning information for job: 20190731062837668425
2019-07-31 06:29:00,815 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1644.88077998s left)
2019-07-31 06:29:07,806 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062907794567
2019-07-31 06:29:07,825 [salt.minion      :1432][INFO    ][30464] Starting a new job with PID 30464
2019-07-31 06:29:07,847 [salt.minion      :1711][INFO    ][30464] Returning information for job: 20190731062907794567
2019-07-31 06:29:34,031 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1611.664294s left)
2019-07-31 06:29:37,942 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731062937929421
2019-07-31 06:29:37,964 [salt.minion      :1432][INFO    ][30520] Starting a new job with PID 30520
2019-07-31 06:29:37,989 [salt.minion      :1711][INFO    ][30520] Returning information for job: 20190731062937929421
2019-07-31 06:30:07,644 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1578.05108213s left)
2019-07-31 06:30:08,095 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063008081797
2019-07-31 06:30:08,117 [salt.minion      :1432][INFO    ][30544] Starting a new job with PID 30544
2019-07-31 06:30:08,141 [salt.minion      :1711][INFO    ][30544] Returning information for job: 20190731063008081797
2019-07-31 06:30:38,256 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063038244626
2019-07-31 06:30:38,277 [salt.minion      :1432][INFO    ][30600] Starting a new job with PID 30600
2019-07-31 06:30:38,301 [salt.minion      :1711][INFO    ][30600] Returning information for job: 20190731063038244626
2019-07-31 06:30:41,056 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1544.63916397s left)
2019-07-31 06:31:08,421 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063108408746
2019-07-31 06:31:08,445 [salt.minion      :1432][INFO    ][30622] Starting a new job with PID 30622
2019-07-31 06:31:08,469 [salt.minion      :1711][INFO    ][30622] Returning information for job: 20190731063108408746
2019-07-31 06:31:14,476 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1511.21893311s left)
2019-07-31 06:31:38,601 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063138588793
2019-07-31 06:31:38,623 [salt.minion      :1432][INFO    ][30683] Starting a new job with PID 30683
2019-07-31 06:31:38,648 [salt.minion      :1711][INFO    ][30683] Returning information for job: 20190731063138588793
2019-07-31 06:31:47,758 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1477.93715906s left)
2019-07-31 06:32:08,788 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063208775869
2019-07-31 06:32:08,811 [salt.minion      :1432][INFO    ][30703] Starting a new job with PID 30703
2019-07-31 06:32:08,835 [salt.minion      :1711][INFO    ][30703] Returning information for job: 20190731063208775869
2019-07-31 06:32:20,622 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1445.073524s left)
2019-07-31 06:32:38,993 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063238980033
2019-07-31 06:32:39,015 [salt.minion      :1432][INFO    ][30761] Starting a new job with PID 30761
2019-07-31 06:32:39,039 [salt.minion      :1711][INFO    ][30761] Returning information for job: 20190731063238980033
2019-07-31 06:32:54,156 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1411.53997803s left)
2019-07-31 06:33:09,204 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063309191987
2019-07-31 06:33:09,227 [salt.minion      :1432][INFO    ][30781] Starting a new job with PID 30781
2019-07-31 06:33:09,250 [salt.minion      :1711][INFO    ][30781] Returning information for job: 20190731063309191987
2019-07-31 06:33:26,958 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1378.73775601s left)
2019-07-31 06:33:39,419 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063339406223
2019-07-31 06:33:39,442 [salt.minion      :1432][INFO    ][30851] Starting a new job with PID 30851
2019-07-31 06:33:39,465 [salt.minion      :1711][INFO    ][30851] Returning information for job: 20190731063339406223
2019-07-31 06:34:00,641 [salt.loaded.ext.module.maas:1023][INFO    ][23400] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1345.05391908s left)
2019-07-31 06:34:09,438 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063409425907
2019-07-31 06:34:09,461 [salt.minion      :1432][INFO    ][30880] Starting a new job with PID 30880
2019-07-31 06:34:09,484 [salt.minion      :1711][INFO    ][30880] Returning information for job: 20190731063409425907
2019-07-31 06:34:34,019 [salt.loaded.ext.module.maas:993 ][INFO    ][23400] Machine 8xer3x mark broken
2019-07-31 06:34:34,764 [salt.loaded.ext.module.maas:996 ][INFO    ][23400] Machine 8xer3x mark fixed
2019-07-31 06:34:35,516 [salt.loaded.ext.module.maas:684 ][INFO    ][23400] deploymachines hwe_kernel=hwe-16.04 system_id=8xer3x distro_series=xenial
2019-07-31 06:34:39,475 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063439463223
2019-07-31 06:34:39,495 [salt.minion      :1432][INFO    ][30988] Starting a new job with PID 30988
2019-07-31 06:34:39,520 [salt.minion      :1711][INFO    ][30988] Returning information for job: 20190731063439463223
2019-07-31 06:34:42,847 [salt.loaded.ext.module.maas:160 ][ERROR   ][23400] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-07-31 06:34:42,849 [salt.state       :302 ][ERROR   ][23400] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-07-31 06:34:42,849 [salt.state       :1951][INFO    ][23400] Completed state [maas.wait_for_machine_status] at time 06:34:42.849421 duration_in_ms=947159.421
2019-07-31 06:34:42,855 [salt.minion      :1711][INFO    ][23400] Returning information for job: 20190731061850826429
2019-07-31 06:34:53,571 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command pillar.get with jid 20190731063453557991
2019-07-31 06:34:53,592 [salt.minion      :1432][INFO    ][31025] Starting a new job with PID 31025
2019-07-31 06:34:53,600 [salt.minion      :1711][INFO    ][31025] Returning information for job: 20190731063453557991
2019-07-31 06:34:54,069 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command service.status with jid 20190731063454056254
2019-07-31 06:34:54,090 [salt.minion      :1432][INFO    ][31030] Starting a new job with PID 31030
2019-07-31 06:34:54,482 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][31030] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-07-31 06:34:54,516 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][31030] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-07-31 06:34:54,532 [salt.minion      :1711][INFO    ][31030] Returning information for job: 20190731063454056254
2019-07-31 06:34:55,034 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731063455021894
2019-07-31 06:34:55,055 [salt.minion      :1432][INFO    ][31041] Starting a new job with PID 31041
2019-07-31 06:34:58,594 [salt.state       :915 ][INFO    ][31041] Loading fresh modules for state activity
2019-07-31 06:34:58,936 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'salt-minion --version' in directory '/root'
2019-07-31 06:34:59,306 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'salt-minion --version' in directory '/root'
2019-07-31 06:35:00,182 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'salt-minion --version' in directory '/root'
2019-07-31 06:35:00,552 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'salt-minion --version' in directory '/root'
2019-07-31 06:35:02,042 [salt.state       :1780][INFO    ][31041] Running state [salt-minion] at time 06:35:02.042835
2019-07-31 06:35:02,043 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [salt-minion]
2019-07-31 06:35:02,043 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-31 06:35:02,148 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,148 [salt.state       :1951][INFO    ][31041] Completed state [salt-minion] at time 06:35:02.148728 duration_in_ms=105.892
2019-07-31 06:35:02,149 [salt.state       :1780][INFO    ][31041] Running state [salt_minion_dependency_packages] at time 06:35:02.149110
2019-07-31 06:35:02,149 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-07-31 06:35:02,156 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,157 [salt.state       :1951][INFO    ][31041] Completed state [salt_minion_dependency_packages] at time 06:35:02.156996 duration_in_ms=7.886
2019-07-31 06:35:02,160 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/minion.d/minion.conf] at time 06:35:02.160538
2019-07-31 06:35:02,160 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-07-31 06:35:02,374 [salt.state       :300 ][INFO    ][31041] File /etc/salt/minion.d/minion.conf is in the correct state
2019-07-31 06:35:02,374 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/minion.d/minion.conf] at time 06:35:02.374360 duration_in_ms=213.822
2019-07-31 06:35:02,374 [salt.state       :1780][INFO    ][31041] Running state [python-netaddr] at time 06:35:02.374564
2019-07-31 06:35:02,374 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [python-netaddr]
2019-07-31 06:35:02,381 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,381 [salt.state       :1951][INFO    ][31041] Completed state [python-netaddr] at time 06:35:02.381682 duration_in_ms=7.118
2019-07-31 06:35:02,384 [salt.state       :1780][INFO    ][31041] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:35:02.384672
2019-07-31 06:35:02,384 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-07-31 06:35:02,396 [salt.state       :300 ][INFO    ][31041] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-07-31 06:35:02,396 [salt.state       :1951][INFO    ][31041] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:35:02.396554 duration_in_ms=11.882
2019-07-31 06:35:02,397 [salt.state       :1780][INFO    ][31041] Running state [salt-minion] at time 06:35:02.397536
2019-07-31 06:35:02,397 [salt.state       :1813][INFO    ][31041] Executing state service.running for [salt-minion]
2019-07-31 06:35:02,398 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:02,437 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-07-31 06:35:02,455 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-07-31 06:35:02,472 [salt.state       :300 ][INFO    ][31041] The service salt-minion is already running
2019-07-31 06:35:02,473 [salt.state       :1951][INFO    ][31041] Completed state [salt-minion] at time 06:35:02.473363 duration_in_ms=75.826
2019-07-31 06:35:02,475 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains.d] at time 06:35:02.475396
2019-07-31 06:35:02,475 [salt.state       :1813][INFO    ][31041] Executing state file.directory for [/etc/salt/grains.d]
2019-07-31 06:35:02,477 [salt.state       :300 ][INFO    ][31041] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-07-31 06:35:02,477 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains.d] at time 06:35:02.477363 duration_in_ms=1.967
2019-07-31 06:35:02,478 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains] at time 06:35:02.478265
2019-07-31 06:35:02,478 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/grains]
2019-07-31 06:35:02,479 [salt.state       :300 ][INFO    ][31041] File /etc/salt/grains exists with proper permissions. No changes made.
2019-07-31 06:35:02,479 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains] at time 06:35:02.479684 duration_in_ms=1.418
2019-07-31 06:35:02,480 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains.d/placeholder] at time 06:35:02.480289
2019-07-31 06:35:02,480 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-07-31 06:35:02,481 [salt.state       :300 ][INFO    ][31041] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-07-31 06:35:02,481 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains.d/placeholder] at time 06:35:02.481670 duration_in_ms=1.381
2019-07-31 06:35:02,482 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains.d/sphinx] at time 06:35:02.482278
2019-07-31 06:35:02,482 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-07-31 06:35:02,494 [salt.state       :300 ][INFO    ][31041] File /etc/salt/grains.d/sphinx is in the correct state
2019-07-31 06:35:02,494 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains.d/sphinx] at time 06:35:02.494439 duration_in_ms=12.161
2019-07-31 06:35:02,497 [salt.state       :1780][INFO    ][31041] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.497512
2019-07-31 06:35:02,497 [salt.state       :1813][INFO    ][31041] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-07-31 06:35:02,498 [salt.state       :300 ][INFO    ][31041] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-07-31 06:35:02,498 [salt.state       :1951][INFO    ][31041] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.498701 duration_in_ms=1.189
2019-07-31 06:35:02,499 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains.d/dns_records] at time 06:35:02.499345
2019-07-31 06:35:02,499 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-07-31 06:35:02,511 [salt.state       :300 ][INFO    ][31041] File /etc/salt/grains.d/dns_records is in the correct state
2019-07-31 06:35:02,512 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains.d/dns_records] at time 06:35:02.512255 duration_in_ms=12.91
2019-07-31 06:35:02,513 [salt.state       :1780][INFO    ][31041] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.513542
2019-07-31 06:35:02,513 [salt.state       :1813][INFO    ][31041] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-07-31 06:35:02,514 [salt.state       :300 ][INFO    ][31041] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-07-31 06:35:02,514 [salt.state       :1951][INFO    ][31041] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.514712 duration_in_ms=1.169
2019-07-31 06:35:02,515 [salt.state       :1780][INFO    ][31041] Running state [/etc/salt/grains.d/salt] at time 06:35:02.515362
2019-07-31 06:35:02,515 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-07-31 06:35:02,530 [salt.state       :300 ][INFO    ][31041] File /etc/salt/grains.d/salt is in the correct state
2019-07-31 06:35:02,530 [salt.state       :1951][INFO    ][31041] Completed state [/etc/salt/grains.d/salt] at time 06:35:02.530281 duration_in_ms=14.92
2019-07-31 06:35:02,531 [salt.state       :1780][INFO    ][31041] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.531523
2019-07-31 06:35:02,531 [salt.state       :1813][INFO    ][31041] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-07-31 06:35:02,532 [salt.state       :300 ][INFO    ][31041] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-07-31 06:35:02,532 [salt.state       :1951][INFO    ][31041] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:35:02.532695 duration_in_ms=1.172
2019-07-31 06:35:02,535 [salt.state       :1780][INFO    ][31041] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:35:02.535346
2019-07-31 06:35:02,535 [salt.state       :1813][INFO    ][31041] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-07-31 06:35:02,536 [salt.state       :300 ][INFO    ][31041] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-07-31 06:35:02,536 [salt.state       :1951][INFO    ][31041] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:35:02.536529 duration_in_ms=1.182
2019-07-31 06:35:02,537 [salt.state       :1780][INFO    ][31041] Running state [mine.update] at time 06:35:02.537462
2019-07-31 06:35:02,537 [salt.state       :1813][INFO    ][31041] Executing state module.wait for [mine.update]
2019-07-31 06:35:02,538 [salt.state       :300 ][INFO    ][31041] No changes made for mine.update
2019-07-31 06:35:02,538 [salt.state       :1951][INFO    ][31041] Completed state [mine.update] at time 06:35:02.538565 duration_in_ms=1.103
2019-07-31 06:35:02,538 [salt.state       :1780][INFO    ][31041] Running state [ca-certificates] at time 06:35:02.538901
2019-07-31 06:35:02,539 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [ca-certificates]
2019-07-31 06:35:02,549 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,549 [salt.state       :1951][INFO    ][31041] Completed state [ca-certificates] at time 06:35:02.549599 duration_in_ms=10.699
2019-07-31 06:35:02,550 [salt.state       :1780][INFO    ][31041] Running state [update-ca-certificates] at time 06:35:02.550517
2019-07-31 06:35:02,550 [salt.state       :1813][INFO    ][31041] Executing state cmd.wait for [update-ca-certificates]
2019-07-31 06:35:02,551 [salt.state       :300 ][INFO    ][31041] No changes made for update-ca-certificates
2019-07-31 06:35:02,551 [salt.state       :1951][INFO    ][31041] Completed state [update-ca-certificates] at time 06:35:02.551568 duration_in_ms=1.052
2019-07-31 06:35:02,551 [salt.state       :1780][INFO    ][31041] Running state [iptables] at time 06:35:02.551876
2019-07-31 06:35:02,552 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [iptables]
2019-07-31 06:35:02,561 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,562 [salt.state       :1951][INFO    ][31041] Completed state [iptables] at time 06:35:02.562077 duration_in_ms=10.201
2019-07-31 06:35:02,562 [salt.state       :1780][INFO    ][31041] Running state [iptables-persistent] at time 06:35:02.562371
2019-07-31 06:35:02,562 [salt.state       :1813][INFO    ][31041] Executing state pkg.installed for [iptables-persistent]
2019-07-31 06:35:02,571 [salt.state       :300 ][INFO    ][31041] All specified packages are already installed
2019-07-31 06:35:02,571 [salt.state       :1951][INFO    ][31041] Completed state [iptables-persistent] at time 06:35:02.571511 duration_in_ms=9.14
2019-07-31 06:35:02,572 [salt.state       :1780][INFO    ][31041] Running state [iptables_modules_v4_load] at time 06:35:02.572725
2019-07-31 06:35:02,573 [salt.state       :1813][INFO    ][31041] Executing state kmod.present for [iptables_modules_v4_load]
2019-07-31 06:35:02,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'lsmod' in directory '/root'
2019-07-31 06:35:02,595 [salt.state       :300 ][INFO    ][31041] Kernel modules iptable_filter, ip_tables are already present
2019-07-31 06:35:02,596 [salt.state       :1951][INFO    ][31041] Completed state [iptables_modules_v4_load] at time 06:35:02.595950 duration_in_ms=23.225
2019-07-31 06:35:02,596 [salt.state       :1780][INFO    ][31041] Running state [/etc/iptables/rules.v4] at time 06:35:02.596712
2019-07-31 06:35:02,597 [salt.state       :1813][INFO    ][31041] Executing state file.managed for [/etc/iptables/rules.v4]
2019-07-31 06:35:02,697 [salt.state       :300 ][INFO    ][31041] File /etc/iptables/rules.v4 is in the correct state
2019-07-31 06:35:02,698 [salt.state       :1951][INFO    ][31041] Completed state [/etc/iptables/rules.v4] at time 06:35:02.697985 duration_in_ms=101.273
2019-07-31 06:35:02,699 [salt.state       :1780][INFO    ][31041] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:35:02.699034
2019-07-31 06:35:02,699 [salt.state       :1813][INFO    ][31041] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-07-31 06:35:02,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-07-31 06:35:02,719 [salt.state       :300 ][INFO    ][31041] onlyif execution failed
2019-07-31 06:35:02,719 [salt.state       :1951][INFO    ][31041] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:35:02.719673 duration_in_ms=20.637
2019-07-31 06:35:02,721 [salt.state       :1780][INFO    ][31041] Running state [netfilter-persistent] at time 06:35:02.721442
2019-07-31 06:35:02,722 [salt.state       :1813][INFO    ][31041] Executing state service.running for [netfilter-persistent]
2019-07-31 06:35:02,723 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:02,744 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-07-31 06:35:02,763 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-07-31 06:35:02,782 [salt.state       :300 ][INFO    ][31041] The service netfilter-persistent is already running
2019-07-31 06:35:02,782 [salt.state       :1951][INFO    ][31041] Completed state [netfilter-persistent] at time 06:35:02.782784 duration_in_ms=61.342
2019-07-31 06:35:02,784 [salt.state       :1780][INFO    ][31041] Running state [iptables_extra.remove_stale_tables] at time 06:35:02.784179
2019-07-31 06:35:02,784 [salt.state       :1813][INFO    ][31041] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-07-31 06:35:02,785 [salt.state       :300 ][INFO    ][31041] No changes made for iptables_extra.remove_stale_tables
2019-07-31 06:35:02,785 [salt.state       :1951][INFO    ][31041] Completed state [iptables_extra.remove_stale_tables] at time 06:35:02.785606 duration_in_ms=1.426
2019-07-31 06:35:02,786 [salt.state       :1780][INFO    ][31041] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:35:02.785994
2019-07-31 06:35:02,786 [salt.state       :1813][INFO    ][31041] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-07-31 06:35:02,787 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31041] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-07-31 06:35:02,803 [salt.state       :300 ][INFO    ][31041] onlyif execution failed
2019-07-31 06:35:02,804 [salt.state       :1951][INFO    ][31041] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:35:02.804067 duration_in_ms=18.073
2019-07-31 06:35:02,805 [salt.state       :1780][INFO    ][31041] Running state [/etc/iptables/rules.v6] at time 06:35:02.805627
2019-07-31 06:35:02,806 [salt.state       :1813][INFO    ][31041] Executing state file.absent for [/etc/iptables/rules.v6]
2019-07-31 06:35:02,806 [salt.state       :300 ][INFO    ][31041] File /etc/iptables/rules.v6 is not present
2019-07-31 06:35:02,807 [salt.state       :1951][INFO    ][31041] Completed state [/etc/iptables/rules.v6] at time 06:35:02.807236 duration_in_ms=1.609
2019-07-31 06:35:02,808 [salt.state       :1780][INFO    ][31041] Running state [iptables_extra.flush_all] at time 06:35:02.808358
2019-07-31 06:35:02,808 [salt.state       :1813][INFO    ][31041] Executing state module.wait for [iptables_extra.flush_all]
2019-07-31 06:35:02,809 [salt.state       :300 ][INFO    ][31041] No changes made for iptables_extra.flush_all
2019-07-31 06:35:02,809 [salt.state       :1951][INFO    ][31041] Completed state [iptables_extra.flush_all] at time 06:35:02.809644 duration_in_ms=1.286
2019-07-31 06:35:02,814 [salt.minion      :1711][INFO    ][31041] Returning information for job: 20190731063455021894
2019-07-31 06:35:03,430 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731063503418007
2019-07-31 06:35:03,452 [salt.minion      :1432][INFO    ][31125] Starting a new job with PID 31125
2019-07-31 06:35:04,197 [salt.state       :915 ][INFO    ][31125] Loading fresh modules for state activity
2019-07-31 06:35:04,808 [salt.state       :1780][INFO    ][31125] Running state [maas-rack-controller] at time 06:35:04.808044
2019-07-31 06:35:04,808 [salt.state       :1813][INFO    ][31125] Executing state pkg.installed for [maas-rack-controller]
2019-07-31 06:35:04,808 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31125] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-31 06:35:04,884 [salt.state       :300 ][INFO    ][31125] All specified packages are already installed
2019-07-31 06:35:04,884 [salt.state       :1951][INFO    ][31125] Completed state [maas-rack-controller] at time 06:35:04.884598 duration_in_ms=76.554
2019-07-31 06:35:04,884 [salt.state       :1780][INFO    ][31125] Running state [ipmitool] at time 06:35:04.884841
2019-07-31 06:35:04,885 [salt.state       :1813][INFO    ][31125] Executing state pkg.installed for [ipmitool]
2019-07-31 06:35:04,889 [salt.state       :300 ][INFO    ][31125] All specified packages are already installed
2019-07-31 06:35:04,889 [salt.state       :1951][INFO    ][31125] Completed state [ipmitool] at time 06:35:04.889927 duration_in_ms=5.085
2019-07-31 06:35:04,892 [salt.state       :1780][INFO    ][31125] Running state [/etc/maas/rackd.conf] at time 06:35:04.892190
2019-07-31 06:35:04,892 [salt.state       :1813][INFO    ][31125] Executing state file.line for [/etc/maas/rackd.conf]
2019-07-31 06:35:04,893 [salt.state       :300 ][INFO    ][31125] No changes needed to be made
2019-07-31 06:35:04,893 [salt.state       :1951][INFO    ][31125] Completed state [/etc/maas/rackd.conf] at time 06:35:04.893317 duration_in_ms=1.126
2019-07-31 06:35:04,893 [salt.state       :1780][INFO    ][31125] Running state [/etc/maas/rackd.conf] at time 06:35:04.893478
2019-07-31 06:35:04,893 [salt.state       :1813][INFO    ][31125] Executing state file.managed for [/etc/maas/rackd.conf]
2019-07-31 06:35:04,893 [salt.loaded.int.states.file:2298][WARNING ][31125] 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-07-31 06:35:04,894 [salt.state       :300 ][INFO    ][31125] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-07-31 06:35:04,894 [salt.state       :1951][INFO    ][31125] Completed state [/etc/maas/rackd.conf] at time 06:35:04.894363 duration_in_ms=0.885
2019-07-31 06:35:04,895 [salt.state       :1780][INFO    ][31125] Running state [maas-rackd] at time 06:35:04.895047
2019-07-31 06:35:04,895 [salt.state       :1813][INFO    ][31125] Executing state service.running for [maas-rackd]
2019-07-31 06:35:04,895 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31125] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:04,928 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31125] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-07-31 06:35:04,944 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31125] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-07-31 06:35:04,960 [salt.state       :300 ][INFO    ][31125] The service maas-rackd is already running
2019-07-31 06:35:04,960 [salt.state       :1951][INFO    ][31125] Completed state [maas-rackd] at time 06:35:04.960321 duration_in_ms=65.274
2019-07-31 06:35:04,961 [salt.minion      :1711][INFO    ][31125] Returning information for job: 20190731063503418007
2019-07-31 06:35:05,561 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731063505548675
2019-07-31 06:35:05,583 [salt.minion      :1432][INFO    ][31148] Starting a new job with PID 31148
2019-07-31 06:35:06,336 [salt.state       :915 ][INFO    ][31148] Loading fresh modules for state activity
2019-07-31 06:35:07,084 [salt.state       :1780][INFO    ][31148] Running state [maas-region-controller] at time 06:35:07.084104
2019-07-31 06:35:07,084 [salt.state       :1813][INFO    ][31148] Executing state pkg.installed for [maas-region-controller]
2019-07-31 06:35:07,085 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-31 06:35:07,159 [salt.state       :300 ][INFO    ][31148] All specified packages are already installed
2019-07-31 06:35:07,160 [salt.state       :1951][INFO    ][31148] Completed state [maas-region-controller] at time 06:35:07.159983 duration_in_ms=75.879
2019-07-31 06:35:07,160 [salt.state       :1780][INFO    ][31148] Running state [python-oauth] at time 06:35:07.160270
2019-07-31 06:35:07,160 [salt.state       :1813][INFO    ][31148] Executing state pkg.installed for [python-oauth]
2019-07-31 06:35:07,166 [salt.state       :300 ][INFO    ][31148] All specified packages are already installed
2019-07-31 06:35:07,166 [salt.state       :1951][INFO    ][31148] Completed state [python-oauth] at time 06:35:07.166513 duration_in_ms=6.242
2019-07-31 06:35:07,169 [salt.state       :1780][INFO    ][31148] Running state [/etc/maas/regiond.conf] at time 06:35:07.169261
2019-07-31 06:35:07,169 [salt.state       :1813][INFO    ][31148] Executing state file.replace for [/etc/maas/regiond.conf]
2019-07-31 06:35:07,220 [salt.state       :300 ][INFO    ][31148] No changes needed to be made
2019-07-31 06:35:07,220 [salt.state       :1951][INFO    ][31148] Completed state [/etc/maas/regiond.conf] at time 06:35:07.220769 duration_in_ms=51.507
2019-07-31 06:35:07,221 [salt.state       :1780][INFO    ][31148] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:35:07.221483
2019-07-31 06:35:07,221 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-07-31 06:35:07,310 [salt.state       :300 ][INFO    ][31148] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-07-31 06:35:07,311 [salt.state       :1951][INFO    ][31148] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:35:07.311589 duration_in_ms=90.105
2019-07-31 06:35:07,312 [salt.state       :1780][INFO    ][31148] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:35:07.312526
2019-07-31 06:35:07,313 [salt.state       :1813][INFO    ][31148] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-31 06:35:07,329 [salt.state       :300 ][INFO    ][31148] No changes needed to be made
2019-07-31 06:35:07,329 [salt.state       :1951][INFO    ][31148] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:35:07.329835 duration_in_ms=17.309
2019-07-31 06:35:07,330 [salt.state       :1780][INFO    ][31148] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:35:07.330432
2019-07-31 06:35:07,330 [salt.state       :1813][INFO    ][31148] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-31 06:35:07,389 [salt.state       :300 ][INFO    ][31148] No changes needed to be made
2019-07-31 06:35:07,390 [salt.state       :1951][INFO    ][31148] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:35:07.390193 duration_in_ms=59.76
2019-07-31 06:35:07,391 [salt.state       :1780][INFO    ][31148] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:35:07.391019
2019-07-31 06:35:07,391 [salt.state       :1813][INFO    ][31148] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-07-31 06:35:07,430 [salt.state       :300 ][INFO    ][31148] No changes needed to be made
2019-07-31 06:35:07,431 [salt.state       :1951][INFO    ][31148] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:35:07.431275 duration_in_ms=40.256
2019-07-31 06:35:07,431 [salt.state       :1780][INFO    ][31148] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:35:07.431930
2019-07-31 06:35:07,432 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-07-31 06:35:07,448 [salt.state       :300 ][INFO    ][31148] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-07-31 06:35:07,448 [salt.state       :1951][INFO    ][31148] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:35:07.448353 duration_in_ms=16.422
2019-07-31 06:35:07,452 [salt.state       :1780][INFO    ][31148] Running state [a2enmod headers] at time 06:35:07.452750
2019-07-31 06:35:07,453 [salt.state       :1813][INFO    ][31148] Executing state cmd.run for [a2enmod headers]
2019-07-31 06:35:07,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command 'a2enmod headers' in directory '/root'
2019-07-31 06:35:07,517 [salt.state       :300 ][INFO    ][31148] {'pid': 31167, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-07-31 06:35:07,517 [salt.state       :1951][INFO    ][31148] Completed state [a2enmod headers] at time 06:35:07.517763 duration_in_ms=65.012
2019-07-31 06:35:07,518 [salt.state       :1780][INFO    ][31148] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:35:07.518137
2019-07-31 06:35:07,518 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-07-31 06:35:07,533 [salt.state       :300 ][INFO    ][31148] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-07-31 06:35:07,533 [salt.state       :1951][INFO    ][31148] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:35:07.533665 duration_in_ms=15.528
2019-07-31 06:35:07,534 [salt.state       :1780][INFO    ][31148] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:35:07.534239
2019-07-31 06:35:07,534 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-07-31 06:35:07,602 [salt.state       :300 ][INFO    ][31148] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-07-31 06:35:07,603 [salt.state       :1951][INFO    ][31148] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:35:07.603132 duration_in_ms=68.892
2019-07-31 06:35:07,604 [salt.state       :1780][INFO    ][31148] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:35:07.603987
2019-07-31 06:35:07,604 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-07-31 06:35:07,681 [salt.state       :300 ][INFO    ][31148] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-07-31 06:35:07,681 [salt.state       :1951][INFO    ][31148] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:35:07.681318 duration_in_ms=77.33
2019-07-31 06:35:07,682 [salt.state       :1780][INFO    ][31148] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:35:07.682052
2019-07-31 06:35:07,682 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-07-31 06:35:07,806 [salt.state       :300 ][INFO    ][31148] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-07-31 06:35:07,807 [salt.state       :1951][INFO    ][31148] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:35:07.807214 duration_in_ms=125.16
2019-07-31 06:35:07,807 [salt.state       :1780][INFO    ][31148] Running state [/root/.pgpass] at time 06:35:07.807670
2019-07-31 06:35:07,808 [salt.state       :1813][INFO    ][31148] Executing state file.managed for [/root/.pgpass]
2019-07-31 06:35:07,866 [salt.state       :300 ][INFO    ][31148] File /root/.pgpass is in the correct state
2019-07-31 06:35:07,867 [salt.state       :1951][INFO    ][31148] Completed state [/root/.pgpass] at time 06:35:07.866961 duration_in_ms=59.291
2019-07-31 06:35:07,874 [salt.state       :1780][INFO    ][31148] Running state [maas-region syncdb --noinput] at time 06:35:07.874131
2019-07-31 06:35:07,874 [salt.state       :1813][INFO    ][31148] Executing state cmd.run for [maas-region syncdb --noinput]
2019-07-31 06:35:07,875 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-07-31 06:35:09,800 [salt.state       :300 ][INFO    ][31148] {'pid': 31180, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, piston3, auth, metadataserver, contenttypes, sites, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-07-31 06:35:09,800 [salt.state       :1951][INFO    ][31148] Completed state [maas-region syncdb --noinput] at time 06:35:09.800813 duration_in_ms=1926.682
2019-07-31 06:35:09,801 [salt.state       :2022][WARNING ][31148] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-31 06:35:09,804 [salt.state       :1780][INFO    ][31148] Running state [maas-regiond] at time 06:35:09.803992
2019-07-31 06:35:09,804 [salt.state       :1813][INFO    ][31148] Executing state service.running for [maas-regiond]
2019-07-31 06:35:09,806 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:09,842 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-07-31 06:35:09,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-07-31 06:35:09,875 [salt.state       :300 ][INFO    ][31148] The service maas-regiond is already running
2019-07-31 06:35:09,875 [salt.state       :1951][INFO    ][31148] Completed state [maas-regiond] at time 06:35:09.875885 duration_in_ms=71.893
2019-07-31 06:35:09,877 [salt.state       :1780][INFO    ][31148] Running state [bind9] at time 06:35:09.877903
2019-07-31 06:35:09,878 [salt.state       :1813][INFO    ][31148] Executing state service.running for [bind9]
2019-07-31 06:35:09,879 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:09,896 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-07-31 06:35:09,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-07-31 06:35:09,926 [salt.state       :300 ][INFO    ][31148] The service bind9 is already running
2019-07-31 06:35:09,927 [salt.state       :1951][INFO    ][31148] Completed state [bind9] at time 06:35:09.926941 duration_in_ms=49.038
2019-07-31 06:35:09,928 [salt.state       :1780][INFO    ][31148] Running state [apache2] at time 06:35:09.928746
2019-07-31 06:35:09,929 [salt.state       :1813][INFO    ][31148] Executing state service.running for [apache2]
2019-07-31 06:35:09,929 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-07-31 06:35:09,946 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-07-31 06:35:09,961 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-07-31 06:35:09,980 [salt.state       :300 ][INFO    ][31148] The service apache2 is already running
2019-07-31 06:35:09,981 [salt.state       :1951][INFO    ][31148] Completed state [apache2] at time 06:35:09.981109 duration_in_ms=52.362
2019-07-31 06:35:09,983 [salt.state       :1780][INFO    ][31148] Running state [maasng.wait_for_http_code] at time 06:35:09.983154
2019-07-31 06:35:09,983 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maasng.wait_for_http_code]
2019-07-31 06:35:09,984 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:35:10,108 [salt.state       :300 ][INFO    ][31148] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-07-31 06:35:10,109 [salt.state       :1951][INFO    ][31148] Completed state [maasng.wait_for_http_code] at time 06:35:10.109454 duration_in_ms=126.299
2019-07-31 06:35:10,111 [salt.state       :1780][INFO    ][31148] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:35:10.110941
2019-07-31 06:35:10,111 [salt.state       :1813][INFO    ][31148] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-07-31 06:35:10,112 [salt.state       :300 ][INFO    ][31148] /var/lib/maas/.setup_admin exists
2019-07-31 06:35:10,112 [salt.state       :1951][INFO    ][31148] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:35:10.112626 duration_in_ms=1.685
2019-07-31 06:35:10,113 [salt.state       :1780][INFO    ][31148] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:35:10.113824
2019-07-31 06:35:10,114 [salt.state       :1813][INFO    ][31148] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:35:10,115 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:35:11,632 [salt.state       :300 ][INFO    ][31148] {'pid': 31201, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:35:11,633 [salt.state       :1951][INFO    ][31148] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:35:11.633591 duration_in_ms=1519.766
2019-07-31 06:35:11,642 [salt.state       :1780][INFO    ][31148] Running state [maas_region_boot_source_resources_mirror] at time 06:35:11.642707
2019-07-31 06:35:11,643 [salt.state       :1813][INFO    ][31148] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-07-31 06:35:11,737 [salt.state       :300 ][INFO    ][31148] {'changes': {}}
2019-07-31 06:35:11,738 [salt.state       :1951][INFO    ][31148] Completed state [maas_region_boot_source_resources_mirror] at time 06:35:11.738160 duration_in_ms=95.454
2019-07-31 06:35:11,738 [salt.state       :1780][INFO    ][31148] Running state [maasng.boot_resources_import] at time 06:35:11.738777
2019-07-31 06:35:11,739 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maasng.boot_resources_import]
2019-07-31 06:35:11,739 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:35:11,834 [salt.loaded.ext.module.maasng:1600][INFO    ][31148] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-07-31 06:35:16,905 [salt.loaded.ext.module.maasng:1600][INFO    ][31148] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-07-31 06:35:20,618 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063520605142
2019-07-31 06:35:20,638 [salt.minion      :1432][INFO    ][31229] Starting a new job with PID 31229
2019-07-31 06:35:20,661 [salt.minion      :1711][INFO    ][31229] Returning information for job: 20190731063520605142
2019-07-31 06:35:21,963 [salt.loaded.ext.module.maasng:1600][INFO    ][31148] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-07-31 06:35:27,018 [salt.loaded.ext.module.maasng:1600][INFO    ][31148] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2019-07-31 06:35:50,706 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063550693321
2019-07-31 06:35:50,728 [salt.minion      :1432][INFO    ][31315] Starting a new job with PID 31315
2019-07-31 06:35:50,743 [salt.minion      :1711][INFO    ][31315] Returning information for job: 20190731063550693321
2019-07-31 06:36:21,997 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063620773422
2019-07-31 06:36:22,020 [salt.minion      :1432][INFO    ][31347] Starting a new job with PID 31347
2019-07-31 06:36:22,042 [salt.minion      :1711][INFO    ][31347] Returning information for job: 20190731063620773422
2019-07-31 06:36:52,075 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063652062441
2019-07-31 06:36:52,099 [salt.minion      :1432][INFO    ][31401] Starting a new job with PID 31401
2019-07-31 06:36:52,123 [salt.minion      :1711][INFO    ][31401] Returning information for job: 20190731063652062441
2019-07-31 06:37:22,140 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063722130781
2019-07-31 06:37:22,162 [salt.minion      :1432][INFO    ][31417] Starting a new job with PID 31417
2019-07-31 06:37:22,186 [salt.minion      :1711][INFO    ][31417] Returning information for job: 20190731063722130781
2019-07-31 06:37:52,212 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063752200933
2019-07-31 06:37:52,232 [salt.minion      :1432][INFO    ][31478] Starting a new job with PID 31478
2019-07-31 06:37:52,253 [salt.minion      :1711][INFO    ][31478] Returning information for job: 20190731063752200933
2019-07-31 06:38:22,282 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063822271386
2019-07-31 06:38:22,305 [salt.minion      :1432][INFO    ][31506] Starting a new job with PID 31506
2019-07-31 06:38:22,332 [salt.minion      :1711][INFO    ][31506] Returning information for job: 20190731063822271386
2019-07-31 06:38:52,366 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063852353891
2019-07-31 06:38:52,385 [salt.minion      :1432][INFO    ][31556] Starting a new job with PID 31556
2019-07-31 06:38:52,403 [salt.minion      :1711][INFO    ][31556] Returning information for job: 20190731063852353891
2019-07-31 06:39:22,442 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063922429810
2019-07-31 06:39:22,465 [salt.minion      :1432][INFO    ][31575] Starting a new job with PID 31575
2019-07-31 06:39:22,488 [salt.minion      :1711][INFO    ][31575] Returning information for job: 20190731063922429810
2019-07-31 06:39:52,528 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731063952515515
2019-07-31 06:39:52,548 [salt.minion      :1432][INFO    ][31628] Starting a new job with PID 31628
2019-07-31 06:39:52,574 [salt.minion      :1711][INFO    ][31628] Returning information for job: 20190731063952515515
2019-07-31 06:40:22,617 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064022608312
2019-07-31 06:40:22,638 [salt.minion      :1432][INFO    ][31643] Starting a new job with PID 31643
2019-07-31 06:40:22,656 [salt.minion      :1711][INFO    ][31643] Returning information for job: 20190731064022608312
2019-07-31 06:40:27,457 [salt.state       :300 ][INFO    ][31148] {'ret': True}
2019-07-31 06:40:27,458 [salt.state       :1951][INFO    ][31148] Completed state [maasng.boot_resources_import] at time 06:40:27.458002 duration_in_ms=315719.221
2019-07-31 06:40:27,460 [salt.state       :1780][INFO    ][31148] Running state [maas_region_boot_sources_selection_xenial] at time 06:40:27.460065
2019-07-31 06:40:27,460 [salt.state       :1813][INFO    ][31148] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-07-31 06:40:28,766 [salt.state       :300 ][INFO    ][31148] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-07-31 06:40:28,767 [salt.state       :1951][INFO    ][31148] Completed state [maas_region_boot_sources_selection_xenial] at time 06:40:28.767390 duration_in_ms=1307.325
2019-07-31 06:40:28,768 [salt.state       :1780][INFO    ][31148] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:40:28.768665
2019-07-31 06:40:28,769 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-07-31 06:40:28,769 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:40:28,770 [salt.loaded.ext.module.maasng:1771][INFO    ][31148] boot-sources sync initiated for ALL Rack's
2019-07-31 06:40:30,511 [salt.loaded.ext.module.maasng:1878][INFO    ][31148] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:899.0/900s
2019-07-31 06:40:36,811 [salt.loaded.ext.module.maasng:1878][INFO    ][31148] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:892.0/900s
2019-07-31 06:40:42,712 [salt.state       :300 ][INFO    ][31148] {'ret': True}
2019-07-31 06:40:42,712 [salt.state       :1951][INFO    ][31148] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:40:42.712683 duration_in_ms=13944.016
2019-07-31 06:40:42,714 [salt.state       :1780][INFO    ][31148] Running state [maas.process_maas_config] at time 06:40:42.714833
2019-07-31 06:40:42,715 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maas.process_maas_config]
2019-07-31 06:40:42,716 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:40:42,716 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=enable_http_proxy value=True
2019-07-31 06:40:42,779 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=upstream_dns value=8.8.8.8
2019-07-31 06:40:42,844 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=commissioning_distro_series value=xenial
2019-07-31 06:40:42,916 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=default_osystem value=ubuntu
2019-07-31 06:40:42,975 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=active_discovery_interval value=600
2019-07-31 06:40:46,170 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=dnssec_validation value=no
2019-07-31 06:40:46,245 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=maas_name value=mas01
2019-07-31 06:40:46,545 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=network_discovery value=enabled
2019-07-31 06:40:46,674 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=enable_third_party_drivers value=True
2019-07-31 06:40:46,734 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=default_storage_layout value=lvm
2019-07-31 06:40:46,800 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=ntp_external_only value=True
2019-07-31 06:40:46,865 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=disk_erase_with_secure_erase value=False
2019-07-31 06:40:46,924 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=default_distro_series value=xenial
2019-07-31 06:40:46,982 [salt.loaded.ext.module.maas:160 ][ERROR   ][31148] Failed for object default_distro_series reason {"default_distro_series": ["'xenial' is not a valid release.  It should be one of: '---'."]}
2019-07-31 06:40:46,983 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-07-31 06:40:47,084 [salt.state       :302 ][ERROR   ][31148] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'default_distro_series': '{"default_distro_series": ["\'xenial\' is not a valid release.  It should be one of: \'---\'."]}'}, '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_min_hwe_kernel']}
2019-07-31 06:40:47,085 [salt.state       :1951][INFO    ][31148] Completed state [maas.process_maas_config] at time 06:40:47.085060 duration_in_ms=4370.226
2019-07-31 06:40:47,086 [salt.state       :1780][INFO    ][31148] Running state [pxe_admin] at time 06:40:47.086013
2019-07-31 06:40:47,086 [salt.state       :1813][INFO    ][31148] Executing state maasng.fabric_present for [pxe_admin]
2019-07-31 06:40:47,150 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:40:47,222 [salt.loaded.ext.module.maasng:1008][WARNING ][31148] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-07-31 06:40:47,222 [salt.loaded.ext.module.maasng:1011][WARNING ][31148] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-07-31 06:40:47,303 [salt.state       :300 ][INFO    ][31148] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-07-31 06:40:47,303 [salt.state       :1951][INFO    ][31148] Completed state [pxe_admin] at time 06:40:47.303663 duration_in_ms=217.65
2019-07-31 06:40:47,304 [salt.state       :1780][INFO    ][31148] Running state [vlan 0] at time 06:40:47.304149
2019-07-31 06:40:47,304 [salt.state       :1813][INFO    ][31148] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-31 06:40:47,362 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:40:47,482 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u't4xamg', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-07-31 06:40:47,821 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:40:47,923 [salt.state       :300 ][INFO    ][31148] {'new': 'Vlan untagged was updated'}
2019-07-31 06:40:47,924 [salt.state       :1951][INFO    ][31148] Completed state [vlan 0] at time 06:40:47.923989 duration_in_ms=619.84
2019-07-31 06:40:47,925 [salt.state       :1780][INFO    ][31148] Running state [192.168.11.0/24] at time 06:40:47.925285
2019-07-31 06:40:47,925 [salt.state       :1813][INFO    ][31148] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-07-31 06:40:48,138 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:40:48,139 [salt.loaded.ext.module.maasng:1235][WARNING ][31148] Ignoring parameter vlan:0
2019-07-31 06:40:48,237 [salt.state       :300 ][INFO    ][31148] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-07-31 06:40:48,238 [salt.state       :1951][INFO    ][31148] Completed state [192.168.11.0/24] at time 06:40:48.238050 duration_in_ms=312.763
2019-07-31 06:40:48,239 [salt.state       :1780][INFO    ][31148] Running state [maas_create_iprange_1] at time 06:40:48.239260
2019-07-31 06:40:48,239 [salt.state       :1813][INFO    ][31148] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-07-31 06:40:48,319 [salt.state       :300 ][INFO    ][31148] Iprange maas_create_iprange_1 already exist.
2019-07-31 06:40:48,319 [salt.state       :1951][INFO    ][31148] Completed state [maas_create_iprange_1] at time 06:40:48.319527 duration_in_ms=80.267
2019-07-31 06:40:48,320 [salt.state       :1780][INFO    ][31148] Running state [vlan 0] at time 06:40:48.319983
2019-07-31 06:40:48,320 [salt.state       :1813][INFO    ][31148] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-31 06:40:48,386 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:40:48,512 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:40:49,052 [salt.loaded.ext.module.maasng:945 ][INFO    ][31148] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:40:49,541 [salt.state       :300 ][INFO    ][31148] {'new': 'Vlan untagged was updated'}
2019-07-31 06:40:49,541 [salt.state       :1951][INFO    ][31148] Completed state [vlan 0] at time 06:40:49.541468 duration_in_ms=1221.485
2019-07-31 06:40:49,542 [salt.state       :1780][INFO    ][31148] Running state [opnfv] at time 06:40:49.542172
2019-07-31 06:40:49,542 [salt.state       :1813][INFO    ][31148] Executing state maasng.sshkey_present for [opnfv]
2019-07-31 06:40:49,681 [salt.loaded.ext.module.maasng:1903][INFO    ][31148] [{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-07-31 06:40:49,682 [salt.state       :300 ][INFO    ][31148] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-07-31 06:40:49,682 [salt.state       :1951][INFO    ][31148] Completed state [opnfv] at time 06:40:49.682422 duration_in_ms=140.249
2019-07-31 06:40:49,683 [salt.state       :1780][INFO    ][31148] Running state [maas.process_tags] at time 06:40:49.683339
2019-07-31 06:40:49,683 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maas.process_tags]
2019-07-31 06:40:49,684 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:40:49,801 [salt.loaded.ext.module.maas:92  ][INFO    ][31148] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-07-31 06:40:49,866 [salt.state       :300 ][INFO    ][31148] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-07-31 06:40:49,867 [salt.state       :1951][INFO    ][31148] Completed state [maas.process_tags] at time 06:40:49.867104 duration_in_ms=183.763
2019-07-31 06:40:49,872 [salt.minion      :1711][INFO    ][31148] Returning information for job: 20190731063505548675
2019-07-31 06:41:00,562 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731064100548803
2019-07-31 06:41:00,584 [salt.minion      :1432][INFO    ][31818] Starting a new job with PID 31818
2019-07-31 06:41:04,075 [salt.state       :915 ][INFO    ][31818] Loading fresh modules for state activity
2019-07-31 06:41:04,747 [salt.state       :1780][INFO    ][31818] Running state [maas-region-controller] at time 06:41:04.747394
2019-07-31 06:41:04,747 [salt.state       :1813][INFO    ][31818] Executing state pkg.installed for [maas-region-controller]
2019-07-31 06:41:04,748 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-31 06:41:04,845 [salt.state       :300 ][INFO    ][31818] All specified packages are already installed
2019-07-31 06:41:04,846 [salt.state       :1951][INFO    ][31818] Completed state [maas-region-controller] at time 06:41:04.846180 duration_in_ms=98.785
2019-07-31 06:41:04,846 [salt.state       :1780][INFO    ][31818] Running state [python-oauth] at time 06:41:04.846592
2019-07-31 06:41:04,846 [salt.state       :1813][INFO    ][31818] Executing state pkg.installed for [python-oauth]
2019-07-31 06:41:04,853 [salt.state       :300 ][INFO    ][31818] All specified packages are already installed
2019-07-31 06:41:04,853 [salt.state       :1951][INFO    ][31818] Completed state [python-oauth] at time 06:41:04.853904 duration_in_ms=7.312
2019-07-31 06:41:04,857 [salt.state       :1780][INFO    ][31818] Running state [/etc/maas/regiond.conf] at time 06:41:04.857445
2019-07-31 06:41:04,857 [salt.state       :1813][INFO    ][31818] Executing state file.replace for [/etc/maas/regiond.conf]
2019-07-31 06:41:04,886 [salt.state       :300 ][INFO    ][31818] No changes needed to be made
2019-07-31 06:41:04,886 [salt.state       :1951][INFO    ][31818] Completed state [/etc/maas/regiond.conf] at time 06:41:04.886561 duration_in_ms=29.116
2019-07-31 06:41:04,887 [salt.state       :1780][INFO    ][31818] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:41:04.887010
2019-07-31 06:41:04,887 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-07-31 06:41:04,945 [salt.state       :300 ][INFO    ][31818] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-07-31 06:41:04,946 [salt.state       :1951][INFO    ][31818] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:41:04.946047 duration_in_ms=59.037
2019-07-31 06:41:04,946 [salt.state       :1780][INFO    ][31818] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:41:04.946682
2019-07-31 06:41:04,946 [salt.state       :1813][INFO    ][31818] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-31 06:41:04,958 [salt.state       :300 ][INFO    ][31818] No changes needed to be made
2019-07-31 06:41:04,959 [salt.state       :1951][INFO    ][31818] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:41:04.959001 duration_in_ms=12.319
2019-07-31 06:41:04,959 [salt.state       :1780][INFO    ][31818] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:41:04.959398
2019-07-31 06:41:04,959 [salt.state       :1813][INFO    ][31818] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-31 06:41:04,982 [salt.state       :300 ][INFO    ][31818] No changes needed to be made
2019-07-31 06:41:04,982 [salt.state       :1951][INFO    ][31818] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:41:04.982892 duration_in_ms=23.494
2019-07-31 06:41:04,983 [salt.state       :1780][INFO    ][31818] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:41:04.983299
2019-07-31 06:41:04,983 [salt.state       :1813][INFO    ][31818] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-07-31 06:41:05,003 [salt.state       :300 ][INFO    ][31818] No changes needed to be made
2019-07-31 06:41:05,003 [salt.state       :1951][INFO    ][31818] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:41:05.003616 duration_in_ms=20.317
2019-07-31 06:41:05,004 [salt.state       :1780][INFO    ][31818] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:41:05.004019
2019-07-31 06:41:05,004 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-07-31 06:41:05,014 [salt.state       :300 ][INFO    ][31818] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-07-31 06:41:05,014 [salt.state       :1951][INFO    ][31818] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:41:05.014751 duration_in_ms=10.732
2019-07-31 06:41:05,015 [salt.state       :1780][INFO    ][31818] Running state [a2enmod headers] at time 06:41:05.015772
2019-07-31 06:41:05,016 [salt.state       :1813][INFO    ][31818] Executing state cmd.run for [a2enmod headers]
2019-07-31 06:41:05,016 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command 'a2enmod headers' in directory '/root'
2019-07-31 06:41:05,090 [salt.state       :300 ][INFO    ][31818] {'pid': 31839, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-07-31 06:41:05,090 [salt.state       :1951][INFO    ][31818] Completed state [a2enmod headers] at time 06:41:05.090477 duration_in_ms=74.705
2019-07-31 06:41:05,090 [salt.state       :1780][INFO    ][31818] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:41:05.090830
2019-07-31 06:41:05,091 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-07-31 06:41:05,105 [salt.state       :300 ][INFO    ][31818] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-07-31 06:41:05,105 [salt.state       :1951][INFO    ][31818] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:41:05.105335 duration_in_ms=14.505
2019-07-31 06:41:05,105 [salt.state       :1780][INFO    ][31818] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:41:05.105783
2019-07-31 06:41:05,106 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-07-31 06:41:05,167 [salt.state       :300 ][INFO    ][31818] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-07-31 06:41:05,168 [salt.state       :1951][INFO    ][31818] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:41:05.167914 duration_in_ms=62.13
2019-07-31 06:41:05,170 [salt.state       :1780][INFO    ][31818] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:41:05.170307
2019-07-31 06:41:05,171 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-07-31 06:41:05,233 [salt.state       :300 ][INFO    ][31818] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-07-31 06:41:05,233 [salt.state       :1951][INFO    ][31818] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:41:05.233418 duration_in_ms=63.118
2019-07-31 06:41:05,233 [salt.state       :1780][INFO    ][31818] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:41:05.233902
2019-07-31 06:41:05,234 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-07-31 06:41:05,286 [salt.state       :300 ][INFO    ][31818] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-07-31 06:41:05,287 [salt.state       :1951][INFO    ][31818] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:41:05.287155 duration_in_ms=53.253
2019-07-31 06:41:05,287 [salt.state       :1780][INFO    ][31818] Running state [/root/.pgpass] at time 06:41:05.287379
2019-07-31 06:41:05,287 [salt.state       :1813][INFO    ][31818] Executing state file.managed for [/root/.pgpass]
2019-07-31 06:41:05,329 [salt.state       :300 ][INFO    ][31818] File /root/.pgpass is in the correct state
2019-07-31 06:41:05,329 [salt.state       :1951][INFO    ][31818] Completed state [/root/.pgpass] at time 06:41:05.329275 duration_in_ms=41.896
2019-07-31 06:41:05,333 [salt.state       :1780][INFO    ][31818] Running state [maas-region syncdb --noinput] at time 06:41:05.333082
2019-07-31 06:41:05,333 [salt.state       :1813][INFO    ][31818] Executing state cmd.run for [maas-region syncdb --noinput]
2019-07-31 06:41:05,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-07-31 06:41:07,393 [salt.state       :300 ][INFO    ][31818] {'pid': 31852, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, auth, contenttypes, maasserver, metadataserver, sites, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-07-31 06:41:07,394 [salt.state       :1951][INFO    ][31818] Completed state [maas-region syncdb --noinput] at time 06:41:07.394083 duration_in_ms=2060.999
2019-07-31 06:41:07,394 [salt.state       :2022][WARNING ][31818] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-31 06:41:07,397 [salt.state       :1780][INFO    ][31818] Running state [maas-regiond] at time 06:41:07.397442
2019-07-31 06:41:07,398 [salt.state       :1813][INFO    ][31818] Executing state service.running for [maas-regiond]
2019-07-31 06:41:07,399 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-07-31 06:41:07,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-07-31 06:41:07,457 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-07-31 06:41:07,473 [salt.state       :300 ][INFO    ][31818] The service maas-regiond is already running
2019-07-31 06:41:07,473 [salt.state       :1951][INFO    ][31818] Completed state [maas-regiond] at time 06:41:07.473834 duration_in_ms=76.392
2019-07-31 06:41:07,475 [salt.state       :1780][INFO    ][31818] Running state [bind9] at time 06:41:07.475671
2019-07-31 06:41:07,476 [salt.state       :1813][INFO    ][31818] Executing state service.running for [bind9]
2019-07-31 06:41:07,476 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-07-31 06:41:07,494 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-07-31 06:41:07,510 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-07-31 06:41:07,526 [salt.state       :300 ][INFO    ][31818] The service bind9 is already running
2019-07-31 06:41:07,526 [salt.state       :1951][INFO    ][31818] Completed state [bind9] at time 06:41:07.526609 duration_in_ms=50.938
2019-07-31 06:41:07,528 [salt.state       :1780][INFO    ][31818] Running state [apache2] at time 06:41:07.528325
2019-07-31 06:41:07,528 [salt.state       :1813][INFO    ][31818] Executing state service.running for [apache2]
2019-07-31 06:41:07,529 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-07-31 06:41:07,546 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-07-31 06:41:07,561 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-07-31 06:41:07,581 [salt.state       :300 ][INFO    ][31818] The service apache2 is already running
2019-07-31 06:41:07,581 [salt.state       :1951][INFO    ][31818] Completed state [apache2] at time 06:41:07.581634 duration_in_ms=53.308
2019-07-31 06:41:07,583 [salt.state       :1780][INFO    ][31818] Running state [maasng.wait_for_http_code] at time 06:41:07.582992
2019-07-31 06:41:07,583 [salt.state       :1813][INFO    ][31818] Executing state module.run for [maasng.wait_for_http_code]
2019-07-31 06:41:07,583 [salt.utils.decorators:613 ][WARNING ][31818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:07,590 [salt.state       :300 ][INFO    ][31818] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-07-31 06:41:07,590 [salt.state       :1951][INFO    ][31818] Completed state [maasng.wait_for_http_code] at time 06:41:07.590854 duration_in_ms=7.862
2019-07-31 06:41:07,591 [salt.state       :1780][INFO    ][31818] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:41:07.591555
2019-07-31 06:41:07,591 [salt.state       :1813][INFO    ][31818] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-07-31 06:41:07,592 [salt.state       :300 ][INFO    ][31818] /var/lib/maas/.setup_admin exists
2019-07-31 06:41:07,592 [salt.state       :1951][INFO    ][31818] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:41:07.592464 duration_in_ms=0.909
2019-07-31 06:41:07,593 [salt.state       :1780][INFO    ][31818] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:41:07.593105
2019-07-31 06:41:07,593 [salt.state       :1813][INFO    ][31818] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:41:07,593 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31818] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:41:09,118 [salt.state       :300 ][INFO    ][31818] {'pid': 31871, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:41:09,119 [salt.state       :1951][INFO    ][31818] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:41:09.119421 duration_in_ms=1526.314
2019-07-31 06:41:09,127 [salt.state       :1780][INFO    ][31818] Running state [maas_region_boot_source_resources_mirror] at time 06:41:09.127850
2019-07-31 06:41:09,128 [salt.state       :1813][INFO    ][31818] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-07-31 06:41:09,230 [salt.state       :300 ][INFO    ][31818] {'changes': {}}
2019-07-31 06:41:09,230 [salt.state       :1951][INFO    ][31818] Completed state [maas_region_boot_source_resources_mirror] at time 06:41:09.230531 duration_in_ms=102.679
2019-07-31 06:41:09,231 [salt.state       :1780][INFO    ][31818] Running state [maasng.boot_resources_import] at time 06:41:09.231752
2019-07-31 06:41:09,232 [salt.state       :1813][INFO    ][31818] Executing state module.run for [maasng.boot_resources_import]
2019-07-31 06:41:09,232 [salt.utils.decorators:613 ][WARNING ][31818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:09,332 [salt.loaded.ext.module.maasng:1600][INFO    ][31818] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-07-31 06:41:14,390 [salt.loaded.ext.module.maasng:1600][INFO    ][31818] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-07-31 06:41:15,579 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064115566962
2019-07-31 06:41:15,602 [salt.minion      :1432][INFO    ][31895] Starting a new job with PID 31895
2019-07-31 06:41:15,629 [salt.minion      :1711][INFO    ][31895] Returning information for job: 20190731064115566962
2019-07-31 06:41:19,450 [salt.loaded.ext.module.maasng:1600][INFO    ][31818] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-07-31 06:41:24,564 [salt.state       :300 ][INFO    ][31818] {'ret': True}
2019-07-31 06:41:24,564 [salt.state       :1951][INFO    ][31818] Completed state [maasng.boot_resources_import] at time 06:41:24.564838 duration_in_ms=15333.085
2019-07-31 06:41:24,566 [salt.state       :1780][INFO    ][31818] Running state [maas_region_boot_sources_selection_xenial] at time 06:41:24.566078
2019-07-31 06:41:24,566 [salt.state       :1813][INFO    ][31818] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-07-31 06:41:24,773 [salt.state       :300 ][INFO    ][31818] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-07-31 06:41:24,773 [salt.state       :1951][INFO    ][31818] Completed state [maas_region_boot_sources_selection_xenial] at time 06:41:24.773880 duration_in_ms=207.801
2019-07-31 06:41:24,775 [salt.state       :1780][INFO    ][31818] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:41:24.775201
2019-07-31 06:41:24,775 [salt.state       :1813][INFO    ][31818] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-07-31 06:41:24,776 [salt.utils.decorators:613 ][WARNING ][31818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:24,776 [salt.loaded.ext.module.maasng:1771][INFO    ][31818] boot-sources sync initiated for ALL Rack's
2019-07-31 06:41:25,851 [salt.state       :300 ][INFO    ][31818] {'ret': True}
2019-07-31 06:41:25,851 [salt.state       :1951][INFO    ][31818] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:41:25.851641 duration_in_ms=1076.44
2019-07-31 06:41:25,853 [salt.state       :1780][INFO    ][31818] Running state [maas.process_maas_config] at time 06:41:25.853212
2019-07-31 06:41:25,853 [salt.state       :1813][INFO    ][31818] Executing state module.run for [maas.process_maas_config]
2019-07-31 06:41:25,854 [salt.utils.decorators:613 ][WARNING ][31818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:25,854 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=enable_http_proxy value=True
2019-07-31 06:41:25,912 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=upstream_dns value=8.8.8.8
2019-07-31 06:41:25,977 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=commissioning_distro_series value=xenial
2019-07-31 06:41:26,036 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=default_osystem value=ubuntu
2019-07-31 06:41:29,299 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=active_discovery_interval value=600
2019-07-31 06:41:29,354 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=dnssec_validation value=no
2019-07-31 06:41:29,424 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=maas_name value=mas01
2019-07-31 06:41:29,477 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=network_discovery value=enabled
2019-07-31 06:41:29,584 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=enable_third_party_drivers value=True
2019-07-31 06:41:29,632 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=default_storage_layout value=lvm
2019-07-31 06:41:29,687 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=ntp_external_only value=True
2019-07-31 06:41:29,733 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=disk_erase_with_secure_erase value=False
2019-07-31 06:41:29,791 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=default_distro_series value=xenial
2019-07-31 06:41:29,864 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-07-31 06:41:29,997 [salt.state       :300 ][INFO    ][31818] {'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-07-31 06:41:29,997 [salt.state       :1951][INFO    ][31818] Completed state [maas.process_maas_config] at time 06:41:29.997455 duration_in_ms=4144.242
2019-07-31 06:41:29,998 [salt.state       :1780][INFO    ][31818] Running state [pxe_admin] at time 06:41:29.998081
2019-07-31 06:41:29,998 [salt.state       :1813][INFO    ][31818] Executing state maasng.fabric_present for [pxe_admin]
2019-07-31 06:41:30,048 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:41:30,120 [salt.loaded.ext.module.maasng:1008][WARNING ][31818] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-07-31 06:41:30,121 [salt.loaded.ext.module.maasng:1011][WARNING ][31818] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-07-31 06:41:30,187 [salt.state       :300 ][INFO    ][31818] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-07-31 06:41:30,187 [salt.state       :1951][INFO    ][31818] Completed state [pxe_admin] at time 06:41:30.187787 duration_in_ms=189.705
2019-07-31 06:41:30,188 [salt.state       :1780][INFO    ][31818] Running state [vlan 0] at time 06:41:30.188208
2019-07-31 06:41:30,188 [salt.state       :1813][INFO    ][31818] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-31 06:41:30,243 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:41:30,393 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u't4xamg', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-07-31 06:41:30,690 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u't4xamg', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-07-31 06:41:30,789 [salt.state       :300 ][INFO    ][31818] {'new': 'Vlan untagged was updated'}
2019-07-31 06:41:30,790 [salt.state       :1951][INFO    ][31818] Completed state [vlan 0] at time 06:41:30.790003 duration_in_ms=601.795
2019-07-31 06:41:30,791 [salt.state       :1780][INFO    ][31818] Running state [192.168.11.0/24] at time 06:41:30.791049
2019-07-31 06:41:30,791 [salt.state       :1813][INFO    ][31818] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-07-31 06:41:30,977 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:41:30,978 [salt.loaded.ext.module.maasng:1235][WARNING ][31818] Ignoring parameter vlan:0
2019-07-31 06:41:31,056 [salt.state       :300 ][INFO    ][31818] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-07-31 06:41:31,056 [salt.state       :1951][INFO    ][31818] Completed state [192.168.11.0/24] at time 06:41:31.056268 duration_in_ms=265.22
2019-07-31 06:41:31,057 [salt.state       :1780][INFO    ][31818] Running state [maas_create_iprange_1] at time 06:41:31.057020
2019-07-31 06:41:31,057 [salt.state       :1813][INFO    ][31818] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-07-31 06:41:31,109 [salt.state       :300 ][INFO    ][31818] Iprange maas_create_iprange_1 already exist.
2019-07-31 06:41:31,110 [salt.state       :1951][INFO    ][31818] Completed state [maas_create_iprange_1] at time 06:41:31.110031 duration_in_ms=53.012
2019-07-31 06:41:31,110 [salt.state       :1780][INFO    ][31818] Running state [vlan 0] at time 06:41:31.110238
2019-07-31 06:41:31,110 [salt.state       :1813][INFO    ][31818] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-31 06:41:31,163 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u't4xamg', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-07-31 06:41:31,241 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u't4xamg', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-07-31 06:41:31,489 [salt.loaded.ext.module.maasng:945 ][INFO    ][31818] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u't4xamg', 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'class_type': u'', u'name': u'pxe_admin'}]
2019-07-31 06:41:31,573 [salt.state       :300 ][INFO    ][31818] {'new': 'Vlan untagged was updated'}
2019-07-31 06:41:31,574 [salt.state       :1951][INFO    ][31818] Completed state [vlan 0] at time 06:41:31.573985 duration_in_ms=463.745
2019-07-31 06:41:31,575 [salt.state       :1780][INFO    ][31818] Running state [opnfv] at time 06:41:31.574966
2019-07-31 06:41:31,575 [salt.state       :1813][INFO    ][31818] Executing state maasng.sshkey_present for [opnfv]
2019-07-31 06:41:31,626 [salt.loaded.ext.module.maasng:1903][INFO    ][31818] [{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-07-31 06:41:31,627 [salt.state       :300 ][INFO    ][31818] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-07-31 06:41:31,627 [salt.state       :1951][INFO    ][31818] Completed state [opnfv] at time 06:41:31.627797 duration_in_ms=52.831
2019-07-31 06:41:31,628 [salt.state       :1780][INFO    ][31818] Running state [maas.process_tags] at time 06:41:31.628607
2019-07-31 06:41:31,629 [salt.state       :1813][INFO    ][31818] Executing state module.run for [maas.process_tags]
2019-07-31 06:41:31,629 [salt.utils.decorators:613 ][WARNING ][31818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:31,703 [salt.loaded.ext.module.maas:92  ][INFO    ][31818] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-07-31 06:41:31,771 [salt.state       :300 ][INFO    ][31818] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-07-31 06:41:31,772 [salt.state       :1951][INFO    ][31818] Completed state [maas.process_tags] at time 06:41:31.772071 duration_in_ms=143.462
2019-07-31 06:41:31,775 [salt.minion      :1711][INFO    ][31818] Returning information for job: 20190731064100548803
2019-07-31 06:41:32,295 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731064132286278
2019-07-31 06:41:32,311 [salt.minion      :1432][INFO    ][32314] Starting a new job with PID 32314
2019-07-31 06:41:35,911 [salt.state       :915 ][INFO    ][32314] Loading fresh modules for state activity
2019-07-31 06:41:36,004 [salt.state       :1780][INFO    ][32314] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:41:36.004474
2019-07-31 06:41:36,004 [salt.state       :1813][INFO    ][32314] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:41:36,007 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32314] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:41:37,477 [salt.state       :300 ][INFO    ][32314] {'pid': 32361, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:41:37,478 [salt.state       :1951][INFO    ][32314] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:41:37.477996 duration_in_ms=1473.521
2019-07-31 06:41:37,480 [salt.state       :1780][INFO    ][32314] Running state [maas.process_machines] at time 06:41:37.480531
2019-07-31 06:41:37,481 [salt.state       :1813][INFO    ][32314] Executing state module.run for [maas.process_machines]
2019-07-31 06:41:37,482 [salt.utils.decorators:613 ][WARNING ][32314] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:41:38,149 [salt.loaded.ext.module.maas:412 ][WARNING ][32314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:41:38,150 [salt.loaded.ext.module.maas:92  ][INFO    ][32314] 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=4mca4c architecture=amd64/generic power_parameters_power_user=admin
2019-07-31 06:41:39,437 [salt.loaded.ext.module.maas:412 ][WARNING ][32314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:41:39,437 [salt.loaded.ext.module.maas:92  ][INFO    ][32314] 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=ynackt architecture=amd64/generic power_parameters_power_user=admin
2019-07-31 06:41:40,611 [salt.loaded.ext.module.maas:412 ][WARNING ][32314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:41:40,612 [salt.loaded.ext.module.maas:92  ][INFO    ][32314] 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=4bnsan architecture=amd64/generic power_parameters_power_user=admin
2019-07-31 06:41:41,890 [salt.loaded.ext.module.maas:412 ][WARNING ][32314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:41:41,891 [salt.loaded.ext.module.maas:92  ][INFO    ][32314] 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=kq4fqa architecture=amd64/generic power_parameters_power_user=admin
2019-07-31 06:41:43,216 [salt.loaded.ext.module.maas:412 ][WARNING ][32314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-31 06:41:43,217 [salt.loaded.ext.module.maas:92  ][INFO    ][32314] 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=8xer3x architecture=amd64/generic power_parameters_power_user=admin
2019-07-31 06:41:44,240 [salt.state       :300 ][INFO    ][32314] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-07-31 06:41:44,240 [salt.state       :1951][INFO    ][32314] Completed state [maas.process_machines] at time 06:41:44.240707 duration_in_ms=6760.175
2019-07-31 06:41:44,243 [salt.minion      :1711][INFO    ][32314] Returning information for job: 20190731064132286278
2019-07-31 06:42:17,419 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731064217405987
2019-07-31 06:42:17,438 [salt.minion      :1432][INFO    ][32587] Starting a new job with PID 32587
2019-07-31 06:42:21,087 [salt.state       :915 ][INFO    ][32587] Loading fresh modules for state activity
2019-07-31 06:42:21,163 [salt.state       :1780][INFO    ][32587] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:42:21.163259
2019-07-31 06:42:21,163 [salt.state       :1813][INFO    ][32587] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:42:21,165 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32587] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:42:22,627 [salt.state       :300 ][INFO    ][32587] {'pid': 32595, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:42:22,627 [salt.state       :1951][INFO    ][32587] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:42:22.627429 duration_in_ms=1464.171
2019-07-31 06:42:22,629 [salt.state       :1780][INFO    ][32587] Running state [maas.wait_for_machine_status] at time 06:42:22.628978
2019-07-31 06:42:22,629 [salt.state       :1813][INFO    ][32587] Executing state module.run for [maas.wait_for_machine_status]
2019-07-31 06:42:22,629 [salt.utils.decorators:613 ][WARNING ][32587] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:42:26,060 [salt.loaded.ext.module.maas:993 ][INFO    ][32587] Machine 8xer3x mark broken
2019-07-31 06:42:26,685 [salt.loaded.ext.module.maas:996 ][INFO    ][32587] Machine 8xer3x mark fixed
2019-07-31 06:42:27,864 [salt.loaded.ext.module.maas:684 ][INFO    ][32587] deploymachines hwe_kernel=hwe-16.04 system_id=8xer3x distro_series=xenial
2019-07-31 06:42:30,649 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1491.98679399s left)
2019-07-31 06:42:32,489 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064232480039
2019-07-31 06:42:32,512 [salt.minion      :1432][INFO    ][32706] Starting a new job with PID 32706
2019-07-31 06:42:32,538 [salt.minion      :1711][INFO    ][32706] Returning information for job: 20190731064232480039
2019-07-31 06:43:02,528 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064302520141
2019-07-31 06:43:02,547 [salt.minion      :1432][INFO    ][32730] Starting a new job with PID 32730
2019-07-31 06:43:02,573 [salt.minion      :1711][INFO    ][32730] Returning information for job: 20190731064302520141
2019-07-31 06:43:03,813 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1458.82257795s left)
2019-07-31 06:43:32,757 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064332706026
2019-07-31 06:43:32,779 [salt.minion      :1432][INFO    ][331] Starting a new job with PID 331
2019-07-31 06:43:32,802 [salt.minion      :1711][INFO    ][331] Returning information for job: 20190731064332706026
2019-07-31 06:43:37,363 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1425.2733779s left)
2019-07-31 06:44:02,805 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064402791912
2019-07-31 06:44:02,827 [salt.minion      :1432][INFO    ][366] Starting a new job with PID 366
2019-07-31 06:44:02,855 [salt.minion      :1711][INFO    ][366] Returning information for job: 20190731064402791912
2019-07-31 06:44:09,738 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1392.8974359s left)
2019-07-31 06:44:32,858 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064432845059
2019-07-31 06:44:32,879 [salt.minion      :1432][INFO    ][530] Starting a new job with PID 530
2019-07-31 06:44:32,895 [salt.minion      :1711][INFO    ][530] Returning information for job: 20190731064432845059
2019-07-31 06:44:43,257 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.37878394s left)
2019-07-31 06:45:02,899 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064502886229
2019-07-31 06:45:02,921 [salt.minion      :1432][INFO    ][554] Starting a new job with PID 554
2019-07-31 06:45:02,947 [salt.minion      :1711][INFO    ][554] Returning information for job: 20190731064502886229
2019-07-31 06:45:16,532 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1326.10400581s left)
2019-07-31 06:45:32,956 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064532943198
2019-07-31 06:45:32,979 [salt.minion      :1432][INFO    ][734] Starting a new job with PID 734
2019-07-31 06:45:33,006 [salt.minion      :1711][INFO    ][734] Returning information for job: 20190731064532943198
2019-07-31 06:45:49,981 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1292.65504384s left)
2019-07-31 06:46:03,023 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064603010594
2019-07-31 06:46:03,047 [salt.minion      :1432][INFO    ][757] Starting a new job with PID 757
2019-07-31 06:46:03,073 [salt.minion      :1711][INFO    ][757] Returning information for job: 20190731064603010594
2019-07-31 06:46:23,873 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1258.76262999s left)
2019-07-31 06:46:33,096 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064633080320
2019-07-31 06:46:33,122 [salt.minion      :1432][INFO    ][826] Starting a new job with PID 826
2019-07-31 06:46:33,154 [salt.minion      :1711][INFO    ][826] Returning information for job: 20190731064633080320
2019-07-31 06:46:57,305 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1225.3311379s left)
2019-07-31 06:47:03,176 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064703163914
2019-07-31 06:47:03,198 [salt.minion      :1432][INFO    ][853] Starting a new job with PID 853
2019-07-31 06:47:03,230 [salt.minion      :1711][INFO    ][853] Returning information for job: 20190731064703163914
2019-07-31 06:47:30,946 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.69036698s left)
2019-07-31 06:47:33,258 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064733245171
2019-07-31 06:47:33,282 [salt.minion      :1432][INFO    ][945] Starting a new job with PID 945
2019-07-31 06:47:33,311 [salt.minion      :1711][INFO    ][945] Returning information for job: 20190731064733245171
2019-07-31 06:48:03,343 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064803330450
2019-07-31 06:48:03,363 [salt.minion      :1432][INFO    ][968] Starting a new job with PID 968
2019-07-31 06:48:03,391 [salt.minion      :1711][INFO    ][968] Returning information for job: 20190731064803330450
2019-07-31 06:48:04,067 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1158.56934595s left)
2019-07-31 06:48:33,427 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064833412955
2019-07-31 06:48:33,450 [salt.minion      :1432][INFO    ][1101] Starting a new job with PID 1101
2019-07-31 06:48:33,474 [salt.minion      :1711][INFO    ][1101] Returning information for job: 20190731064833412955
2019-07-31 06:48:37,719 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.91684794s left)
2019-07-31 06:49:03,513 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064903500880
2019-07-31 06:49:03,537 [salt.minion      :1432][INFO    ][1127] Starting a new job with PID 1127
2019-07-31 06:49:03,566 [salt.minion      :1711][INFO    ][1127] Returning information for job: 20190731064903500880
2019-07-31 06:49:11,313 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1091.32319784s left)
2019-07-31 06:49:33,624 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731064933611597
2019-07-31 06:49:33,646 [salt.minion      :1432][INFO    ][1250] Starting a new job with PID 1250
2019-07-31 06:49:33,672 [salt.minion      :1711][INFO    ][1250] Returning information for job: 20190731064933611597
2019-07-31 06:49:44,497 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1058.13846278s left)
2019-07-31 06:50:03,725 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731065003712581
2019-07-31 06:50:03,748 [salt.minion      :1432][INFO    ][1271] Starting a new job with PID 1271
2019-07-31 06:50:03,775 [salt.minion      :1711][INFO    ][1271] Returning information for job: 20190731065003712581
2019-07-31 06:50:18,050 [salt.loaded.ext.module.maas:1023][INFO    ][32587] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1024.58613682s left)
2019-07-31 06:50:33,828 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command saltutil.find_job with jid 20190731065033816363
2019-07-31 06:50:33,847 [salt.minion      :1432][INFO    ][1348] Starting a new job with PID 1348
2019-07-31 06:50:33,880 [salt.minion      :1711][INFO    ][1348] Returning information for job: 20190731065033816363
2019-07-31 06:50:51,535 [salt.state       :300 ][INFO    ][32587] {'ret': True}
2019-07-31 06:50:51,535 [salt.state       :1951][INFO    ][32587] Completed state [maas.wait_for_machine_status] at time 06:50:51.535530 duration_in_ms=508906.549
2019-07-31 06:50:51,539 [salt.minion      :1711][INFO    ][32587] Returning information for job: 20190731064217405987
2019-07-31 06:50:52,172 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731065052159677
2019-07-31 06:50:52,194 [salt.minion      :1432][INFO    ][1380] Starting a new job with PID 1380
2019-07-31 06:50:56,001 [salt.state       :915 ][INFO    ][1380] Loading fresh modules for state activity
2019-07-31 06:50:56,139 [salt.state       :1780][INFO    ][1380] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:50:56.139385
2019-07-31 06:50:56,139 [salt.state       :1813][INFO    ][1380] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:50:56,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1380] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:50:57,587 [salt.state       :300 ][INFO    ][1380] {'pid': 1394, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:50:57,588 [salt.state       :1951][INFO    ][1380] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:50:57.588008 duration_in_ms=1448.624
2019-07-31 06:50:57,589 [salt.state       :1780][INFO    ][1380] Running state [maas_machines_storage_cmp002_lvm] at time 06:50:57.589475
2019-07-31 06:50:57,589 [salt.state       :1813][INFO    ][1380] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-07-31 06:50:58,205 [salt.state       :300 ][INFO    ][1380] Machine cmp002 is not in Ready state.
2019-07-31 06:50:58,205 [salt.state       :1951][INFO    ][1380] Completed state [maas_machines_storage_cmp002_lvm] at time 06:50:58.205651 duration_in_ms=616.174
2019-07-31 06:50:58,206 [salt.state       :1780][INFO    ][1380] Running state [maas_machines_storage_cmp001_lvm] at time 06:50:58.206067
2019-07-31 06:50:58,206 [salt.state       :1813][INFO    ][1380] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-07-31 06:50:58,798 [salt.state       :300 ][INFO    ][1380] Machine cmp001 is not in Ready state.
2019-07-31 06:50:58,799 [salt.state       :1951][INFO    ][1380] Completed state [maas_machines_storage_cmp001_lvm] at time 06:50:58.799072 duration_in_ms=593.003
2019-07-31 06:50:58,803 [salt.minion      :1711][INFO    ][1380] Returning information for job: 20190731065052159677
2019-07-31 06:50:59,434 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731065059419942
2019-07-31 06:50:59,456 [salt.minion      :1432][INFO    ][1405] Starting a new job with PID 1405
2019-07-31 06:51:00,211 [salt.state       :915 ][INFO    ][1405] Loading fresh modules for state activity
2019-07-31 06:51:00,304 [salt.state       :1780][INFO    ][1405] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:51:00.304634
2019-07-31 06:51:00,305 [salt.state       :1813][INFO    ][1405] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:51:00,307 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1405] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:51:01,813 [salt.state       :300 ][INFO    ][1405] {'pid': 1412, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:51:01,814 [salt.state       :1951][INFO    ][1405] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:51:01.813885 duration_in_ms=1509.252
2019-07-31 06:51:01,816 [salt.state       :1780][INFO    ][1405] Running state [maas.deploy_machines] at time 06:51:01.816472
2019-07-31 06:51:01,817 [salt.state       :1813][INFO    ][1405] Executing state module.run for [maas.deploy_machines]
2019-07-31 06:51:01,818 [salt.utils.decorators:613 ][WARNING ][1405] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:51:02,537 [salt.state       :300 ][INFO    ][1405] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-07-31 06:51:02,538 [salt.state       :1951][INFO    ][1405] Completed state [maas.deploy_machines] at time 06:51:02.538047 duration_in_ms=721.573
2019-07-31 06:51:02,541 [salt.minion      :1711][INFO    ][1405] Returning information for job: 20190731065059419942
2019-07-31 06:51:03,119 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command state.apply with jid 20190731065103106309
2019-07-31 06:51:03,142 [salt.minion      :1432][INFO    ][1425] Starting a new job with PID 1425
2019-07-31 06:51:03,883 [salt.state       :915 ][INFO    ][1425] Loading fresh modules for state activity
2019-07-31 06:51:03,973 [salt.state       :1780][INFO    ][1425] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:51:03.973467
2019-07-31 06:51:03,973 [salt.state       :1813][INFO    ][1425] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-31 06:51:03,976 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1425] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-31 06:51:05,535 [salt.state       :300 ][INFO    ][1425] {'pid': 1435, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-31 06:51:05,536 [salt.state       :1951][INFO    ][1425] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:51:05.536649 duration_in_ms=1563.183
2019-07-31 06:51:05,540 [salt.state       :1780][INFO    ][1425] Running state [maas.wait_for_machine_status] at time 06:51:05.540107
2019-07-31 06:51:05,540 [salt.state       :1813][INFO    ][1425] Executing state module.run for [maas.wait_for_machine_status]
2019-07-31 06:51:05,541 [salt.utils.decorators:613 ][WARNING ][1425] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-31 06:51:09,170 [salt.state       :300 ][INFO    ][1425] {'ret': True}
2019-07-31 06:51:09,171 [salt.state       :1951][INFO    ][1425] Completed state [maas.wait_for_machine_status] at time 06:51:09.171140 duration_in_ms=3631.031
2019-07-31 06:51:09,175 [salt.minion      :1711][INFO    ][1425] Returning information for job: 20190731065103106309
2019-07-31 07:14:05,969 [salt.utils.schedule:1377][INFO    ][19616] Running scheduled job: __mine_interval
2019-07-31 08:14:05,969 [salt.utils.schedule:1377][INFO    ][19616] Running scheduled job: __mine_interval
2019-07-31 08:15:20,542 [salt.minion      :1308][INFO    ][19616] User sudo_ubuntu Executing command cp.push_dir with jid 20190731081520535591
2019-07-31 08:15:20,564 [salt.minion      :1432][INFO    ][7869] Starting a new job with PID 7869
