2019-06-16 20:02:24,994 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-16 20:03:15,032 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-16 20:04:05,072 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-16 20:04:55,115 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-16 20:05:45,160 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-16 20:07:53,937 [salt.utils.decorators:613 ][WARNING ][2748] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 20:07:54,540 [salt.utils.decorators:613 ][WARNING ][2748] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 20:07:56,598 [salt.loaded.int.states.file:2298][WARNING ][2889] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-16 20:08:02,186 [salt.state       :2022][WARNING ][3006] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-16 20:08:04,826 [salt.utils.decorators:613 ][WARNING ][3006] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 20:23:16,728 [salt.utils.decorators:613 ][WARNING ][3006] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 20:46:01,562 [salt.utils.decorators:613 ][WARNING ][3006] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:01:06,995 [salt.utils.decorators:613 ][WARNING ][3006] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:01:10,619 [salt.loaded.ext.module.maasng:1008][WARNING ][3006] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-16 21:01:10,619 [salt.loaded.ext.module.maasng:1011][WARNING ][3006] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-16 21:01:11,194 [salt.loaded.ext.module.maasng:1235][WARNING ][3006] Ignoring parameter vlan:0
2019-06-16 21:01:13,723 [salt.loaded.int.module.cmdmod:395 ][INFO    ][846] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-16 21:01:13,751 [salt.loaded.int.module.cmdmod:395 ][INFO    ][846] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-16 21:01:13,770 [salt.utils.parsers:1051][WARNING ][359] Minion received a SIGTERM. Exiting.
2019-06-16 21:01:14,752 [salt.cli.daemons :293 ][INFO    ][914] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-06-16 21:01:14,831 [salt.cli.daemons :82  ][INFO    ][914] Starting up the Salt Minion
2019-06-16 21:01:14,831 [salt.utils.event :1017][INFO    ][914] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-06-16 21:01:15,657 [salt.minion      :976 ][INFO    ][914] Creating minion process manager
2019-06-16 21:01:17,077 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][914] Executing command ['date', '+%z'] in directory '/root'
2019-06-16 21:01:17,097 [salt.utils.schedule:568 ][INFO    ][914] Updating job settings for scheduled job: __mine_interval
2019-06-16 21:01:17,098 [salt.minion      :1108][INFO    ][914] Added mine.update to scheduler
2019-06-16 21:01:17,102 [salt.minion      :1975][INFO    ][914] Minion is starting as user 'root'
2019-06-16 21:01:17,116 [salt.minion      :2336][INFO    ][914] Minion is ready to receive requests!
2019-06-16 21:01:17,752 [salt.utils.decorators:613 ][WARNING ][851] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:01:17,824 [salt.loaded.ext.module.maas:412 ][WARNING ][851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:01:22,474 [salt.loaded.ext.module.maas:412 ][WARNING ][851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:01:27,197 [salt.loaded.ext.module.maas:412 ][WARNING ][851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:01:27,536 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210127522707
2019-06-16 21:01:27,559 [salt.minion      :1432][INFO    ][1112] Starting a new job with PID 1112
2019-06-16 21:01:27,583 [salt.minion      :1711][INFO    ][1112] Returning information for job: 20190616210127522707
2019-06-16 21:01:31,946 [salt.loaded.ext.module.maas:412 ][WARNING ][851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:01:36,604 [salt.loaded.ext.module.maas:412 ][WARNING ][851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:02:10,240 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616210210226897
2019-06-16 21:02:10,263 [salt.minion      :1432][INFO    ][1342] Starting a new job with PID 1342
2019-06-16 21:02:13,992 [salt.state       :915 ][INFO    ][1342] Loading fresh modules for state activity
2019-06-16 21:02:14,043 [salt.fileclient  :1219][INFO    ][1342] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-16 21:02:14,083 [salt.state       :1780][INFO    ][1342] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:02:14.083908
2019-06-16 21:02:14,084 [salt.state       :1813][INFO    ][1342] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:02:14,086 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1342] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:02:15,485 [salt.state       :300 ][INFO    ][1342] {'pid': 1350, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:02:15,485 [salt.state       :1951][INFO    ][1342] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:02:15.485919 duration_in_ms=1402.012
2019-06-16 21:02:15,487 [salt.state       :1780][INFO    ][1342] Running state [maas.wait_for_machine_status] at time 21:02:15.487346
2019-06-16 21:02:15,487 [salt.state       :1813][INFO    ][1342] Executing state module.run for [maas.wait_for_machine_status]
2019-06-16 21:02:15,487 [salt.utils.decorators:613 ][WARNING ][1342] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:02:16,253 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.23876595s left)
2019-06-16 21:02:25,270 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210225257335
2019-06-16 21:02:25,294 [salt.minion      :1432][INFO    ][1361] Starting a new job with PID 1361
2019-06-16 21:02:25,316 [salt.minion      :1711][INFO    ][1361] Returning information for job: 20190616210225257335
2019-06-16 21:02:47,285 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.20692301s left)
2019-06-16 21:02:55,319 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210255306020
2019-06-16 21:02:55,342 [salt.minion      :1432][INFO    ][1380] Starting a new job with PID 1380
2019-06-16 21:02:55,364 [salt.minion      :1711][INFO    ][1380] Returning information for job: 20190616210255306020
2019-06-16 21:03:18,686 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.8051579s left)
2019-06-16 21:03:25,362 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210325350150
2019-06-16 21:03:25,376 [salt.minion      :1432][INFO    ][1576] Starting a new job with PID 1576
2019-06-16 21:03:25,389 [salt.minion      :1711][INFO    ][1576] Returning information for job: 20190616210325350150
2019-06-16 21:03:50,052 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.43925595s left)
2019-06-16 21:03:55,395 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210355382702
2019-06-16 21:03:55,419 [salt.minion      :1432][INFO    ][1878] Starting a new job with PID 1878
2019-06-16 21:03:55,443 [salt.minion      :1711][INFO    ][1878] Returning information for job: 20190616210355382702
2019-06-16 21:04:21,926 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.5657289s left)
2019-06-16 21:04:25,453 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210425440202
2019-06-16 21:04:25,474 [salt.minion      :1432][INFO    ][2618] Starting a new job with PID 2618
2019-06-16 21:04:25,496 [salt.minion      :1711][INFO    ][2618] Returning information for job: 20190616210425440202
2019-06-16 21:04:53,644 [salt.loaded.ext.module.maas:1023][INFO    ][1342] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.84720802s left)
2019-06-16 21:04:55,502 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210455489099
2019-06-16 21:04:55,526 [salt.minion      :1432][INFO    ][2639] Starting a new job with PID 2639
2019-06-16 21:04:55,550 [salt.minion      :1711][INFO    ][2639] Returning information for job: 20190616210455489099
2019-06-16 21:05:25,568 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210525555128
2019-06-16 21:05:25,591 [salt.minion      :1432][INFO    ][2862] Starting a new job with PID 2862
2019-06-16 21:05:25,614 [salt.minion      :1711][INFO    ][2862] Returning information for job: 20190616210525555128
2019-06-16 21:05:27,275 [salt.state       :300 ][INFO    ][1342] {'ret': True}
2019-06-16 21:05:27,275 [salt.state       :1951][INFO    ][1342] Completed state [maas.wait_for_machine_status] at time 21:05:27.275748 duration_in_ms=191788.4
2019-06-16 21:05:27,278 [salt.minion      :1711][INFO    ][1342] Returning information for job: 20190616210210226897
2019-06-16 21:05:27,744 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616210527731416
2019-06-16 21:05:27,762 [salt.minion      :1432][INFO    ][2889] Starting a new job with PID 2889
2019-06-16 21:05:31,497 [salt.state       :915 ][INFO    ][2889] Loading fresh modules for state activity
2019-06-16 21:05:31,551 [salt.fileclient  :1219][INFO    ][2889] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-16 21:05:31,642 [salt.state       :1780][INFO    ][2889] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:31.642250
2019-06-16 21:05:31,642 [salt.state       :1813][INFO    ][2889] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:05:31,644 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2889] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:05:33,089 [salt.state       :300 ][INFO    ][2889] {'pid': 2911, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:05:33,090 [salt.state       :1951][INFO    ][2889] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:33.090567 duration_in_ms=1448.317
2019-06-16 21:05:33,093 [salt.state       :1780][INFO    ][2889] Running state [maas_machines_storage_cmp002_lvm] at time 21:05:33.093721
2019-06-16 21:05:33,094 [salt.state       :1813][INFO    ][2889] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-16 21:05:34,664 [salt.loaded.ext.module.maasng:610 ][INFO    ][2889] 8y886n
2019-06-16 21:05:34,664 [salt.loaded.ext.module.maasng:626 ][INFO    ][2889] sda
2019-06-16 21:05:35,468 [salt.loaded.ext.module.maasng:361 ][INFO    ][2889] 8y886n
2019-06-16 21:05:35,601 [salt.loaded.ext.module.maasng:367 ][INFO    ][2889] [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'id': 3, u'system_id': u'8y886n', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'7ee38096-2016-4c82-8bf0-eaaac086c51d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8y886n', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'363d1922-a5ab-4de1-85a2-3ae9ff325b9a', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/partition/4', u'type': u'partition', u'id': 4, u'device_id': 3}], u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'cad42ebc-cf9e-4ddc-88eb-07867c3e74e5', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/9/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'id': 9, u'system_id': u'8y886n', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'65f2309b-363d-4c09-8cd7-529567fdf54a', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'partitions': [], u'used_size': 2397988454400, u'serial': None, u'size': 2397988454400}]
2019-06-16 21:05:35,601 [salt.loaded.ext.module.maasng:632 ][INFO    ][2889] vgroot
2019-06-16 21:05:35,601 [salt.loaded.ext.module.maasng:635 ][INFO    ][2889] lvroot
2019-06-16 21:05:35,602 [salt.loaded.ext.module.maasng:639 ][INFO    ][2889] 107374182400
2019-06-16 21:05:36,348 [salt.loaded.ext.module.maasng:645 ][INFO    ][2889] {u'hwe_kernel': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.40'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', 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/8y886n/', u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'8y886n', u'raids': [], u'memory': 32768, u'commissioning_status_name': u'Passed', 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'block_size': 4096, u'available_size': 0, u'uuid': u'7a9a9ad6-5449-4018-a561-1da04702546b', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'a540d8d9-c84d-44f3-9bfd-6291f7d50f71', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'8y886n', u'partition_table_type': None, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/12/', u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'size': 107374182400, u'type': u'virtual', u'id': 12, u'serial': None, u'name': u'vgroot-lvroot'}], u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8e2c7138-e0fd-4a70-baef-0af74f7a0a79', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8y886n', u'device_id': 3, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'247e147b-c5a5-467b-b3d8-83b849501fb4', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8y886n', u'partition_table_type': u'GPT', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'7a9a9ad6-5449-4018-a561-1da04702546b', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'a540d8d9-c84d-44f3-9bfd-6291f7d50f71', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'8y886n', u'partition_table_type': None, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/12/', u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 107374182400, u'type': u'virtual', u'id': 12, u'serial': None, u'name': u'vgroot-lvroot'}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8e2c7138-e0fd-4a70-baef-0af74f7a0a79', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8y886n', u'device_id': 3, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'247e147b-c5a5-467b-b3d8-83b849501fb4', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8y886n', u'partition_table_type': u'GPT', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'8y886n', u'id': 7}], u'current_installation_result_id': None, u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'8e2c7138-e0fd-4a70-baef-0af74f7a0a79', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8y886n', u'device_id': 3, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'247e147b-c5a5-467b-b3d8-83b849501fb4', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8y886n', u'partition_table_type': u'GPT', u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 3, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, u'interface_set': [{u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'id': 29, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'8y886n', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/interfaces/4/'}, {u'discovered': None, u'name': u'enp7s0', u'links': [{u'id': 30, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'8y886n', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/interfaces/15/'}, {u'discovered': None, u'name': u'enp9s0', u'links': [{u'id': 31, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'8y886n', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/interfaces/16/'}, {u'discovered': None, u'name': u'enp8s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'8y886n', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/interfaces/17/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'id': 29, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'8y886n', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8y886n/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-06-16 21:05:36,350 [salt.state       :300 ][INFO    ][2889] {'new': {'storage_layout': 'lvm'}}
2019-06-16 21:05:36,350 [salt.state       :1951][INFO    ][2889] Completed state [maas_machines_storage_cmp002_lvm] at time 21:05:36.350631 duration_in_ms=3256.909
2019-06-16 21:05:36,351 [salt.state       :1780][INFO    ][2889] Running state [maas_machines_storage_cmp001_lvm] at time 21:05:36.351209
2019-06-16 21:05:36,351 [salt.state       :1813][INFO    ][2889] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-16 21:05:37,670 [salt.loaded.ext.module.maasng:610 ][INFO    ][2889] awmhn3
2019-06-16 21:05:37,670 [salt.loaded.ext.module.maasng:626 ][INFO    ][2889] sda
2019-06-16 21:05:38,357 [salt.loaded.ext.module.maasng:361 ][INFO    ][2889] awmhn3
2019-06-16 21:05:38,490 [salt.loaded.ext.module.maasng:367 ][INFO    ][2889] [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'id': 1, u'system_id': u'awmhn3', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'df2de41e-a181-4287-a9de-17bd5180a596', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'awmhn3', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'a6a774af-828e-482e-a2ba-0c0e791bbb93', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/partition/2', u'type': u'partition', u'id': 2, u'device_id': 1}], u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'17064f35-e67e-4e47-804c-6c18071d8cb7', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/7/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'id': 7, u'system_id': u'awmhn3', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'6d09bac2-acd9-4f08-9919-ee83ffcf1117', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'partitions': [], u'used_size': 2397988454400, u'serial': None, u'size': 2397988454400}]
2019-06-16 21:05:38,490 [salt.loaded.ext.module.maasng:632 ][INFO    ][2889] vgroot
2019-06-16 21:05:38,491 [salt.loaded.ext.module.maasng:635 ][INFO    ][2889] lvroot
2019-06-16 21:05:38,491 [salt.loaded.ext.module.maasng:639 ][INFO    ][2889] 107374182400
2019-06-16 21:05:39,180 [salt.loaded.ext.module.maasng:645 ][INFO    ][2889] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'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'mode': u'dhcp', u'id': 16}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'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'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'awmhn3', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/interfaces/5/'}, u'fqdn': u'cmp001.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'awmhn3', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'a5a5b0dc-0d57-48cf-93c8-aafc4b4940e5', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'awmhn3', u'filesystem': {u'uuid': u'003cc314-998e-4005-82bf-bed1ceac4f45', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 8, u'device_id': 1}]}, u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'awmhn3', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'a5a5b0dc-0d57-48cf-93c8-aafc4b4940e5', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'awmhn3', u'filesystem': {u'uuid': u'003cc314-998e-4005-82bf-bed1ceac4f45', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 8, u'device_id': 1}]}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'61e168bc-90bc-46a1-be5b-1e12f7f109db', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'awmhn3', u'partition_table_type': None, u'filesystem': {u'uuid': u'a4da3083-1c48-4a0e-8eef-89940433c78b', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/13/', u'used_size': 107374182400, u'id': 13, u'serial': None, u'partitions': []}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'awmhn3', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.38'], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'awmhn3', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'a5a5b0dc-0d57-48cf-93c8-aafc4b4940e5', u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/1/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'awmhn3', u'filesystem': {u'uuid': u'003cc314-998e-4005-82bf-bed1ceac4f45', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 8, u'device_id': 1}]}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'awmhn3', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'memory_test_status_name': u'Unknown', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'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'mode': u'dhcp', u'id': 16}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'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'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'awmhn3', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'system_id': u'awmhn3', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/interfaces/10/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 20}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'system_id': u'awmhn3', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/interfaces/12/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 22}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'system_id': u'awmhn3', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/interfaces/14/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'61e168bc-90bc-46a1-be5b-1e12f7f109db', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'awmhn3', u'partition_table_type': None, u'filesystem': {u'uuid': u'a4da3083-1c48-4a0e-8eef-89940433c78b', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/awmhn3/blockdevices/13/', u'used_size': 107374182400, u'id': 13, u'serial': None, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/awmhn3/'}
2019-06-16 21:05:39,182 [salt.state       :300 ][INFO    ][2889] {'new': {'storage_layout': 'lvm'}}
2019-06-16 21:05:39,183 [salt.state       :1951][INFO    ][2889] Completed state [maas_machines_storage_cmp001_lvm] at time 21:05:39.183182 duration_in_ms=2831.973
2019-06-16 21:05:39,187 [salt.minion      :1711][INFO    ][2889] Returning information for job: 20190616210527731416
2019-06-16 21:05:39,826 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616210539812621
2019-06-16 21:05:39,848 [salt.minion      :1432][INFO    ][2946] Starting a new job with PID 2946
2019-06-16 21:05:40,594 [salt.state       :915 ][INFO    ][2946] Loading fresh modules for state activity
2019-06-16 21:05:40,650 [salt.fileclient  :1219][INFO    ][2946] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-16 21:05:40,696 [salt.state       :1780][INFO    ][2946] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:40.696832
2019-06-16 21:05:40,697 [salt.state       :1813][INFO    ][2946] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:05:40,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2946] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:05:42,271 [salt.state       :300 ][INFO    ][2946] {'pid': 2953, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:05:42,271 [salt.state       :1951][INFO    ][2946] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:42.271788 duration_in_ms=1574.956
2019-06-16 21:05:42,274 [salt.state       :1780][INFO    ][2946] Running state [maas.deploy_machines] at time 21:05:42.274342
2019-06-16 21:05:42,274 [salt.state       :1813][INFO    ][2946] Executing state module.run for [maas.deploy_machines]
2019-06-16 21:05:42,276 [salt.utils.decorators:613 ][WARNING ][2946] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:05:42,987 [salt.loaded.ext.module.maas:684 ][INFO    ][2946] deploymachines hwe_kernel=hwe-16.04 system_id=8y886n distro_series=xenial
2019-06-16 21:05:49,962 [salt.loaded.ext.module.maas:684 ][INFO    ][2946] deploymachines hwe_kernel=hwe-16.04 system_id=awmhn3 distro_series=xenial
2019-06-16 21:05:54,865 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210554852953
2019-06-16 21:05:54,888 [salt.minion      :1432][INFO    ][3066] Starting a new job with PID 3066
2019-06-16 21:05:54,910 [salt.minion      :1711][INFO    ][3066] Returning information for job: 20190616210554852953
2019-06-16 21:05:56,729 [salt.loaded.ext.module.maas:684 ][INFO    ][2946] deploymachines hwe_kernel=hwe-16.04 system_id=fgnsg3 distro_series=xenial
2019-06-16 21:06:03,600 [salt.loaded.ext.module.maas:684 ][INFO    ][2946] deploymachines hwe_kernel=hwe-16.04 system_id=6hqtcs distro_series=xenial
2019-06-16 21:06:10,664 [salt.loaded.ext.module.maas:684 ][INFO    ][2946] deploymachines hwe_kernel=hwe-16.04 system_id=sbnnkc distro_series=xenial
2019-06-16 21:06:17,730 [salt.state       :300 ][INFO    ][2946] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-16 21:06:17,731 [salt.state       :1951][INFO    ][2946] Completed state [maas.deploy_machines] at time 21:06:17.731413 duration_in_ms=35457.069
2019-06-16 21:06:17,735 [salt.minion      :1711][INFO    ][2946] Returning information for job: 20190616210539812621
2019-06-16 21:06:18,387 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616210618373692
2019-06-16 21:06:18,410 [salt.minion      :1432][INFO    ][3315] Starting a new job with PID 3315
2019-06-16 21:06:22,069 [salt.state       :915 ][INFO    ][3315] Loading fresh modules for state activity
2019-06-16 21:06:22,121 [salt.fileclient  :1219][INFO    ][3315] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-16 21:06:22,170 [salt.state       :1780][INFO    ][3315] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:06:22.170812
2019-06-16 21:06:22,171 [salt.state       :1813][INFO    ][3315] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:06:22,173 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3315] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:06:23,620 [salt.state       :300 ][INFO    ][3315] {'pid': 3326, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:06:23,621 [salt.state       :1951][INFO    ][3315] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:06:23.620936 duration_in_ms=1450.125
2019-06-16 21:06:23,623 [salt.state       :1780][INFO    ][3315] Running state [maas.wait_for_machine_status] at time 21:06:23.623635
2019-06-16 21:06:23,624 [salt.state       :1813][INFO    ][3315] Executing state module.run for [maas.wait_for_machine_status]
2019-06-16 21:06:23,624 [salt.utils.decorators:613 ][WARNING ][3315] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:06:27,237 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.39516211s left)
2019-06-16 21:06:33,465 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210633451795
2019-06-16 21:06:33,486 [salt.minion      :1432][INFO    ][3353] Starting a new job with PID 3353
2019-06-16 21:06:33,507 [salt.minion      :1711][INFO    ][3353] Returning information for job: 20190616210633451795
2019-06-16 21:07:00,662 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.96997619s left)
2019-06-16 21:07:03,511 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210703499041
2019-06-16 21:07:03,535 [salt.minion      :1432][INFO    ][3436] Starting a new job with PID 3436
2019-06-16 21:07:03,558 [salt.minion      :1711][INFO    ][3436] Returning information for job: 20190616210703499041
2019-06-16 21:07:33,599 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210733587097
2019-06-16 21:07:33,618 [salt.minion      :1432][INFO    ][3525] Starting a new job with PID 3525
2019-06-16 21:07:33,629 [salt.minion      :1711][INFO    ][3525] Returning information for job: 20190616210733587097
2019-06-16 21:07:33,647 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.98499417s left)
2019-06-16 21:08:03,808 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210803795130
2019-06-16 21:08:03,832 [salt.minion      :1432][INFO    ][3758] Starting a new job with PID 3758
2019-06-16 21:08:03,853 [salt.minion      :1711][INFO    ][3758] Returning information for job: 20190616210803795130
2019-06-16 21:08:06,499 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.13309717s left)
2019-06-16 21:08:33,888 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210833872780
2019-06-16 21:08:33,910 [salt.minion      :1432][INFO    ][4145] Starting a new job with PID 4145
2019-06-16 21:08:33,932 [salt.minion      :1711][INFO    ][4145] Returning information for job: 20190616210833872780
2019-06-16 21:08:41,344 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.28861117s left)
2019-06-16 21:09:03,976 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210903963613
2019-06-16 21:09:04,001 [salt.minion      :1432][INFO    ][4208] Starting a new job with PID 4208
2019-06-16 21:09:04,024 [salt.minion      :1711][INFO    ][4208] Returning information for job: 20190616210903963613
2019-06-16 21:09:34,063 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616210934050336
2019-06-16 21:09:34,088 [salt.minion      :1432][INFO    ][4637] Starting a new job with PID 4637
2019-06-16 21:09:34,109 [salt.minion      :1711][INFO    ][4637] Returning information for job: 20190616210934050336
2019-06-16 21:10:04,160 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211004151383
2019-06-16 21:10:04,184 [salt.minion      :1432][INFO    ][4690] Starting a new job with PID 4690
2019-06-16 21:10:04,200 [salt.minion      :1711][INFO    ][4690] Returning information for job: 20190616211004151383
2019-06-16 21:10:34,246 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211034234351
2019-06-16 21:10:34,268 [salt.minion      :1432][INFO    ][4794] Starting a new job with PID 4794
2019-06-16 21:10:34,289 [salt.minion      :1711][INFO    ][4794] Returning information for job: 20190616211034234351
2019-06-16 21:11:04,344 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211104332206
2019-06-16 21:11:04,368 [salt.minion      :1432][INFO    ][4851] Starting a new job with PID 4851
2019-06-16 21:11:04,391 [salt.minion      :1711][INFO    ][4851] Returning information for job: 20190616211104332206
2019-06-16 21:11:34,438 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211134425890
2019-06-16 21:11:34,459 [salt.minion      :1432][INFO    ][5042] Starting a new job with PID 5042
2019-06-16 21:11:34,475 [salt.minion      :1711][INFO    ][5042] Returning information for job: 20190616211134425890
2019-06-16 21:12:04,525 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211204514339
2019-06-16 21:12:04,552 [salt.minion      :1432][INFO    ][5102] Starting a new job with PID 5102
2019-06-16 21:12:04,575 [salt.minion      :1711][INFO    ][5102] Returning information for job: 20190616211204514339
2019-06-16 21:12:34,644 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211234632058
2019-06-16 21:12:34,669 [salt.minion      :1432][INFO    ][5230] Starting a new job with PID 5230
2019-06-16 21:12:34,688 [salt.minion      :1711][INFO    ][5230] Returning information for job: 20190616211234632058
2019-06-16 21:13:04,764 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211304751416
2019-06-16 21:13:04,787 [salt.minion      :1432][INFO    ][5292] Starting a new job with PID 5292
2019-06-16 21:13:04,810 [salt.minion      :1711][INFO    ][5292] Returning information for job: 20190616211304751416
2019-06-16 21:13:34,890 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211334879763
2019-06-16 21:13:34,912 [salt.minion      :1432][INFO    ][5363] Starting a new job with PID 5363
2019-06-16 21:13:34,933 [salt.minion      :1711][INFO    ][5363] Returning information for job: 20190616211334879763
2019-06-16 21:13:58,927 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1794.70583916s left)
2019-06-16 21:14:05,021 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211405005478
2019-06-16 21:14:05,041 [salt.minion      :1432][INFO    ][5538] Starting a new job with PID 5538
2019-06-16 21:14:05,053 [salt.minion      :1711][INFO    ][5538] Returning information for job: 20190616211405005478
2019-06-16 21:14:32,099 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1761.53343701s left)
2019-06-16 21:14:35,234 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211435221480
2019-06-16 21:14:35,258 [salt.minion      :1432][INFO    ][5799] Starting a new job with PID 5799
2019-06-16 21:14:35,280 [salt.minion      :1711][INFO    ][5799] Returning information for job: 20190616211435221480
2019-06-16 21:15:05,342 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211505336709
2019-06-16 21:15:05,356 [salt.minion      :1432][INFO    ][5991] Starting a new job with PID 5991
2019-06-16 21:15:05,371 [salt.minion      :1711][INFO    ][5991] Returning information for job: 20190616211505336709
2019-06-16 21:15:05,504 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1728.12790704s left)
2019-06-16 21:15:35,436 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211535424519
2019-06-16 21:15:35,460 [salt.minion      :1432][INFO    ][6157] Starting a new job with PID 6157
2019-06-16 21:15:35,484 [salt.minion      :1711][INFO    ][6157] Returning information for job: 20190616211535424519
2019-06-16 21:15:39,370 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1694.26216197s left)
2019-06-16 21:16:05,558 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211605553112
2019-06-16 21:16:05,572 [salt.minion      :1432][INFO    ][6420] Starting a new job with PID 6420
2019-06-16 21:16:05,583 [salt.minion      :1711][INFO    ][6420] Returning information for job: 20190616211605553112
2019-06-16 21:16:12,823 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1660.80978608s left)
2019-06-16 21:16:35,657 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211635645133
2019-06-16 21:16:35,680 [salt.minion      :1432][INFO    ][6503] Starting a new job with PID 6503
2019-06-16 21:16:35,701 [salt.minion      :1711][INFO    ][6503] Returning information for job: 20190616211635645133
2019-06-16 21:16:46,292 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1627.33995008s left)
2019-06-16 21:17:05,798 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211705785308
2019-06-16 21:17:05,820 [salt.minion      :1432][INFO    ][6735] Starting a new job with PID 6735
2019-06-16 21:17:05,844 [salt.minion      :1711][INFO    ][6735] Returning information for job: 20190616211705785308
2019-06-16 21:17:19,035 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1594.59765196s left)
2019-06-16 21:17:35,910 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211735896093
2019-06-16 21:17:35,933 [salt.minion      :1432][INFO    ][6838] Starting a new job with PID 6838
2019-06-16 21:17:35,957 [salt.minion      :1711][INFO    ][6838] Returning information for job: 20190616211735896093
2019-06-16 21:17:52,573 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1561.05947614s left)
2019-06-16 21:18:06,108 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211806096983
2019-06-16 21:18:06,129 [salt.minion      :1432][INFO    ][7093] Starting a new job with PID 7093
2019-06-16 21:18:06,150 [salt.minion      :1711][INFO    ][7093] Returning information for job: 20190616211806096983
2019-06-16 21:18:26,000 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1527.63275599s left)
2019-06-16 21:18:36,270 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211836257280
2019-06-16 21:18:36,294 [salt.minion      :1432][INFO    ][7171] Starting a new job with PID 7171
2019-06-16 21:18:36,315 [salt.minion      :1711][INFO    ][7171] Returning information for job: 20190616211836257280
2019-06-16 21:18:58,974 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1494.65850115s left)
2019-06-16 21:19:06,445 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211906431328
2019-06-16 21:19:06,470 [salt.minion      :1432][INFO    ][7253] Starting a new job with PID 7253
2019-06-16 21:19:06,492 [salt.minion      :1711][INFO    ][7253] Returning information for job: 20190616211906431328
2019-06-16 21:19:32,644 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1460.98870897s left)
2019-06-16 21:19:36,620 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616211936607089
2019-06-16 21:19:36,644 [salt.minion      :1432][INFO    ][7281] Starting a new job with PID 7281
2019-06-16 21:19:36,667 [salt.minion      :1711][INFO    ][7281] Returning information for job: 20190616211936607089
2019-06-16 21:20:05,992 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1427.64067101s left)
2019-06-16 21:20:06,821 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212006808455
2019-06-16 21:20:06,845 [salt.minion      :1432][INFO    ][7339] Starting a new job with PID 7339
2019-06-16 21:20:06,869 [salt.minion      :1711][INFO    ][7339] Returning information for job: 20190616212006808455
2019-06-16 21:20:37,021 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212037008513
2019-06-16 21:20:37,045 [salt.minion      :1432][INFO    ][7362] Starting a new job with PID 7362
2019-06-16 21:20:37,067 [salt.minion      :1711][INFO    ][7362] Returning information for job: 20190616212037008513
2019-06-16 21:20:39,286 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1394.34654403s left)
2019-06-16 21:21:07,248 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212107235585
2019-06-16 21:21:07,275 [salt.minion      :1432][INFO    ][7416] Starting a new job with PID 7416
2019-06-16 21:21:07,298 [salt.minion      :1711][INFO    ][7416] Returning information for job: 20190616212107235585
2019-06-16 21:21:12,777 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1360.85538912s left)
2019-06-16 21:21:37,275 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212137262727
2019-06-16 21:21:37,300 [salt.minion      :1432][INFO    ][7437] Starting a new job with PID 7437
2019-06-16 21:21:37,322 [salt.minion      :1711][INFO    ][7437] Returning information for job: 20190616212137262727
2019-06-16 21:21:46,311 [salt.loaded.ext.module.maas:1023][INFO    ][3315] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1327.32130814s left)
2019-06-16 21:22:07,309 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212207296831
2019-06-16 21:22:07,332 [salt.minion      :1432][INFO    ][7494] Starting a new job with PID 7494
2019-06-16 21:22:07,354 [salt.minion      :1711][INFO    ][7494] Returning information for job: 20190616212207296831
2019-06-16 21:22:19,623 [salt.loaded.ext.module.maas:993 ][INFO    ][3315] Machine sbnnkc mark broken
2019-06-16 21:22:20,368 [salt.loaded.ext.module.maas:996 ][INFO    ][3315] Machine sbnnkc mark fixed
2019-06-16 21:22:21,258 [salt.loaded.ext.module.maas:684 ][INFO    ][3315] deploymachines hwe_kernel=hwe-16.04 system_id=sbnnkc distro_series=xenial
2019-06-16 21:22:23,558 [salt.loaded.ext.module.maas:160 ][ERROR   ][3315] 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-06-16 21:22:23,560 [salt.state       :302 ][ERROR   ][3315] 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-06-16 21:22:23,560 [salt.state       :1951][INFO    ][3315] Completed state [maas.wait_for_machine_status] at time 21:22:23.560444 duration_in_ms=959936.803
2019-06-16 21:22:23,567 [salt.minion      :1711][INFO    ][3315] Returning information for job: 20190616210618373692
2019-06-16 21:22:34,329 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command pillar.get with jid 20190616212234317175
2019-06-16 21:22:34,352 [salt.minion      :1432][INFO    ][7594] Starting a new job with PID 7594
2019-06-16 21:22:34,362 [salt.minion      :1711][INFO    ][7594] Returning information for job: 20190616212234317175
2019-06-16 21:22:34,907 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command service.status with jid 20190616212234900426
2019-06-16 21:22:34,928 [salt.minion      :1432][INFO    ][7599] Starting a new job with PID 7599
2019-06-16 21:22:35,238 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7599] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:35,270 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7599] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-16 21:22:35,285 [salt.minion      :1711][INFO    ][7599] Returning information for job: 20190616212234900426
2019-06-16 21:22:35,809 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616212235796640
2019-06-16 21:22:35,830 [salt.minion      :1432][INFO    ][7610] Starting a new job with PID 7610
2019-06-16 21:22:39,311 [salt.state       :915 ][INFO    ][7610] Loading fresh modules for state activity
2019-06-16 21:22:39,735 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'salt-minion --version' in directory '/root'
2019-06-16 21:22:40,097 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'salt-minion --version' in directory '/root'
2019-06-16 21:22:40,995 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'salt-minion --version' in directory '/root'
2019-06-16 21:22:41,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'salt-minion --version' in directory '/root'
2019-06-16 21:22:42,696 [salt.state       :1780][INFO    ][7610] Running state [salt-minion] at time 21:22:42.696661
2019-06-16 21:22:42,697 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [salt-minion]
2019-06-16 21:22:42,697 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-16 21:22:42,776 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:42,776 [salt.state       :1951][INFO    ][7610] Completed state [salt-minion] at time 21:22:42.776500 duration_in_ms=79.839
2019-06-16 21:22:42,776 [salt.state       :1780][INFO    ][7610] Running state [salt_minion_dependency_packages] at time 21:22:42.776770
2019-06-16 21:22:42,777 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-16 21:22:42,782 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:42,782 [salt.state       :1951][INFO    ][7610] Completed state [salt_minion_dependency_packages] at time 21:22:42.782255 duration_in_ms=5.485
2019-06-16 21:22:42,784 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/minion.d/minion.conf] at time 21:22:42.784654
2019-06-16 21:22:42,784 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-16 21:22:42,963 [salt.state       :300 ][INFO    ][7610] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-16 21:22:42,963 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/minion.d/minion.conf] at time 21:22:42.963254 duration_in_ms=178.601
2019-06-16 21:22:42,963 [salt.state       :1780][INFO    ][7610] Running state [python-netaddr] at time 21:22:42.963439
2019-06-16 21:22:42,963 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [python-netaddr]
2019-06-16 21:22:42,968 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:42,968 [salt.state       :1951][INFO    ][7610] Completed state [python-netaddr] at time 21:22:42.968129 duration_in_ms=4.689
2019-06-16 21:22:42,970 [salt.state       :1780][INFO    ][7610] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:22:42.970137
2019-06-16 21:22:42,970 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-16 21:22:42,980 [salt.state       :300 ][INFO    ][7610] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-16 21:22:42,980 [salt.state       :1951][INFO    ][7610] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:22:42.980263 duration_in_ms=10.126
2019-06-16 21:22:42,980 [salt.state       :1780][INFO    ][7610] Running state [salt-minion] at time 21:22:42.980938
2019-06-16 21:22:42,981 [salt.state       :1813][INFO    ][7610] Executing state service.running for [salt-minion]
2019-06-16 21:22:42,981 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:43,012 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-16 21:22:43,026 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-16 21:22:43,044 [salt.state       :300 ][INFO    ][7610] The service salt-minion is already running
2019-06-16 21:22:43,044 [salt.state       :1951][INFO    ][7610] Completed state [salt-minion] at time 21:22:43.044803 duration_in_ms=63.864
2019-06-16 21:22:43,046 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains.d] at time 21:22:43.046262
2019-06-16 21:22:43,046 [salt.state       :1813][INFO    ][7610] Executing state file.directory for [/etc/salt/grains.d]
2019-06-16 21:22:43,047 [salt.state       :300 ][INFO    ][7610] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-16 21:22:43,047 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains.d] at time 21:22:43.047718 duration_in_ms=1.456
2019-06-16 21:22:43,048 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains] at time 21:22:43.048358
2019-06-16 21:22:43,048 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/grains]
2019-06-16 21:22:43,049 [salt.state       :300 ][INFO    ][7610] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-16 21:22:43,049 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains] at time 21:22:43.049364 duration_in_ms=1.006
2019-06-16 21:22:43,049 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains.d/placeholder] at time 21:22:43.049814
2019-06-16 21:22:43,050 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-16 21:22:43,050 [salt.state       :300 ][INFO    ][7610] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-16 21:22:43,050 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains.d/placeholder] at time 21:22:43.050821 duration_in_ms=1.007
2019-06-16 21:22:43,051 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains.d/sphinx] at time 21:22:43.051258
2019-06-16 21:22:43,051 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-16 21:22:43,065 [salt.state       :300 ][INFO    ][7610] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-16 21:22:43,065 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains.d/sphinx] at time 21:22:43.065540 duration_in_ms=14.28
2019-06-16 21:22:43,069 [salt.state       :1780][INFO    ][7610] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.069226
2019-06-16 21:22:43,069 [salt.state       :1813][INFO    ][7610] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-16 21:22:43,070 [salt.state       :300 ][INFO    ][7610] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-16 21:22:43,070 [salt.state       :1951][INFO    ][7610] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.070686 duration_in_ms=1.46
2019-06-16 21:22:43,071 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains.d/dns_records] at time 21:22:43.071473
2019-06-16 21:22:43,071 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-16 21:22:43,082 [salt.state       :300 ][INFO    ][7610] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-16 21:22:43,083 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains.d/dns_records] at time 21:22:43.083283 duration_in_ms=11.81
2019-06-16 21:22:43,084 [salt.state       :1780][INFO    ][7610] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.084789
2019-06-16 21:22:43,085 [salt.state       :1813][INFO    ][7610] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-16 21:22:43,085 [salt.state       :300 ][INFO    ][7610] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-16 21:22:43,086 [salt.state       :1951][INFO    ][7610] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.086103 duration_in_ms=1.314
2019-06-16 21:22:43,086 [salt.state       :1780][INFO    ][7610] Running state [/etc/salt/grains.d/salt] at time 21:22:43.086868
2019-06-16 21:22:43,087 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-16 21:22:43,100 [salt.state       :300 ][INFO    ][7610] File /etc/salt/grains.d/salt is in the correct state
2019-06-16 21:22:43,101 [salt.state       :1951][INFO    ][7610] Completed state [/etc/salt/grains.d/salt] at time 21:22:43.101236 duration_in_ms=14.368
2019-06-16 21:22:43,102 [salt.state       :1780][INFO    ][7610] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.102665
2019-06-16 21:22:43,103 [salt.state       :1813][INFO    ][7610] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-16 21:22:43,103 [salt.state       :300 ][INFO    ][7610] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-16 21:22:43,104 [salt.state       :1951][INFO    ][7610] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:22:43.103967 duration_in_ms=1.301
2019-06-16 21:22:43,107 [salt.state       :1780][INFO    ][7610] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:22:43.107019
2019-06-16 21:22:43,107 [salt.state       :1813][INFO    ][7610] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-16 21:22:43,108 [salt.state       :300 ][INFO    ][7610] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-16 21:22:43,108 [salt.state       :1951][INFO    ][7610] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:22:43.108360 duration_in_ms=1.341
2019-06-16 21:22:43,109 [salt.state       :1780][INFO    ][7610] Running state [mine.update] at time 21:22:43.109450
2019-06-16 21:22:43,109 [salt.state       :1813][INFO    ][7610] Executing state module.wait for [mine.update]
2019-06-16 21:22:43,110 [salt.state       :300 ][INFO    ][7610] No changes made for mine.update
2019-06-16 21:22:43,110 [salt.state       :1951][INFO    ][7610] Completed state [mine.update] at time 21:22:43.110698 duration_in_ms=1.248
2019-06-16 21:22:43,111 [salt.state       :1780][INFO    ][7610] Running state [ca-certificates] at time 21:22:43.111056
2019-06-16 21:22:43,111 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [ca-certificates]
2019-06-16 21:22:43,122 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:43,122 [salt.state       :1951][INFO    ][7610] Completed state [ca-certificates] at time 21:22:43.122900 duration_in_ms=11.843
2019-06-16 21:22:43,123 [salt.state       :1780][INFO    ][7610] Running state [update-ca-certificates] at time 21:22:43.123923
2019-06-16 21:22:43,124 [salt.state       :1813][INFO    ][7610] Executing state cmd.wait for [update-ca-certificates]
2019-06-16 21:22:43,124 [salt.state       :300 ][INFO    ][7610] No changes made for update-ca-certificates
2019-06-16 21:22:43,125 [salt.state       :1951][INFO    ][7610] Completed state [update-ca-certificates] at time 21:22:43.125062 duration_in_ms=1.139
2019-06-16 21:22:43,125 [salt.state       :1780][INFO    ][7610] Running state [iptables] at time 21:22:43.125396
2019-06-16 21:22:43,125 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [iptables]
2019-06-16 21:22:43,135 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:43,136 [salt.state       :1951][INFO    ][7610] Completed state [iptables] at time 21:22:43.136073 duration_in_ms=10.676
2019-06-16 21:22:43,136 [salt.state       :1780][INFO    ][7610] Running state [iptables-persistent] at time 21:22:43.136402
2019-06-16 21:22:43,136 [salt.state       :1813][INFO    ][7610] Executing state pkg.installed for [iptables-persistent]
2019-06-16 21:22:43,146 [salt.state       :300 ][INFO    ][7610] All specified packages are already installed
2019-06-16 21:22:43,146 [salt.state       :1951][INFO    ][7610] Completed state [iptables-persistent] at time 21:22:43.146424 duration_in_ms=10.022
2019-06-16 21:22:43,147 [salt.state       :1780][INFO    ][7610] Running state [iptables_modules_v4_load] at time 21:22:43.147737
2019-06-16 21:22:43,148 [salt.state       :1813][INFO    ][7610] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-16 21:22:43,148 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'lsmod' in directory '/root'
2019-06-16 21:22:43,173 [salt.state       :300 ][INFO    ][7610] Kernel modules iptable_filter, ip_tables are already present
2019-06-16 21:22:43,174 [salt.state       :1951][INFO    ][7610] Completed state [iptables_modules_v4_load] at time 21:22:43.173902 duration_in_ms=26.165
2019-06-16 21:22:43,174 [salt.state       :1780][INFO    ][7610] Running state [/etc/iptables/rules.v4] at time 21:22:43.174909
2019-06-16 21:22:43,175 [salt.state       :1813][INFO    ][7610] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-16 21:22:43,286 [salt.state       :300 ][INFO    ][7610] File /etc/iptables/rules.v4 is in the correct state
2019-06-16 21:22:43,287 [salt.state       :1951][INFO    ][7610] Completed state [/etc/iptables/rules.v4] at time 21:22:43.287055 duration_in_ms=112.147
2019-06-16 21:22:43,288 [salt.state       :1780][INFO    ][7610] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:22:43.288227
2019-06-16 21:22:43,288 [salt.state       :1813][INFO    ][7610] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-16 21:22:43,289 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-16 21:22:43,308 [salt.state       :300 ][INFO    ][7610] onlyif execution failed
2019-06-16 21:22:43,309 [salt.state       :1951][INFO    ][7610] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:22:43.308962 duration_in_ms=20.735
2019-06-16 21:22:43,310 [salt.state       :1780][INFO    ][7610] Running state [netfilter-persistent] at time 21:22:43.310073
2019-06-16 21:22:43,310 [salt.state       :1813][INFO    ][7610] Executing state service.running for [netfilter-persistent]
2019-06-16 21:22:43,311 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:43,331 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-16 21:22:43,349 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-16 21:22:43,367 [salt.state       :300 ][INFO    ][7610] The service netfilter-persistent is already running
2019-06-16 21:22:43,367 [salt.state       :1951][INFO    ][7610] Completed state [netfilter-persistent] at time 21:22:43.367749 duration_in_ms=57.675
2019-06-16 21:22:43,369 [salt.state       :1780][INFO    ][7610] Running state [iptables_extra.remove_stale_tables] at time 21:22:43.369139
2019-06-16 21:22:43,369 [salt.state       :1813][INFO    ][7610] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-16 21:22:43,370 [salt.state       :300 ][INFO    ][7610] No changes made for iptables_extra.remove_stale_tables
2019-06-16 21:22:43,370 [salt.state       :1951][INFO    ][7610] Completed state [iptables_extra.remove_stale_tables] at time 21:22:43.370596 duration_in_ms=1.458
2019-06-16 21:22:43,371 [salt.state       :1780][INFO    ][7610] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:22:43.370993
2019-06-16 21:22:43,371 [salt.state       :1813][INFO    ][7610] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-16 21:22:43,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7610] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-16 21:22:43,387 [salt.state       :300 ][INFO    ][7610] onlyif execution failed
2019-06-16 21:22:43,388 [salt.state       :1951][INFO    ][7610] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:22:43.388055 duration_in_ms=17.061
2019-06-16 21:22:43,389 [salt.state       :1780][INFO    ][7610] Running state [/etc/iptables/rules.v6] at time 21:22:43.389560
2019-06-16 21:22:43,390 [salt.state       :1813][INFO    ][7610] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-16 21:22:43,390 [salt.state       :300 ][INFO    ][7610] File /etc/iptables/rules.v6 is not present
2019-06-16 21:22:43,391 [salt.state       :1951][INFO    ][7610] Completed state [/etc/iptables/rules.v6] at time 21:22:43.391086 duration_in_ms=1.526
2019-06-16 21:22:43,392 [salt.state       :1780][INFO    ][7610] Running state [iptables_extra.flush_all] at time 21:22:43.392126
2019-06-16 21:22:43,392 [salt.state       :1813][INFO    ][7610] Executing state module.wait for [iptables_extra.flush_all]
2019-06-16 21:22:43,393 [salt.state       :300 ][INFO    ][7610] No changes made for iptables_extra.flush_all
2019-06-16 21:22:43,393 [salt.state       :1951][INFO    ][7610] Completed state [iptables_extra.flush_all] at time 21:22:43.393315 duration_in_ms=1.189
2019-06-16 21:22:43,397 [salt.minion      :1711][INFO    ][7610] Returning information for job: 20190616212235796640
2019-06-16 21:22:44,030 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616212244016687
2019-06-16 21:22:44,053 [salt.minion      :1432][INFO    ][7686] Starting a new job with PID 7686
2019-06-16 21:22:44,849 [salt.state       :915 ][INFO    ][7686] Loading fresh modules for state activity
2019-06-16 21:22:45,435 [salt.state       :1780][INFO    ][7686] Running state [maas-rack-controller] at time 21:22:45.435356
2019-06-16 21:22:45,435 [salt.state       :1813][INFO    ][7686] Executing state pkg.installed for [maas-rack-controller]
2019-06-16 21:22:45,436 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7686] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-16 21:22:45,490 [salt.state       :300 ][INFO    ][7686] All specified packages are already installed
2019-06-16 21:22:45,490 [salt.state       :1951][INFO    ][7686] Completed state [maas-rack-controller] at time 21:22:45.490595 duration_in_ms=55.239
2019-06-16 21:22:45,490 [salt.state       :1780][INFO    ][7686] Running state [ipmitool] at time 21:22:45.490801
2019-06-16 21:22:45,491 [salt.state       :1813][INFO    ][7686] Executing state pkg.installed for [ipmitool]
2019-06-16 21:22:45,495 [salt.state       :300 ][INFO    ][7686] All specified packages are already installed
2019-06-16 21:22:45,495 [salt.state       :1951][INFO    ][7686] Completed state [ipmitool] at time 21:22:45.495200 duration_in_ms=4.4
2019-06-16 21:22:45,497 [salt.state       :1780][INFO    ][7686] Running state [/etc/maas/rackd.conf] at time 21:22:45.497119
2019-06-16 21:22:45,497 [salt.state       :1813][INFO    ][7686] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-16 21:22:45,497 [salt.state       :300 ][INFO    ][7686] No changes needed to be made
2019-06-16 21:22:45,498 [salt.state       :1951][INFO    ][7686] Completed state [/etc/maas/rackd.conf] at time 21:22:45.498106 duration_in_ms=0.986
2019-06-16 21:22:45,498 [salt.state       :1780][INFO    ][7686] Running state [/etc/maas/rackd.conf] at time 21:22:45.498250
2019-06-16 21:22:45,498 [salt.state       :1813][INFO    ][7686] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-16 21:22:45,498 [salt.loaded.int.states.file:2298][WARNING ][7686] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-16 21:22:45,498 [salt.state       :300 ][INFO    ][7686] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-16 21:22:45,499 [salt.state       :1951][INFO    ][7686] Completed state [/etc/maas/rackd.conf] at time 21:22:45.499027 duration_in_ms=0.777
2019-06-16 21:22:45,499 [salt.state       :1780][INFO    ][7686] Running state [maas-rackd] at time 21:22:45.499633
2019-06-16 21:22:45,499 [salt.state       :1813][INFO    ][7686] Executing state service.running for [maas-rackd]
2019-06-16 21:22:45,500 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7686] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:45,532 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7686] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-16 21:22:45,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7686] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-16 21:22:45,561 [salt.state       :300 ][INFO    ][7686] The service maas-rackd is already running
2019-06-16 21:22:45,561 [salt.state       :1951][INFO    ][7686] Completed state [maas-rackd] at time 21:22:45.561253 duration_in_ms=61.619
2019-06-16 21:22:45,562 [salt.minion      :1711][INFO    ][7686] Returning information for job: 20190616212244016687
2019-06-16 21:22:46,089 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616212246076501
2019-06-16 21:22:46,111 [salt.minion      :1432][INFO    ][7711] Starting a new job with PID 7711
2019-06-16 21:22:46,831 [salt.state       :915 ][INFO    ][7711] Loading fresh modules for state activity
2019-06-16 21:22:47,431 [salt.state       :1780][INFO    ][7711] Running state [maas-region-controller] at time 21:22:47.431720
2019-06-16 21:22:47,432 [salt.state       :1813][INFO    ][7711] Executing state pkg.installed for [maas-region-controller]
2019-06-16 21:22:47,432 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-16 21:22:47,524 [salt.state       :300 ][INFO    ][7711] All specified packages are already installed
2019-06-16 21:22:47,525 [salt.state       :1951][INFO    ][7711] Completed state [maas-region-controller] at time 21:22:47.524992 duration_in_ms=93.272
2019-06-16 21:22:47,525 [salt.state       :1780][INFO    ][7711] Running state [python-oauth] at time 21:22:47.525321
2019-06-16 21:22:47,525 [salt.state       :1813][INFO    ][7711] Executing state pkg.installed for [python-oauth]
2019-06-16 21:22:47,532 [salt.state       :300 ][INFO    ][7711] All specified packages are already installed
2019-06-16 21:22:47,532 [salt.state       :1951][INFO    ][7711] Completed state [python-oauth] at time 21:22:47.532603 duration_in_ms=7.282
2019-06-16 21:22:47,535 [salt.state       :1780][INFO    ][7711] Running state [/etc/maas/regiond.conf] at time 21:22:47.535690
2019-06-16 21:22:47,535 [salt.state       :1813][INFO    ][7711] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-16 21:22:47,574 [salt.state       :300 ][INFO    ][7711] No changes needed to be made
2019-06-16 21:22:47,574 [salt.state       :1951][INFO    ][7711] Completed state [/etc/maas/regiond.conf] at time 21:22:47.574806 duration_in_ms=39.116
2019-06-16 21:22:47,575 [salt.state       :1780][INFO    ][7711] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:22:47.575269
2019-06-16 21:22:47,575 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-16 21:22:47,640 [salt.state       :300 ][INFO    ][7711] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-16 21:22:47,640 [salt.state       :1951][INFO    ][7711] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:22:47.640227 duration_in_ms=64.957
2019-06-16 21:22:47,640 [salt.state       :1780][INFO    ][7711] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:22:47.640700
2019-06-16 21:22:47,641 [salt.state       :1813][INFO    ][7711] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-16 21:22:47,653 [salt.state       :300 ][INFO    ][7711] No changes needed to be made
2019-06-16 21:22:47,653 [salt.state       :1951][INFO    ][7711] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:22:47.653598 duration_in_ms=12.898
2019-06-16 21:22:47,654 [salt.state       :1780][INFO    ][7711] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:22:47.654066
2019-06-16 21:22:47,654 [salt.state       :1813][INFO    ][7711] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-16 21:22:47,671 [salt.state       :300 ][INFO    ][7711] No changes needed to be made
2019-06-16 21:22:47,671 [salt.state       :1951][INFO    ][7711] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:22:47.671461 duration_in_ms=17.395
2019-06-16 21:22:47,672 [salt.state       :1780][INFO    ][7711] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:22:47.671953
2019-06-16 21:22:47,672 [salt.state       :1813][INFO    ][7711] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-16 21:22:47,694 [salt.state       :300 ][INFO    ][7711] No changes needed to be made
2019-06-16 21:22:47,694 [salt.state       :1951][INFO    ][7711] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:22:47.694640 duration_in_ms=22.687
2019-06-16 21:22:47,695 [salt.state       :1780][INFO    ][7711] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:22:47.695072
2019-06-16 21:22:47,695 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-16 21:22:47,705 [salt.state       :300 ][INFO    ][7711] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-16 21:22:47,705 [salt.state       :1951][INFO    ][7711] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:22:47.705838 duration_in_ms=10.766
2019-06-16 21:22:47,707 [salt.state       :1780][INFO    ][7711] Running state [a2enmod headers] at time 21:22:47.706953
2019-06-16 21:22:47,707 [salt.state       :1813][INFO    ][7711] Executing state cmd.run for [a2enmod headers]
2019-06-16 21:22:47,707 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command 'a2enmod headers' in directory '/root'
2019-06-16 21:22:47,776 [salt.state       :300 ][INFO    ][7711] {'pid': 7730, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-16 21:22:47,777 [salt.state       :1951][INFO    ][7711] Completed state [a2enmod headers] at time 21:22:47.777253 duration_in_ms=70.299
2019-06-16 21:22:47,777 [salt.state       :1780][INFO    ][7711] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:22:47.777844
2019-06-16 21:22:47,778 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-16 21:22:47,794 [salt.state       :300 ][INFO    ][7711] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-16 21:22:47,795 [salt.state       :1951][INFO    ][7711] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:22:47.795193 duration_in_ms=17.349
2019-06-16 21:22:47,795 [salt.state       :1780][INFO    ][7711] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:22:47.795831
2019-06-16 21:22:47,796 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-16 21:22:47,855 [salt.state       :300 ][INFO    ][7711] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-16 21:22:47,856 [salt.state       :1951][INFO    ][7711] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:22:47.856065 duration_in_ms=60.235
2019-06-16 21:22:47,856 [salt.state       :1780][INFO    ][7711] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:22:47.856574
2019-06-16 21:22:47,856 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-16 21:22:47,909 [salt.state       :300 ][INFO    ][7711] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-16 21:22:47,909 [salt.state       :1951][INFO    ][7711] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:22:47.909703 duration_in_ms=53.129
2019-06-16 21:22:47,910 [salt.state       :1780][INFO    ][7711] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:22:47.910146
2019-06-16 21:22:47,910 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-16 21:22:47,969 [salt.state       :300 ][INFO    ][7711] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-16 21:22:47,969 [salt.state       :1951][INFO    ][7711] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:22:47.969706 duration_in_ms=59.56
2019-06-16 21:22:47,970 [salt.state       :1780][INFO    ][7711] Running state [/root/.pgpass] at time 21:22:47.969974
2019-06-16 21:22:47,970 [salt.state       :1813][INFO    ][7711] Executing state file.managed for [/root/.pgpass]
2019-06-16 21:22:48,023 [salt.state       :300 ][INFO    ][7711] File /root/.pgpass is in the correct state
2019-06-16 21:22:48,024 [salt.state       :1951][INFO    ][7711] Completed state [/root/.pgpass] at time 21:22:48.023976 duration_in_ms=54.001
2019-06-16 21:22:48,028 [salt.state       :1780][INFO    ][7711] Running state [maas-region syncdb --noinput] at time 21:22:48.028519
2019-06-16 21:22:48,028 [salt.state       :1813][INFO    ][7711] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-16 21:22:48,029 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-16 21:22:50,178 [salt.state       :300 ][INFO    ][7711] {'pid': 7743, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: piston3, contenttypes, maasserver, sites, auth, metadataserver, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-16 21:22:50,179 [salt.state       :1951][INFO    ][7711] Completed state [maas-region syncdb --noinput] at time 21:22:50.178867 duration_in_ms=2150.346
2019-06-16 21:22:50,179 [salt.state       :2022][WARNING ][7711] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-16 21:22:50,182 [salt.state       :1780][INFO    ][7711] Running state [maas-regiond] at time 21:22:50.182221
2019-06-16 21:22:50,182 [salt.state       :1813][INFO    ][7711] Executing state service.running for [maas-regiond]
2019-06-16 21:22:50,184 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:50,222 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-16 21:22:50,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-16 21:22:50,255 [salt.state       :300 ][INFO    ][7711] The service maas-regiond is already running
2019-06-16 21:22:50,256 [salt.state       :1951][INFO    ][7711] Completed state [maas-regiond] at time 21:22:50.256317 duration_in_ms=74.097
2019-06-16 21:22:50,258 [salt.state       :1780][INFO    ][7711] Running state [bind9] at time 21:22:50.258309
2019-06-16 21:22:50,258 [salt.state       :1813][INFO    ][7711] Executing state service.running for [bind9]
2019-06-16 21:22:50,259 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:50,277 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-16 21:22:50,293 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-16 21:22:50,309 [salt.state       :300 ][INFO    ][7711] The service bind9 is already running
2019-06-16 21:22:50,309 [salt.state       :1951][INFO    ][7711] Completed state [bind9] at time 21:22:50.309682 duration_in_ms=51.373
2019-06-16 21:22:50,311 [salt.state       :1780][INFO    ][7711] Running state [apache2] at time 21:22:50.311515
2019-06-16 21:22:50,311 [salt.state       :1813][INFO    ][7711] Executing state service.running for [apache2]
2019-06-16 21:22:50,312 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-16 21:22:50,330 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-16 21:22:50,346 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-16 21:22:50,368 [salt.state       :300 ][INFO    ][7711] The service apache2 is already running
2019-06-16 21:22:50,368 [salt.state       :1951][INFO    ][7711] Completed state [apache2] at time 21:22:50.368770 duration_in_ms=57.255
2019-06-16 21:22:50,370 [salt.state       :1780][INFO    ][7711] Running state [maasng.wait_for_http_code] at time 21:22:50.370517
2019-06-16 21:22:50,370 [salt.state       :1813][INFO    ][7711] Executing state module.run for [maasng.wait_for_http_code]
2019-06-16 21:22:50,371 [salt.utils.decorators:613 ][WARNING ][7711] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:22:50,504 [salt.state       :300 ][INFO    ][7711] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-16 21:22:50,505 [salt.state       :1951][INFO    ][7711] Completed state [maasng.wait_for_http_code] at time 21:22:50.505026 duration_in_ms=134.509
2019-06-16 21:22:50,506 [salt.state       :1780][INFO    ][7711] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:22:50.505995
2019-06-16 21:22:50,506 [salt.state       :1813][INFO    ][7711] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-16 21:22:50,507 [salt.state       :300 ][INFO    ][7711] /var/lib/maas/.setup_admin exists
2019-06-16 21:22:50,507 [salt.state       :1951][INFO    ][7711] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:22:50.507298 duration_in_ms=1.303
2019-06-16 21:22:50,508 [salt.state       :1780][INFO    ][7711] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:22:50.508167
2019-06-16 21:22:50,508 [salt.state       :1813][INFO    ][7711] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:22:50,509 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7711] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:22:51,905 [salt.state       :300 ][INFO    ][7711] {'pid': 7765, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:22:51,905 [salt.state       :1951][INFO    ][7711] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:22:51.905866 duration_in_ms=1397.698
2019-06-16 21:22:51,916 [salt.state       :1780][INFO    ][7711] Running state [maas_region_boot_source_resources_mirror] at time 21:22:51.916454
2019-06-16 21:22:51,917 [salt.state       :1813][INFO    ][7711] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-16 21:22:52,012 [salt.state       :300 ][INFO    ][7711] {'changes': {}}
2019-06-16 21:22:52,013 [salt.state       :1951][INFO    ][7711] Completed state [maas_region_boot_source_resources_mirror] at time 21:22:52.013226 duration_in_ms=96.771
2019-06-16 21:22:52,014 [salt.state       :1780][INFO    ][7711] Running state [maasng.boot_resources_import] at time 21:22:52.014645
2019-06-16 21:22:52,015 [salt.state       :1813][INFO    ][7711] Executing state module.run for [maasng.boot_resources_import]
2019-06-16 21:22:52,015 [salt.utils.decorators:613 ][WARNING ][7711] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:22:52,121 [salt.loaded.ext.module.maasng:1600][INFO    ][7711] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-16 21:22:57,188 [salt.loaded.ext.module.maasng:1600][INFO    ][7711] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-16 21:23:01,112 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212301099039
2019-06-16 21:23:01,136 [salt.minion      :1432][INFO    ][7936] Starting a new job with PID 7936
2019-06-16 21:23:01,157 [salt.minion      :1711][INFO    ][7936] Returning information for job: 20190616212301099039
2019-06-16 21:23:02,250 [salt.loaded.ext.module.maasng:1600][INFO    ][7711] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-16 21:23:07,370 [salt.state       :300 ][INFO    ][7711] {'ret': True}
2019-06-16 21:23:07,371 [salt.state       :1951][INFO    ][7711] Completed state [maasng.boot_resources_import] at time 21:23:07.371106 duration_in_ms=15356.461
2019-06-16 21:23:07,372 [salt.state       :1780][INFO    ][7711] Running state [maas_region_boot_sources_selection_xenial] at time 21:23:07.372207
2019-06-16 21:23:07,372 [salt.state       :1813][INFO    ][7711] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-16 21:23:07,596 [salt.state       :300 ][INFO    ][7711] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-16 21:23:07,596 [salt.state       :1951][INFO    ][7711] Completed state [maas_region_boot_sources_selection_xenial] at time 21:23:07.596466 duration_in_ms=224.257
2019-06-16 21:23:07,597 [salt.state       :1780][INFO    ][7711] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:23:07.597887
2019-06-16 21:23:07,598 [salt.state       :1813][INFO    ][7711] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-16 21:23:07,599 [salt.utils.decorators:613 ][WARNING ][7711] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:23:07,599 [salt.loaded.ext.module.maasng:1771][INFO    ][7711] boot-sources sync initiated for ALL Rack's
2019-06-16 21:23:08,637 [salt.state       :300 ][INFO    ][7711] {'ret': True}
2019-06-16 21:23:08,638 [salt.state       :1951][INFO    ][7711] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:23:08.637988 duration_in_ms=1040.1
2019-06-16 21:23:08,640 [salt.state       :1780][INFO    ][7711] Running state [maas.process_maas_config] at time 21:23:08.640132
2019-06-16 21:23:08,640 [salt.state       :1813][INFO    ][7711] Executing state module.run for [maas.process_maas_config]
2019-06-16 21:23:08,641 [salt.utils.decorators:613 ][WARNING ][7711] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:23:08,642 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=enable_http_proxy value=True
2019-06-16 21:23:08,705 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=upstream_dns value=8.8.8.8
2019-06-16 21:23:08,769 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=commissioning_distro_series value=xenial
2019-06-16 21:23:11,666 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=default_osystem value=ubuntu
2019-06-16 21:23:11,754 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=active_discovery_interval value=600
2019-06-16 21:23:11,812 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=dnssec_validation value=no
2019-06-16 21:23:11,865 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=maas_name value=mas01
2019-06-16 21:23:11,926 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=network_discovery value=enabled
2019-06-16 21:23:12,067 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=enable_third_party_drivers value=True
2019-06-16 21:23:12,149 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=default_storage_layout value=lvm
2019-06-16 21:23:12,217 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=ntp_external_only value=True
2019-06-16 21:23:12,274 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-16 21:23:12,348 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=default_distro_series value=xenial
2019-06-16 21:23:12,412 [salt.loaded.ext.module.maas:92  ][INFO    ][7711] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-16 21:23:12,538 [salt.state       :300 ][INFO    ][7711] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-06-16 21:23:12,538 [salt.state       :1951][INFO    ][7711] Completed state [maas.process_maas_config] at time 21:23:12.538882 duration_in_ms=3898.75
2019-06-16 21:23:12,539 [salt.state       :1780][INFO    ][7711] Running state [pxe_admin] at time 21:23:12.539868
2019-06-16 21:23:12,540 [salt.state       :1813][INFO    ][7711] Executing state maasng.fabric_present for [pxe_admin]
2019-06-16 21:23:12,602 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'8pdspn', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-16 21:23:12,681 [salt.loaded.ext.module.maasng:1008][WARNING ][7711] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-16 21:23:12,682 [salt.loaded.ext.module.maasng:1011][WARNING ][7711] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-16 21:23:12,752 [salt.state       :300 ][INFO    ][7711] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-16 21:23:12,752 [salt.state       :1951][INFO    ][7711] Completed state [pxe_admin] at time 21:23:12.752469 duration_in_ms=212.6
2019-06-16 21:23:12,752 [salt.state       :1780][INFO    ][7711] Running state [vlan 0] at time 21:23:12.752909
2019-06-16 21:23:12,753 [salt.state       :1813][INFO    ][7711] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-16 21:23:12,811 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'name': u'untagged', 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'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-06-16 21:23:12,937 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'8pdspn', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-16 21:23:13,257 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8pdspn', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-16 21:23:13,358 [salt.state       :300 ][INFO    ][7711] {'new': 'Vlan untagged was updated'}
2019-06-16 21:23:13,359 [salt.state       :1951][INFO    ][7711] Completed state [vlan 0] at time 21:23:13.359247 duration_in_ms=606.336
2019-06-16 21:23:13,360 [salt.state       :1780][INFO    ][7711] Running state [192.168.11.0/24] at time 21:23:13.360792
2019-06-16 21:23:13,361 [salt.state       :1813][INFO    ][7711] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-16 21:23:13,562 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'8pdspn', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-16 21:23:13,563 [salt.loaded.ext.module.maasng:1235][WARNING ][7711] Ignoring parameter vlan:0
2019-06-16 21:23:13,634 [salt.state       :300 ][INFO    ][7711] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-16 21:23:13,635 [salt.state       :1951][INFO    ][7711] Completed state [192.168.11.0/24] at time 21:23:13.635308 duration_in_ms=274.516
2019-06-16 21:23:13,636 [salt.state       :1780][INFO    ][7711] Running state [maas_create_iprange_1] at time 21:23:13.636628
2019-06-16 21:23:13,637 [salt.state       :1813][INFO    ][7711] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-16 21:23:13,693 [salt.state       :300 ][INFO    ][7711] Iprange maas_create_iprange_1 already exist.
2019-06-16 21:23:13,694 [salt.state       :1951][INFO    ][7711] Completed state [maas_create_iprange_1] at time 21:23:13.694267 duration_in_ms=57.639
2019-06-16 21:23:13,694 [salt.state       :1780][INFO    ][7711] Running state [vlan 0] at time 21:23:13.694619
2019-06-16 21:23:13,694 [salt.state       :1813][INFO    ][7711] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-16 21:23:13,759 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'name': u'untagged', 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'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-06-16 21:23:13,877 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8pdspn', u'name': u'untagged', 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'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-06-16 21:23:14,105 [salt.loaded.ext.module.maasng:945 ][INFO    ][7711] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 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'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'8pdspn', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-16 21:23:14,184 [salt.state       :300 ][INFO    ][7711] {'new': 'Vlan untagged was updated'}
2019-06-16 21:23:14,184 [salt.state       :1951][INFO    ][7711] Completed state [vlan 0] at time 21:23:14.184448 duration_in_ms=489.828
2019-06-16 21:23:14,185 [salt.state       :1780][INFO    ][7711] Running state [opnfv] at time 21:23:14.185345
2019-06-16 21:23:14,185 [salt.state       :1813][INFO    ][7711] Executing state maasng.sshkey_present for [opnfv]
2019-06-16 21:23:14,257 [salt.loaded.ext.module.maasng:1903][INFO    ][7711] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-06-16 21:23:14,258 [salt.state       :300 ][INFO    ][7711] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-16 21:23:14,258 [salt.state       :1951][INFO    ][7711] Completed state [opnfv] at time 21:23:14.258572 duration_in_ms=73.227
2019-06-16 21:23:14,261 [salt.minion      :1711][INFO    ][7711] Returning information for job: 20190616212246076501
2019-06-16 21:23:14,895 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616212314884454
2019-06-16 21:23:14,917 [salt.minion      :1432][INFO    ][8326] Starting a new job with PID 8326
2019-06-16 21:23:18,423 [salt.state       :915 ][INFO    ][8326] Loading fresh modules for state activity
2019-06-16 21:23:18,475 [salt.state       :1780][INFO    ][8326] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:23:18.475639
2019-06-16 21:23:18,475 [salt.state       :1813][INFO    ][8326] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:23:18,477 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8326] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:23:19,853 [salt.state       :300 ][INFO    ][8326] {'pid': 8349, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:23:19,853 [salt.state       :1951][INFO    ][8326] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:23:19.853558 duration_in_ms=1377.919
2019-06-16 21:23:19,854 [salt.state       :1780][INFO    ][8326] Running state [maas.process_machines] at time 21:23:19.854731
2019-06-16 21:23:19,854 [salt.state       :1813][INFO    ][8326] Executing state module.run for [maas.process_machines]
2019-06-16 21:23:19,855 [salt.utils.decorators:613 ][WARNING ][8326] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:23:20,400 [salt.loaded.ext.module.maas:412 ][WARNING ][8326] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:23:20,400 [salt.loaded.ext.module.maas:92  ][INFO    ][8326] 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=8y886n architecture=amd64/generic power_parameters_power_user=admin
2019-06-16 21:23:21,748 [salt.loaded.ext.module.maas:412 ][WARNING ][8326] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:23:21,750 [salt.loaded.ext.module.maas:92  ][INFO    ][8326] 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=awmhn3 architecture=amd64/generic power_parameters_power_user=admin
2019-06-16 21:23:23,036 [salt.loaded.ext.module.maas:412 ][WARNING ][8326] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:23:23,037 [salt.loaded.ext.module.maas:92  ][INFO    ][8326] 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=fgnsg3 architecture=amd64/generic power_parameters_power_user=admin
2019-06-16 21:23:24,311 [salt.loaded.ext.module.maas:412 ][WARNING ][8326] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:23:24,312 [salt.loaded.ext.module.maas:92  ][INFO    ][8326] 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=6hqtcs architecture=amd64/generic power_parameters_power_user=admin
2019-06-16 21:23:25,312 [salt.loaded.ext.module.maas:412 ][WARNING ][8326] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-16 21:23:25,313 [salt.loaded.ext.module.maas:92  ][INFO    ][8326] 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=sbnnkc architecture=amd64/generic power_parameters_power_user=admin
2019-06-16 21:23:26,505 [salt.state       :300 ][INFO    ][8326] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-16 21:23:26,506 [salt.state       :1951][INFO    ][8326] Completed state [maas.process_machines] at time 21:23:26.505935 duration_in_ms=6651.202
2019-06-16 21:23:26,509 [salt.minion      :1711][INFO    ][8326] Returning information for job: 20190616212314884454
2019-06-16 21:23:59,639 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616212359630117
2019-06-16 21:23:59,664 [salt.minion      :1432][INFO    ][8597] Starting a new job with PID 8597
2019-06-16 21:24:03,226 [salt.state       :915 ][INFO    ][8597] Loading fresh modules for state activity
2019-06-16 21:24:03,316 [salt.state       :1780][INFO    ][8597] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:03.316216
2019-06-16 21:24:03,316 [salt.state       :1813][INFO    ][8597] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:24:03,318 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8597] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:24:04,843 [salt.state       :300 ][INFO    ][8597] {'pid': 8604, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:24:04,843 [salt.state       :1951][INFO    ][8597] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:04.843827 duration_in_ms=1527.611
2019-06-16 21:24:04,846 [salt.state       :1780][INFO    ][8597] Running state [maas.wait_for_machine_status] at time 21:24:04.846424
2019-06-16 21:24:04,847 [salt.state       :1813][INFO    ][8597] Executing state module.run for [maas.wait_for_machine_status]
2019-06-16 21:24:04,847 [salt.utils.decorators:613 ][WARNING ][8597] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:24:08,011 [salt.loaded.ext.module.maas:993 ][INFO    ][8597] Machine sbnnkc mark broken
2019-06-16 21:24:08,639 [salt.loaded.ext.module.maas:996 ][INFO    ][8597] Machine sbnnkc mark fixed
2019-06-16 21:24:09,842 [salt.loaded.ext.module.maas:684 ][INFO    ][8597] deploymachines hwe_kernel=hwe-16.04 system_id=sbnnkc distro_series=xenial
2019-06-16 21:24:12,115 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1492.74344397s left)
2019-06-16 21:24:14,736 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212414723556
2019-06-16 21:24:14,762 [salt.minion      :1432][INFO    ][8699] Starting a new job with PID 8699
2019-06-16 21:24:14,788 [salt.minion      :1711][INFO    ][8699] Returning information for job: 20190616212414723556
2019-06-16 21:24:44,792 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212444782802
2019-06-16 21:24:44,811 [salt.minion      :1432][INFO    ][8722] Starting a new job with PID 8722
2019-06-16 21:24:44,832 [salt.minion      :1711][INFO    ][8722] Returning information for job: 20190616212444782802
2019-06-16 21:24:45,550 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1459.30838799s left)
2019-06-16 21:25:14,920 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212514856788
2019-06-16 21:25:14,942 [salt.minion      :1432][INFO    ][8774] Starting a new job with PID 8774
2019-06-16 21:25:14,964 [salt.minion      :1711][INFO    ][8774] Returning information for job: 20190616212514856788
2019-06-16 21:25:18,838 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1426.02038789s left)
2019-06-16 21:25:44,964 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212544949722
2019-06-16 21:25:44,988 [salt.minion      :1432][INFO    ][8795] Starting a new job with PID 8795
2019-06-16 21:25:45,015 [salt.minion      :1711][INFO    ][8795] Returning information for job: 20190616212544949722
2019-06-16 21:25:51,854 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1393.00433397s left)
2019-06-16 21:26:15,020 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212615007833
2019-06-16 21:26:15,043 [salt.minion      :1432][INFO    ][8948] Starting a new job with PID 8948
2019-06-16 21:26:15,070 [salt.minion      :1711][INFO    ][8948] Returning information for job: 20190616212615007833
2019-06-16 21:26:25,425 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1359.43275285s left)
2019-06-16 21:26:45,078 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212645065323
2019-06-16 21:26:45,103 [salt.minion      :1432][INFO    ][8974] Starting a new job with PID 8974
2019-06-16 21:26:45,130 [salt.minion      :1711][INFO    ][8974] Returning information for job: 20190616212645065323
2019-06-16 21:26:58,514 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1326.34370995s left)
2019-06-16 21:27:15,148 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212715132511
2019-06-16 21:27:15,172 [salt.minion      :1432][INFO    ][9159] Starting a new job with PID 9159
2019-06-16 21:27:15,197 [salt.minion      :1711][INFO    ][9159] Returning information for job: 20190616212715132511
2019-06-16 21:27:32,018 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1292.83996797s left)
2019-06-16 21:27:45,207 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212745195169
2019-06-16 21:27:45,232 [salt.minion      :1432][INFO    ][9179] Starting a new job with PID 9179
2019-06-16 21:27:45,257 [salt.minion      :1711][INFO    ][9179] Returning information for job: 20190616212745195169
2019-06-16 21:28:05,504 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1259.35345888s left)
2019-06-16 21:28:15,271 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212815258785
2019-06-16 21:28:15,294 [salt.minion      :1432][INFO    ][9275] Starting a new job with PID 9275
2019-06-16 21:28:15,319 [salt.minion      :1711][INFO    ][9275] Returning information for job: 20190616212815258785
2019-06-16 21:28:39,061 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1225.79711795s left)
2019-06-16 21:28:45,341 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212845328964
2019-06-16 21:28:45,366 [salt.minion      :1432][INFO    ][9304] Starting a new job with PID 9304
2019-06-16 21:28:45,392 [salt.minion      :1711][INFO    ][9304] Returning information for job: 20190616212845328964
2019-06-16 21:29:12,602 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1192.25617385s left)
2019-06-16 21:29:15,418 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212915405916
2019-06-16 21:29:15,441 [salt.minion      :1432][INFO    ][9463] Starting a new job with PID 9463
2019-06-16 21:29:15,468 [salt.minion      :1711][INFO    ][9463] Returning information for job: 20190616212915405916
2019-06-16 21:29:45,495 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616212945482220
2019-06-16 21:29:45,518 [salt.minion      :1432][INFO    ][9491] Starting a new job with PID 9491
2019-06-16 21:29:45,542 [salt.minion      :1711][INFO    ][9491] Returning information for job: 20190616212945482220
2019-06-16 21:29:45,782 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1159.07579303s left)
2019-06-16 21:30:15,578 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616213015565631
2019-06-16 21:30:15,602 [salt.minion      :1432][INFO    ][9607] Starting a new job with PID 9607
2019-06-16 21:30:15,629 [salt.minion      :1711][INFO    ][9607] Returning information for job: 20190616213015565631
2019-06-16 21:30:19,137 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1125.72126794s left)
2019-06-16 21:30:45,669 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616213045655906
2019-06-16 21:30:45,693 [salt.minion      :1432][INFO    ][9631] Starting a new job with PID 9631
2019-06-16 21:30:45,717 [salt.minion      :1711][INFO    ][9631] Returning information for job: 20190616213045655906
2019-06-16 21:30:52,623 [salt.loaded.ext.module.maas:1023][INFO    ][8597] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1092.23492002s left)
2019-06-16 21:31:15,765 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command saltutil.find_job with jid 20190616213115752292
2019-06-16 21:31:15,789 [salt.minion      :1432][INFO    ][9706] Starting a new job with PID 9706
2019-06-16 21:31:15,816 [salt.minion      :1711][INFO    ][9706] Returning information for job: 20190616213115752292
2019-06-16 21:31:26,022 [salt.state       :300 ][INFO    ][8597] {'ret': True}
2019-06-16 21:31:26,023 [salt.state       :1951][INFO    ][8597] Completed state [maas.wait_for_machine_status] at time 21:31:26.023223 duration_in_ms=441176.798
2019-06-16 21:31:26,026 [salt.minion      :1711][INFO    ][8597] Returning information for job: 20190616212359630117
2019-06-16 21:31:26,667 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616213126654463
2019-06-16 21:31:26,689 [salt.minion      :1432][INFO    ][9734] Starting a new job with PID 9734
2019-06-16 21:31:30,401 [salt.state       :915 ][INFO    ][9734] Loading fresh modules for state activity
2019-06-16 21:31:30,536 [salt.state       :1780][INFO    ][9734] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:30.536633
2019-06-16 21:31:30,536 [salt.state       :1813][INFO    ][9734] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:31:30,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9734] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:31:31,904 [salt.state       :300 ][INFO    ][9734] {'pid': 9749, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:31:31,905 [salt.state       :1951][INFO    ][9734] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:31.904999 duration_in_ms=1368.367
2019-06-16 21:31:31,906 [salt.state       :1780][INFO    ][9734] Running state [maas_machines_storage_cmp002_lvm] at time 21:31:31.906209
2019-06-16 21:31:31,906 [salt.state       :1813][INFO    ][9734] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-16 21:31:32,619 [salt.state       :300 ][INFO    ][9734] Machine cmp002 is not in Ready state.
2019-06-16 21:31:32,619 [salt.state       :1951][INFO    ][9734] Completed state [maas_machines_storage_cmp002_lvm] at time 21:31:32.619675 duration_in_ms=713.464
2019-06-16 21:31:32,620 [salt.state       :1780][INFO    ][9734] Running state [maas_machines_storage_cmp001_lvm] at time 21:31:32.620283
2019-06-16 21:31:32,620 [salt.state       :1813][INFO    ][9734] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-16 21:31:33,328 [salt.state       :300 ][INFO    ][9734] Machine cmp001 is not in Ready state.
2019-06-16 21:31:33,329 [salt.state       :1951][INFO    ][9734] Completed state [maas_machines_storage_cmp001_lvm] at time 21:31:33.329052 duration_in_ms=708.768
2019-06-16 21:31:33,333 [salt.minion      :1711][INFO    ][9734] Returning information for job: 20190616213126654463
2019-06-16 21:31:33,956 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616213133943407
2019-06-16 21:31:33,981 [salt.minion      :1432][INFO    ][9759] Starting a new job with PID 9759
2019-06-16 21:31:34,759 [salt.state       :915 ][INFO    ][9759] Loading fresh modules for state activity
2019-06-16 21:31:34,849 [salt.state       :1780][INFO    ][9759] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:34.849405
2019-06-16 21:31:34,849 [salt.state       :1813][INFO    ][9759] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:31:34,852 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9759] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:31:36,140 [salt.state       :300 ][INFO    ][9759] {'pid': 9767, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:31:36,140 [salt.state       :1951][INFO    ][9759] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:36.140528 duration_in_ms=1291.123
2019-06-16 21:31:36,141 [salt.state       :1780][INFO    ][9759] Running state [maas.deploy_machines] at time 21:31:36.141719
2019-06-16 21:31:36,141 [salt.state       :1813][INFO    ][9759] Executing state module.run for [maas.deploy_machines]
2019-06-16 21:31:36,142 [salt.utils.decorators:613 ][WARNING ][9759] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:31:36,875 [salt.state       :300 ][INFO    ][9759] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-16 21:31:36,875 [salt.state       :1951][INFO    ][9759] Completed state [maas.deploy_machines] at time 21:31:36.875815 duration_in_ms=734.092
2019-06-16 21:31:36,879 [salt.minion      :1711][INFO    ][9759] Returning information for job: 20190616213133943407
2019-06-16 21:31:37,520 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command state.apply with jid 20190616213137506522
2019-06-16 21:31:37,543 [salt.minion      :1432][INFO    ][9776] Starting a new job with PID 9776
2019-06-16 21:31:38,303 [salt.state       :915 ][INFO    ][9776] Loading fresh modules for state activity
2019-06-16 21:31:38,395 [salt.state       :1780][INFO    ][9776] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:38.395766
2019-06-16 21:31:38,396 [salt.state       :1813][INFO    ][9776] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-16 21:31:38,398 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9776] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-16 21:31:39,775 [salt.state       :300 ][INFO    ][9776] {'pid': 9783, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-16 21:31:39,776 [salt.state       :1951][INFO    ][9776] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:31:39.776252 duration_in_ms=1380.485
2019-06-16 21:31:39,779 [salt.state       :1780][INFO    ][9776] Running state [maas.wait_for_machine_status] at time 21:31:39.779414
2019-06-16 21:31:39,780 [salt.state       :1813][INFO    ][9776] Executing state module.run for [maas.wait_for_machine_status]
2019-06-16 21:31:39,780 [salt.utils.decorators:613 ][WARNING ][9776] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-16 21:31:43,268 [salt.state       :300 ][INFO    ][9776] {'ret': True}
2019-06-16 21:31:43,268 [salt.state       :1951][INFO    ][9776] Completed state [maas.wait_for_machine_status] at time 21:31:43.268874 duration_in_ms=3489.459
2019-06-16 21:31:43,272 [salt.minion      :1711][INFO    ][9776] Returning information for job: 20190616213137506522
2019-06-16 22:01:18,118 [salt.utils.schedule:1377][INFO    ][914] Running scheduled job: __mine_interval
2019-06-16 22:57:59,502 [salt.minion      :1308][INFO    ][914] User sudo_ubuntu Executing command cp.push_dir with jid 20190616225759488833
2019-06-16 22:57:59,529 [salt.minion      :1432][INFO    ][16015] Starting a new job with PID 16015
