2019-05-16 20:13:25,772 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-16 20:14:15,819 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-16 20:15:05,858 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-16 20:15:55,901 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-16 20:16:45,948 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-16 20:18:55,396 [salt.utils.decorators:613 ][WARNING ][2720] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:18:55,987 [salt.utils.decorators:613 ][WARNING ][2720] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:18:57,984 [salt.loaded.int.states.file:2298][WARNING ][2859] 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-05-16 20:19:03,566 [salt.state       :2022][WARNING ][2972] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-16 20:19:06,329 [salt.utils.decorators:613 ][WARNING ][2972] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:19:19,632 [salt.utils.decorators:613 ][WARNING ][2972] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:19:51,313 [salt.utils.decorators:613 ][WARNING ][2972] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:19:52,461 [salt.utils.decorators:613 ][WARNING ][2972] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:19:56,380 [salt.loaded.ext.module.maasng:1008][WARNING ][2972] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-16 20:19:56,380 [salt.loaded.ext.module.maasng:1011][WARNING ][2972] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-16 20:19:57,069 [salt.loaded.ext.module.maasng:1235][WARNING ][2972] Ignoring parameter vlan:0
2019-05-16 20:20:03,699 [salt.utils.decorators:613 ][WARNING ][5715] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:20:03,747 [salt.loaded.ext.module.maas:412 ][WARNING ][5715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:20:05,215 [salt.loaded.ext.module.maas:412 ][WARNING ][5715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:20:06,580 [salt.loaded.ext.module.maas:412 ][WARNING ][5715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:20:07,963 [salt.loaded.ext.module.maas:412 ][WARNING ][5715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:20:09,269 [salt.loaded.ext.module.maas:412 ][WARNING ][5715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:20:13,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6379] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-16 20:20:13,942 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6379] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-16 20:20:13,965 [salt.utils.parsers:1051][WARNING ][354] Minion received a SIGTERM. Exiting.
2019-05-16 20:20:15,005 [salt.cli.daemons :293 ][INFO    ][6428] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-05-16 20:20:15,103 [salt.cli.daemons :82  ][INFO    ][6428] Starting up the Salt Minion
2019-05-16 20:20:15,103 [salt.utils.event :1017][INFO    ][6428] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-05-16 20:20:16,001 [salt.minion      :976 ][INFO    ][6428] Creating minion process manager
2019-05-16 20:20:17,441 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6428] Executing command ['date', '+%z'] in directory '/root'
2019-05-16 20:20:17,460 [salt.utils.schedule:568 ][INFO    ][6428] Updating job settings for scheduled job: __mine_interval
2019-05-16 20:20:17,462 [salt.minion      :1108][INFO    ][6428] Added mine.update to scheduler
2019-05-16 20:20:17,465 [salt.minion      :1975][INFO    ][6428] Minion is starting as user 'root'
2019-05-16 20:20:17,476 [salt.minion      :2336][INFO    ][6428] Minion is ready to receive requests!
2019-05-16 20:20:41,759 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516202041746462
2019-05-16 20:20:41,782 [salt.minion      :1432][INFO    ][6526] Starting a new job with PID 6526
2019-05-16 20:20:45,571 [salt.state       :915 ][INFO    ][6526] Loading fresh modules for state activity
2019-05-16 20:20:45,622 [salt.fileclient  :1219][INFO    ][6526] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-16 20:20:45,668 [salt.state       :1780][INFO    ][6526] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:20:45.668467
2019-05-16 20:20:45,668 [salt.state       :1813][INFO    ][6526] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:20:45,671 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6526] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:20:47,079 [salt.state       :300 ][INFO    ][6526] {'pid': 6533, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:20:47,080 [salt.state       :1951][INFO    ][6526] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:20:47.080003 duration_in_ms=1411.537
2019-05-16 20:20:47,081 [salt.state       :1780][INFO    ][6526] Running state [maas.wait_for_machine_status] at time 20:20:47.081507
2019-05-16 20:20:47,081 [salt.state       :1813][INFO    ][6526] Executing state module.run for [maas.wait_for_machine_status]
2019-05-16 20:20:47,082 [salt.utils.decorators:613 ][WARNING ][6526] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:20:47,960 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.12618589s left)
2019-05-16 20:20:56,853 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202056838707
2019-05-16 20:20:56,876 [salt.minion      :1432][INFO    ][6545] Starting a new job with PID 6545
2019-05-16 20:20:56,899 [salt.minion      :1711][INFO    ][6545] Returning information for job: 20190516202056838707
2019-05-16 20:21:18,981 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.10543704s left)
2019-05-16 20:21:26,910 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202126893958
2019-05-16 20:21:26,932 [salt.minion      :1432][INFO    ][6597] Starting a new job with PID 6597
2019-05-16 20:21:26,957 [salt.minion      :1711][INFO    ][6597] Returning information for job: 20190516202126893958
2019-05-16 20:21:50,076 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.01010108s left)
2019-05-16 20:21:56,956 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202156945907
2019-05-16 20:21:56,975 [salt.minion      :1432][INFO    ][6735] Starting a new job with PID 6735
2019-05-16 20:21:56,993 [salt.minion      :1711][INFO    ][6735] Returning information for job: 20190516202156945907
2019-05-16 20:22:21,524 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.56224489s left)
2019-05-16 20:22:27,001 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202226985728
2019-05-16 20:22:27,024 [salt.minion      :1432][INFO    ][7027] Starting a new job with PID 7027
2019-05-16 20:22:27,047 [salt.minion      :1711][INFO    ][7027] Returning information for job: 20190516202226985728
2019-05-16 20:22:53,235 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.85155702s left)
2019-05-16 20:22:57,063 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202257050073
2019-05-16 20:22:57,084 [salt.minion      :1432][INFO    ][7172] Starting a new job with PID 7172
2019-05-16 20:22:57,108 [salt.minion      :1711][INFO    ][7172] Returning information for job: 20190516202257050073
2019-05-16 20:23:25,034 [salt.loaded.ext.module.maas:1023][INFO    ][6526] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.05229902s left)
2019-05-16 20:23:27,125 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202327111646
2019-05-16 20:23:27,147 [salt.minion      :1432][INFO    ][7662] Starting a new job with PID 7662
2019-05-16 20:23:27,169 [salt.minion      :1711][INFO    ][7662] Returning information for job: 20190516202327111646
2019-05-16 20:23:57,190 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202357174758
2019-05-16 20:23:57,213 [salt.minion      :1432][INFO    ][7858] Starting a new job with PID 7858
2019-05-16 20:23:57,235 [salt.minion      :1711][INFO    ][7858] Returning information for job: 20190516202357174758
2019-05-16 20:23:58,294 [salt.state       :300 ][INFO    ][6526] {'ret': True}
2019-05-16 20:23:58,295 [salt.state       :1951][INFO    ][6526] Completed state [maas.wait_for_machine_status] at time 20:23:58.295290 duration_in_ms=191213.78
2019-05-16 20:23:58,299 [salt.minion      :1711][INFO    ][6526] Returning information for job: 20190516202041746462
2019-05-16 20:23:58,963 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516202358951233
2019-05-16 20:23:58,979 [salt.minion      :1432][INFO    ][7888] Starting a new job with PID 7888
2019-05-16 20:24:02,715 [salt.state       :915 ][INFO    ][7888] Loading fresh modules for state activity
2019-05-16 20:24:02,768 [salt.fileclient  :1219][INFO    ][7888] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-16 20:24:02,855 [salt.state       :1780][INFO    ][7888] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:02.855217
2019-05-16 20:24:02,855 [salt.state       :1813][INFO    ][7888] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:24:02,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7888] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:24:04,297 [salt.state       :300 ][INFO    ][7888] {'pid': 7914, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:24:04,298 [salt.state       :1951][INFO    ][7888] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:04.298219 duration_in_ms=1443.002
2019-05-16 20:24:04,301 [salt.state       :1780][INFO    ][7888] Running state [maas_machines_storage_cmp002_lvm] at time 20:24:04.301318
2019-05-16 20:24:04,301 [salt.state       :1813][INFO    ][7888] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-16 20:24:05,614 [salt.loaded.ext.module.maasng:610 ][INFO    ][7888] kxdama
2019-05-16 20:24:05,615 [salt.loaded.ext.module.maasng:626 ][INFO    ][7888] sda
2019-05-16 20:24:06,506 [salt.loaded.ext.module.maasng:361 ][INFO    ][7888] kxdama
2019-05-16 20:24:06,620 [salt.loaded.ext.module.maasng:367 ][INFO    ][7888] [{u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'name': u'sda', u'system_id': u'kxdama', u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'0fc229fc-cbfb-447c-9c7a-b4090fb74b78', u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kxdama', u'filesystem': {u'uuid': u'7a0e9c98-efa9-4e18-901c-73db23bdccbb', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 5, u'size': 2397992648704}], u'type': u'physical', u'id': 4, u'size': 2397998940160}, {u'model': None, u'partition_table_type': None, u'block_size': 4096, u'uuid': u'd1729dd8-6708-4cf8-b8b9-6e15cb2513ec', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'filesystem': {u'uuid': u'f608f284-5089-4853-a7d7-ea73574839de', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'kxdama', u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/10/', u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 10, u'size': 2397988454400}]
2019-05-16 20:24:06,621 [salt.loaded.ext.module.maasng:632 ][INFO    ][7888] vgroot
2019-05-16 20:24:06,621 [salt.loaded.ext.module.maasng:635 ][INFO    ][7888] lvroot
2019-05-16 20:24:06,621 [salt.loaded.ext.module.maasng:639 ][INFO    ][7888] 107374182400
2019-05-16 20:24:07,369 [salt.loaded.ext.module.maasng:645 ][INFO    ][7888] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'ip_addresses': [u'192.168.11.41'], u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'37f3f62d-69a0-4b92-94c6-ffdd0069ef35', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kxdama', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'da072a0c-6acb-4479-8dd9-d47b5b80f154', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kxdama', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/'}, u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'disable_ipv4': False, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'address_ttl': None, u'system_id': u'kxdama', u'power_state': u'on', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'uuid': u'7767e532-2c73-4dc0-b497-1af01cf6c9a7', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ec291281-8d61-4e05-96db-81fc306606db', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'kxdama', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/12/'}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'37f3f62d-69a0-4b92-94c6-ffdd0069ef35', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kxdama', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'da072a0c-6acb-4479-8dd9-d47b5b80f154', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kxdama', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/'}, {u'size': 107374182400, u'model': None, u'uuid': u'7767e532-2c73-4dc0-b497-1af01cf6c9a7', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ec291281-8d61-4e05-96db-81fc306606db', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'kxdama', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/12/'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'kxdama', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', 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'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'id': 34, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'kxdama', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/interfaces/4/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 35, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 18, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'kxdama', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 19, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'kxdama', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/interfaces/19/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 20, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'kxdama', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'37f3f62d-69a0-4b92-94c6-ffdd0069ef35', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kxdama', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'da072a0c-6acb-4479-8dd9-d47b5b80f154', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kxdama', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/blockdevices/4/'}], 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'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'id': 34, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'kxdama', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kxdama/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/kxdama/'}
2019-05-16 20:24:07,371 [salt.state       :300 ][INFO    ][7888] {'new': {'storage_layout': 'lvm'}}
2019-05-16 20:24:07,372 [salt.state       :1951][INFO    ][7888] Completed state [maas_machines_storage_cmp002_lvm] at time 20:24:07.372128 duration_in_ms=3070.809
2019-05-16 20:24:07,372 [salt.state       :1780][INFO    ][7888] Running state [maas_machines_storage_cmp001_lvm] at time 20:24:07.372670
2019-05-16 20:24:07,373 [salt.state       :1813][INFO    ][7888] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-16 20:24:08,872 [salt.loaded.ext.module.maasng:610 ][INFO    ][7888] 6fqcmp
2019-05-16 20:24:08,872 [salt.loaded.ext.module.maasng:626 ][INFO    ][7888] sda
2019-05-16 20:24:09,585 [salt.loaded.ext.module.maasng:361 ][INFO    ][7888] 6fqcmp
2019-05-16 20:24:09,712 [salt.loaded.ext.module.maasng:367 ][INFO    ][7888] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'4bd78f15-1de4-4dd1-88ec-9d84d648a40f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6fqcmp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'29e6042f-232a-41ad-a1cf-1192ebcd312f', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/partition/1'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'6fqcmp', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/'}, {u'size': 2397988454400, u'model': None, u'uuid': u'7145d918-4fbe-46c1-a152-1b789aab0989', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'1216f730-852c-4e30-8aac-9ab647d8010a', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'6fqcmp', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/7/'}]
2019-05-16 20:24:09,713 [salt.loaded.ext.module.maasng:632 ][INFO    ][7888] vgroot
2019-05-16 20:24:09,713 [salt.loaded.ext.module.maasng:635 ][INFO    ][7888] lvroot
2019-05-16 20:24:09,714 [salt.loaded.ext.module.maasng:639 ][INFO    ][7888] 107374182400
2019-05-16 20:24:10,482 [salt.loaded.ext.module.maasng:645 ][INFO    ][7888] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 17, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'6fqcmp', u'params': u'', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/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'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'name': u'sda', u'system_id': u'6fqcmp', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'0777f052-f14e-4e6c-a68f-a6e9dbf7a1ff', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6fqcmp', u'filesystem': {u'uuid': u'0016acf1-4859-4a61-b07f-0cfa4c6cb98a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'size': 2397998940160}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 4, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'6fqcmp', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'model': None, u'partition_table_type': None, u'block_size': 4096, u'uuid': u'09002e7d-5eb5-4164-85cc-f5e8c76a6dcd', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'filesystem': {u'uuid': u'49516d11-2633-4260-8931-a848b101b3ae', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'6fqcmp', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/13/', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 13, u'size': 107374182400}], u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'name': u'sda', u'system_id': u'6fqcmp', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'0777f052-f14e-4e6c-a68f-a6e9dbf7a1ff', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6fqcmp', u'filesystem': {u'uuid': u'0016acf1-4859-4a61-b07f-0cfa4c6cb98a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'size': 2397998940160}, {u'model': None, u'partition_table_type': None, u'block_size': 4096, u'uuid': u'09002e7d-5eb5-4164-85cc-f5e8c76a6dcd', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'filesystem': {u'uuid': u'49516d11-2633-4260-8931-a848b101b3ae', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'6fqcmp', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/13/', u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 13, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'6fqcmp', u'id': 8}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'name': u'sda', u'system_id': u'6fqcmp', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'0777f052-f14e-4e6c-a68f-a6e9dbf7a1ff', u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/blockdevices/2/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6fqcmp', u'filesystem': {u'uuid': u'0016acf1-4859-4a61-b07f-0cfa4c6cb98a', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 17, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'6fqcmp', u'params': u'', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 9, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'6fqcmp', u'params': u'', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/interfaces/9/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 21, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 11, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'6fqcmp', u'params': u'', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/interfaces/11/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 23, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 12, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'6fqcmp', u'params': u'', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6fqcmp/interfaces/12/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/6fqcmp/'}
2019-05-16 20:24:10,485 [salt.state       :300 ][INFO    ][7888] {'new': {'storage_layout': 'lvm'}}
2019-05-16 20:24:10,485 [salt.state       :1951][INFO    ][7888] Completed state [maas_machines_storage_cmp001_lvm] at time 20:24:10.485819 duration_in_ms=3113.145
2019-05-16 20:24:10,491 [salt.minion      :1711][INFO    ][7888] Returning information for job: 20190516202358951233
2019-05-16 20:24:11,145 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516202411131946
2019-05-16 20:24:11,166 [salt.minion      :1432][INFO    ][8030] Starting a new job with PID 8030
2019-05-16 20:24:11,865 [salt.state       :915 ][INFO    ][8030] Loading fresh modules for state activity
2019-05-16 20:24:11,917 [salt.fileclient  :1219][INFO    ][8030] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-16 20:24:11,958 [salt.state       :1780][INFO    ][8030] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:11.958275
2019-05-16 20:24:11,958 [salt.state       :1813][INFO    ][8030] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:24:11,960 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8030] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:24:13,522 [salt.state       :300 ][INFO    ][8030] {'pid': 8046, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:24:13,523 [salt.state       :1951][INFO    ][8030] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:13.523026 duration_in_ms=1564.751
2019-05-16 20:24:13,525 [salt.state       :1780][INFO    ][8030] Running state [maas.deploy_machines] at time 20:24:13.525667
2019-05-16 20:24:13,526 [salt.state       :1813][INFO    ][8030] Executing state module.run for [maas.deploy_machines]
2019-05-16 20:24:13,527 [salt.utils.decorators:613 ][WARNING ][8030] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:24:14,263 [salt.loaded.ext.module.maas:684 ][INFO    ][8030] deploymachines hwe_kernel=hwe-16.04 system_id=kxdama distro_series=xenial
2019-05-16 20:24:16,894 [salt.loaded.ext.module.maas:684 ][INFO    ][8030] deploymachines hwe_kernel=hwe-16.04 system_id=6fqcmp distro_series=xenial
2019-05-16 20:24:19,414 [salt.loaded.ext.module.maas:684 ][INFO    ][8030] deploymachines hwe_kernel=hwe-16.04 system_id=t48grb distro_series=xenial
2019-05-16 20:24:21,864 [salt.loaded.ext.module.maas:684 ][INFO    ][8030] deploymachines hwe_kernel=hwe-16.04 system_id=redr88 distro_series=xenial
2019-05-16 20:24:24,446 [salt.loaded.ext.module.maas:684 ][INFO    ][8030] deploymachines hwe_kernel=hwe-16.04 system_id=d7srrm distro_series=xenial
2019-05-16 20:24:26,247 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202426234214
2019-05-16 20:24:26,268 [salt.minion      :1432][INFO    ][8310] Starting a new job with PID 8310
2019-05-16 20:24:26,298 [salt.minion      :1711][INFO    ][8310] Returning information for job: 20190516202426234214
2019-05-16 20:24:26,956 [salt.state       :300 ][INFO    ][8030] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-16 20:24:26,957 [salt.state       :1951][INFO    ][8030] Completed state [maas.deploy_machines] at time 20:24:26.957340 duration_in_ms=13431.671
2019-05-16 20:24:26,961 [salt.minion      :1711][INFO    ][8030] Returning information for job: 20190516202411131946
2019-05-16 20:24:27,604 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516202427591829
2019-05-16 20:24:27,626 [salt.minion      :1432][INFO    ][8324] Starting a new job with PID 8324
2019-05-16 20:24:31,486 [salt.state       :915 ][INFO    ][8324] Loading fresh modules for state activity
2019-05-16 20:24:31,539 [salt.fileclient  :1219][INFO    ][8324] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-16 20:24:31,582 [salt.state       :1780][INFO    ][8324] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:31.582426
2019-05-16 20:24:31,582 [salt.state       :1813][INFO    ][8324] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:24:31,584 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8324] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:24:33,025 [salt.state       :300 ][INFO    ][8324] {'pid': 8344, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:24:33,026 [salt.state       :1951][INFO    ][8324] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:24:33.026160 duration_in_ms=1443.735
2019-05-16 20:24:33,027 [salt.state       :1780][INFO    ][8324] Running state [maas.wait_for_machine_status] at time 20:24:33.027701
2019-05-16 20:24:33,027 [salt.state       :1813][INFO    ][8324] Executing state module.run for [maas.wait_for_machine_status]
2019-05-16 20:24:33,028 [salt.utils.decorators:613 ][WARNING ][8324] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:24:36,423 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.60964513s left)
2019-05-16 20:24:42,665 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202442648805
2019-05-16 20:24:42,687 [salt.minion      :1432][INFO    ][8355] Starting a new job with PID 8355
2019-05-16 20:24:42,713 [salt.minion      :1711][INFO    ][8355] Returning information for job: 20190516202442648805
2019-05-16 20:25:09,885 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.14711118s left)
2019-05-16 20:25:12,718 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202512706121
2019-05-16 20:25:12,740 [salt.minion      :1432][INFO    ][8409] Starting a new job with PID 8409
2019-05-16 20:25:12,763 [salt.minion      :1711][INFO    ][8409] Returning information for job: 20190516202512706121
2019-05-16 20:25:42,761 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202542748866
2019-05-16 20:25:42,783 [salt.minion      :1432][INFO    ][8428] Starting a new job with PID 8428
2019-05-16 20:25:42,807 [salt.minion      :1711][INFO    ][8428] Returning information for job: 20190516202542748866
2019-05-16 20:25:43,548 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.48491001s left)
2019-05-16 20:26:12,794 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202612782279
2019-05-16 20:26:12,814 [salt.minion      :1432][INFO    ][8575] Starting a new job with PID 8575
2019-05-16 20:26:12,836 [salt.minion      :1711][INFO    ][8575] Returning information for job: 20190516202612782279
2019-05-16 20:26:17,013 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.019979s left)
2019-05-16 20:26:42,847 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202642834889
2019-05-16 20:26:42,869 [salt.minion      :1432][INFO    ][8735] Starting a new job with PID 8735
2019-05-16 20:26:42,892 [salt.minion      :1711][INFO    ][8735] Returning information for job: 20190516202642834889
2019-05-16 20:26:50,207 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.82545805s left)
2019-05-16 20:27:12,904 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202712889748
2019-05-16 20:27:12,926 [salt.minion      :1432][INFO    ][9491] Starting a new job with PID 9491
2019-05-16 20:27:12,949 [salt.minion      :1711][INFO    ][9491] Returning information for job: 20190516202712889748
2019-05-16 20:27:23,639 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.3940351s left)
2019-05-16 20:27:42,967 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202742951366
2019-05-16 20:27:42,990 [salt.minion      :1432][INFO    ][9551] Starting a new job with PID 9551
2019-05-16 20:27:43,015 [salt.minion      :1711][INFO    ][9551] Returning information for job: 20190516202742951366
2019-05-16 20:27:57,109 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.92310214s left)
2019-05-16 20:28:13,036 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202813022824
2019-05-16 20:28:13,059 [salt.minion      :1432][INFO    ][9696] Starting a new job with PID 9696
2019-05-16 20:28:13,084 [salt.minion      :1711][INFO    ][9696] Returning information for job: 20190516202813022824
2019-05-16 20:28:30,309 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.72340798s left)
2019-05-16 20:28:43,100 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202843088105
2019-05-16 20:28:43,122 [salt.minion      :1432][INFO    ][9726] Starting a new job with PID 9726
2019-05-16 20:28:43,144 [salt.minion      :1711][INFO    ][9726] Returning information for job: 20190516202843088105
2019-05-16 20:29:03,212 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.82099009s left)
2019-05-16 20:29:13,171 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202913157499
2019-05-16 20:29:13,192 [salt.minion      :1432][INFO    ][10327] Starting a new job with PID 10327
2019-05-16 20:29:13,209 [salt.minion      :1711][INFO    ][10327] Returning information for job: 20190516202913157499
2019-05-16 20:29:36,303 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.72946596s left)
2019-05-16 20:29:43,233 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516202943220338
2019-05-16 20:29:43,256 [salt.minion      :1432][INFO    ][10362] Starting a new job with PID 10362
2019-05-16 20:29:43,278 [salt.minion      :1711][INFO    ][10362] Returning information for job: 20190516202943220338
2019-05-16 20:30:08,557 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1914.47541404s left)
2019-05-16 20:30:13,304 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203013290867
2019-05-16 20:30:13,326 [salt.minion      :1432][INFO    ][10787] Starting a new job with PID 10787
2019-05-16 20:30:13,350 [salt.minion      :1711][INFO    ][10787] Returning information for job: 20190516203013290867
2019-05-16 20:30:41,959 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.07391214s left)
2019-05-16 20:30:43,387 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203043373831
2019-05-16 20:30:43,409 [salt.minion      :1432][INFO    ][10811] Starting a new job with PID 10811
2019-05-16 20:30:43,433 [salt.minion      :1711][INFO    ][10811] Returning information for job: 20190516203043373831
2019-05-16 20:31:13,467 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203113456990
2019-05-16 20:31:13,489 [salt.minion      :1432][INFO    ][10876] Starting a new job with PID 10876
2019-05-16 20:31:13,513 [salt.minion      :1711][INFO    ][10876] Returning information for job: 20190516203113456990
2019-05-16 20:31:15,300 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1847.73234105s left)
2019-05-16 20:31:43,558 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203143545818
2019-05-16 20:31:43,581 [salt.minion      :1432][INFO    ][10915] Starting a new job with PID 10915
2019-05-16 20:31:43,605 [salt.minion      :1711][INFO    ][10915] Returning information for job: 20190516203143545818
2019-05-16 20:31:48,777 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.25592804s left)
2019-05-16 20:32:13,667 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203213655231
2019-05-16 20:32:13,687 [salt.minion      :1432][INFO    ][11285] Starting a new job with PID 11285
2019-05-16 20:32:13,711 [salt.minion      :1711][INFO    ][11285] Returning information for job: 20190516203213655231
2019-05-16 20:32:22,230 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1780.80289817s left)
2019-05-16 20:32:43,771 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203243758405
2019-05-16 20:32:43,793 [salt.minion      :1432][INFO    ][11355] Starting a new job with PID 11355
2019-05-16 20:32:43,817 [salt.minion      :1711][INFO    ][11355] Returning information for job: 20190516203243758405
2019-05-16 20:32:55,968 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1747.06468797s left)
2019-05-16 20:33:13,888 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203313875892
2019-05-16 20:33:13,911 [salt.minion      :1432][INFO    ][11723] Starting a new job with PID 11723
2019-05-16 20:33:13,934 [salt.minion      :1711][INFO    ][11723] Returning information for job: 20190516203313875892
2019-05-16 20:33:29,630 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1713.40286517s left)
2019-05-16 20:33:44,007 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203343991719
2019-05-16 20:33:44,029 [salt.minion      :1432][INFO    ][11742] Starting a new job with PID 11742
2019-05-16 20:33:44,054 [salt.minion      :1711][INFO    ][11742] Returning information for job: 20190516203343991719
2019-05-16 20:34:03,177 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1679.85581708s left)
2019-05-16 20:34:14,142 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203414126737
2019-05-16 20:34:14,165 [salt.minion      :1432][INFO    ][11802] Starting a new job with PID 11802
2019-05-16 20:34:14,189 [salt.minion      :1711][INFO    ][11802] Returning information for job: 20190516203414126737
2019-05-16 20:34:36,762 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1646.27048707s left)
2019-05-16 20:34:44,281 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203444268199
2019-05-16 20:34:44,304 [salt.minion      :1432][INFO    ][11822] Starting a new job with PID 11822
2019-05-16 20:34:44,334 [salt.minion      :1711][INFO    ][11822] Returning information for job: 20190516203444268199
2019-05-16 20:35:10,141 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1612.89237905s left)
2019-05-16 20:35:14,436 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203514422568
2019-05-16 20:35:14,460 [salt.minion      :1432][INFO    ][11878] Starting a new job with PID 11878
2019-05-16 20:35:14,482 [salt.minion      :1711][INFO    ][11878] Returning information for job: 20190516203514422568
2019-05-16 20:35:43,391 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1579.64166999s left)
2019-05-16 20:35:44,587 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203544574815
2019-05-16 20:35:44,610 [salt.minion      :1432][INFO    ][11898] Starting a new job with PID 11898
2019-05-16 20:35:44,633 [salt.minion      :1711][INFO    ][11898] Returning information for job: 20190516203544574815
2019-05-16 20:36:14,745 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203614735364
2019-05-16 20:36:14,769 [salt.minion      :1432][INFO    ][11954] Starting a new job with PID 11954
2019-05-16 20:36:14,793 [salt.minion      :1711][INFO    ][11954] Returning information for job: 20190516203614735364
2019-05-16 20:36:16,858 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1546.17460108s left)
2019-05-16 20:36:44,905 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203644889641
2019-05-16 20:36:44,928 [salt.minion      :1432][INFO    ][11973] Starting a new job with PID 11973
2019-05-16 20:36:44,951 [salt.minion      :1711][INFO    ][11973] Returning information for job: 20190516203644889641
2019-05-16 20:36:50,450 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1512.58237004s left)
2019-05-16 20:37:15,092 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203715079365
2019-05-16 20:37:15,115 [salt.minion      :1432][INFO    ][12042] Starting a new job with PID 12042
2019-05-16 20:37:15,140 [salt.minion      :1711][INFO    ][12042] Returning information for job: 20190516203715079365
2019-05-16 20:37:23,714 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1479.31809711s left)
2019-05-16 20:37:45,287 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203745273827
2019-05-16 20:37:45,309 [salt.minion      :1432][INFO    ][12061] Starting a new job with PID 12061
2019-05-16 20:37:45,333 [salt.minion      :1711][INFO    ][12061] Returning information for job: 20190516203745273827
2019-05-16 20:37:57,222 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1445.81023717s left)
2019-05-16 20:38:15,490 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203815478042
2019-05-16 20:38:15,513 [salt.minion      :1432][INFO    ][12119] Starting a new job with PID 12119
2019-05-16 20:38:15,536 [salt.minion      :1711][INFO    ][12119] Returning information for job: 20190516203815478042
2019-05-16 20:38:30,536 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1412.49693108s left)
2019-05-16 20:38:45,701 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203845687641
2019-05-16 20:38:45,724 [salt.minion      :1432][INFO    ][12139] Starting a new job with PID 12139
2019-05-16 20:38:45,747 [salt.minion      :1711][INFO    ][12139] Returning information for job: 20190516203845687641
2019-05-16 20:39:04,126 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1378.90634799s left)
2019-05-16 20:39:15,921 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203915908350
2019-05-16 20:39:15,944 [salt.minion      :1432][INFO    ][12336] Starting a new job with PID 12336
2019-05-16 20:39:15,969 [salt.minion      :1711][INFO    ][12336] Returning information for job: 20190516203915908350
2019-05-16 20:39:37,636 [salt.loaded.ext.module.maas:1023][INFO    ][8324] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1345.39698815s left)
2019-05-16 20:39:45,940 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516203945928646
2019-05-16 20:39:45,960 [salt.minion      :1432][INFO    ][12364] Starting a new job with PID 12364
2019-05-16 20:39:45,984 [salt.minion      :1711][INFO    ][12364] Returning information for job: 20190516203945928646
2019-05-16 20:40:09,542 [salt.loaded.ext.module.maas:993 ][INFO    ][8324] Machine t48grb mark broken
2019-05-16 20:40:10,278 [salt.loaded.ext.module.maas:996 ][INFO    ][8324] Machine t48grb mark fixed
2019-05-16 20:40:11,546 [salt.loaded.ext.module.maas:684 ][INFO    ][8324] deploymachines hwe_kernel=hwe-16.04 system_id=t48grb distro_series=xenial
2019-05-16 20:40:14,374 [salt.loaded.ext.module.maas:160 ][ERROR   ][8324] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-05-16 20:40:14,376 [salt.state       :302 ][ERROR   ][8324] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-05-16 20:40:14,377 [salt.state       :1951][INFO    ][8324] Completed state [maas.wait_for_machine_status] at time 20:40:14.377087 duration_in_ms=941349.38
2019-05-16 20:40:14,386 [salt.minion      :1711][INFO    ][8324] Returning information for job: 20190516202427591829
2019-05-16 20:40:25,130 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command pillar.get with jid 20190516204025117329
2019-05-16 20:40:25,151 [salt.minion      :1432][INFO    ][12488] Starting a new job with PID 12488
2019-05-16 20:40:25,159 [salt.minion      :1711][INFO    ][12488] Returning information for job: 20190516204025117329
2019-05-16 20:40:25,688 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command service.status with jid 20190516204025676747
2019-05-16 20:40:25,708 [salt.minion      :1432][INFO    ][12500] Starting a new job with PID 12500
2019-05-16 20:40:26,150 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12500] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:26,184 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12500] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-16 20:40:26,199 [salt.minion      :1711][INFO    ][12500] Returning information for job: 20190516204025676747
2019-05-16 20:40:26,671 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204026658037
2019-05-16 20:40:26,691 [salt.minion      :1432][INFO    ][12512] Starting a new job with PID 12512
2019-05-16 20:40:30,398 [salt.state       :915 ][INFO    ][12512] Loading fresh modules for state activity
2019-05-16 20:40:30,845 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'salt-minion --version' in directory '/root'
2019-05-16 20:40:31,211 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'salt-minion --version' in directory '/root'
2019-05-16 20:40:32,067 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'salt-minion --version' in directory '/root'
2019-05-16 20:40:32,387 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'salt-minion --version' in directory '/root'
2019-05-16 20:40:33,762 [salt.state       :1780][INFO    ][12512] Running state [salt-minion] at time 20:40:33.762218
2019-05-16 20:40:33,762 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [salt-minion]
2019-05-16 20:40:33,763 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-16 20:40:33,837 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:33,837 [salt.state       :1951][INFO    ][12512] Completed state [salt-minion] at time 20:40:33.837379 duration_in_ms=75.162
2019-05-16 20:40:33,837 [salt.state       :1780][INFO    ][12512] Running state [salt_minion_dependency_packages] at time 20:40:33.837643
2019-05-16 20:40:33,837 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-16 20:40:33,842 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:33,842 [salt.state       :1951][INFO    ][12512] Completed state [salt_minion_dependency_packages] at time 20:40:33.842559 duration_in_ms=4.917
2019-05-16 20:40:33,844 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/minion.d/minion.conf] at time 20:40:33.844863
2019-05-16 20:40:33,845 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-16 20:40:34,028 [salt.state       :300 ][INFO    ][12512] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-16 20:40:34,028 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/minion.d/minion.conf] at time 20:40:34.028777 duration_in_ms=183.914
2019-05-16 20:40:34,028 [salt.state       :1780][INFO    ][12512] Running state [python-netaddr] at time 20:40:34.028958
2019-05-16 20:40:34,029 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [python-netaddr]
2019-05-16 20:40:34,033 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:34,033 [salt.state       :1951][INFO    ][12512] Completed state [python-netaddr] at time 20:40:34.033626 duration_in_ms=4.668
2019-05-16 20:40:34,035 [salt.state       :1780][INFO    ][12512] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:40:34.035647
2019-05-16 20:40:34,035 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-16 20:40:34,045 [salt.state       :300 ][INFO    ][12512] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-16 20:40:34,045 [salt.state       :1951][INFO    ][12512] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:40:34.045418 duration_in_ms=9.771
2019-05-16 20:40:34,046 [salt.state       :1780][INFO    ][12512] Running state [salt-minion] at time 20:40:34.046075
2019-05-16 20:40:34,046 [salt.state       :1813][INFO    ][12512] Executing state service.running for [salt-minion]
2019-05-16 20:40:34,046 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:34,080 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-16 20:40:34,096 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-16 20:40:34,111 [salt.state       :300 ][INFO    ][12512] The service salt-minion is already running
2019-05-16 20:40:34,112 [salt.state       :1951][INFO    ][12512] Completed state [salt-minion] at time 20:40:34.112145 duration_in_ms=66.069
2019-05-16 20:40:34,113 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains.d] at time 20:40:34.113417
2019-05-16 20:40:34,113 [salt.state       :1813][INFO    ][12512] Executing state file.directory for [/etc/salt/grains.d]
2019-05-16 20:40:34,114 [salt.state       :300 ][INFO    ][12512] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-16 20:40:34,114 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains.d] at time 20:40:34.114706 duration_in_ms=1.289
2019-05-16 20:40:34,115 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains] at time 20:40:34.115258
2019-05-16 20:40:34,115 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/grains]
2019-05-16 20:40:34,116 [salt.state       :300 ][INFO    ][12512] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-16 20:40:34,116 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains] at time 20:40:34.116175 duration_in_ms=0.917
2019-05-16 20:40:34,116 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains.d/placeholder] at time 20:40:34.116572
2019-05-16 20:40:34,116 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-16 20:40:34,117 [salt.state       :300 ][INFO    ][12512] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-16 20:40:34,117 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains.d/placeholder] at time 20:40:34.117421 duration_in_ms=0.85
2019-05-16 20:40:34,117 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains.d/sphinx] at time 20:40:34.117816
2019-05-16 20:40:34,118 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-16 20:40:34,130 [salt.state       :300 ][INFO    ][12512] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-16 20:40:34,130 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains.d/sphinx] at time 20:40:34.130690 duration_in_ms=12.874
2019-05-16 20:40:34,132 [salt.state       :1780][INFO    ][12512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.132659
2019-05-16 20:40:34,132 [salt.state       :1813][INFO    ][12512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-16 20:40:34,133 [salt.state       :300 ][INFO    ][12512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-16 20:40:34,133 [salt.state       :1951][INFO    ][12512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.133413 duration_in_ms=0.754
2019-05-16 20:40:34,133 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains.d/dns_records] at time 20:40:34.133853
2019-05-16 20:40:34,134 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-16 20:40:34,148 [salt.state       :300 ][INFO    ][12512] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-16 20:40:34,148 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains.d/dns_records] at time 20:40:34.148522 duration_in_ms=14.668
2019-05-16 20:40:34,149 [salt.state       :1780][INFO    ][12512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.149327
2019-05-16 20:40:34,149 [salt.state       :1813][INFO    ][12512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-16 20:40:34,149 [salt.state       :300 ][INFO    ][12512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-16 20:40:34,150 [salt.state       :1951][INFO    ][12512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.150097 duration_in_ms=0.77
2019-05-16 20:40:34,150 [salt.state       :1780][INFO    ][12512] Running state [/etc/salt/grains.d/salt] at time 20:40:34.150520
2019-05-16 20:40:34,150 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-16 20:40:34,160 [salt.state       :300 ][INFO    ][12512] File /etc/salt/grains.d/salt is in the correct state
2019-05-16 20:40:34,160 [salt.state       :1951][INFO    ][12512] Completed state [/etc/salt/grains.d/salt] at time 20:40:34.160580 duration_in_ms=10.06
2019-05-16 20:40:34,161 [salt.state       :1780][INFO    ][12512] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.161340
2019-05-16 20:40:34,161 [salt.state       :1813][INFO    ][12512] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-16 20:40:34,161 [salt.state       :300 ][INFO    ][12512] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-16 20:40:34,162 [salt.state       :1951][INFO    ][12512] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:40:34.162112 duration_in_ms=0.772
2019-05-16 20:40:34,163 [salt.state       :1780][INFO    ][12512] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:40:34.163789
2019-05-16 20:40:34,164 [salt.state       :1813][INFO    ][12512] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-16 20:40:34,164 [salt.state       :300 ][INFO    ][12512] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-16 20:40:34,164 [salt.state       :1951][INFO    ][12512] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:40:34.164590 duration_in_ms=0.801
2019-05-16 20:40:34,165 [salt.state       :1780][INFO    ][12512] Running state [mine.update] at time 20:40:34.165203
2019-05-16 20:40:34,165 [salt.state       :1813][INFO    ][12512] Executing state module.wait for [mine.update]
2019-05-16 20:40:34,165 [salt.state       :300 ][INFO    ][12512] No changes made for mine.update
2019-05-16 20:40:34,165 [salt.state       :1951][INFO    ][12512] Completed state [mine.update] at time 20:40:34.165941 duration_in_ms=0.738
2019-05-16 20:40:34,166 [salt.state       :1780][INFO    ][12512] Running state [ca-certificates] at time 20:40:34.166162
2019-05-16 20:40:34,166 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [ca-certificates]
2019-05-16 20:40:34,173 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:34,173 [salt.state       :1951][INFO    ][12512] Completed state [ca-certificates] at time 20:40:34.173315 duration_in_ms=7.153
2019-05-16 20:40:34,173 [salt.state       :1780][INFO    ][12512] Running state [update-ca-certificates] at time 20:40:34.173937
2019-05-16 20:40:34,174 [salt.state       :1813][INFO    ][12512] Executing state cmd.wait for [update-ca-certificates]
2019-05-16 20:40:34,174 [salt.state       :300 ][INFO    ][12512] No changes made for update-ca-certificates
2019-05-16 20:40:34,174 [salt.state       :1951][INFO    ][12512] Completed state [update-ca-certificates] at time 20:40:34.174690 duration_in_ms=0.753
2019-05-16 20:40:34,174 [salt.state       :1780][INFO    ][12512] Running state [iptables] at time 20:40:34.174905
2019-05-16 20:40:34,175 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [iptables]
2019-05-16 20:40:34,181 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:34,181 [salt.state       :1951][INFO    ][12512] Completed state [iptables] at time 20:40:34.181429 duration_in_ms=6.524
2019-05-16 20:40:34,181 [salt.state       :1780][INFO    ][12512] Running state [iptables-persistent] at time 20:40:34.181685
2019-05-16 20:40:34,181 [salt.state       :1813][INFO    ][12512] Executing state pkg.installed for [iptables-persistent]
2019-05-16 20:40:34,187 [salt.state       :300 ][INFO    ][12512] All specified packages are already installed
2019-05-16 20:40:34,188 [salt.state       :1951][INFO    ][12512] Completed state [iptables-persistent] at time 20:40:34.188011 duration_in_ms=6.326
2019-05-16 20:40:34,188 [salt.state       :1780][INFO    ][12512] Running state [iptables_modules_v4_load] at time 20:40:34.188885
2019-05-16 20:40:34,189 [salt.state       :1813][INFO    ][12512] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-16 20:40:34,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'lsmod' in directory '/root'
2019-05-16 20:40:34,209 [salt.state       :300 ][INFO    ][12512] Kernel modules iptable_filter, ip_tables are already present
2019-05-16 20:40:34,210 [salt.state       :1951][INFO    ][12512] Completed state [iptables_modules_v4_load] at time 20:40:34.210170 duration_in_ms=21.285
2019-05-16 20:40:34,210 [salt.state       :1780][INFO    ][12512] Running state [/etc/iptables/rules.v4] at time 20:40:34.210791
2019-05-16 20:40:34,211 [salt.state       :1813][INFO    ][12512] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-16 20:40:34,298 [salt.state       :300 ][INFO    ][12512] File /etc/iptables/rules.v4 is in the correct state
2019-05-16 20:40:34,298 [salt.state       :1951][INFO    ][12512] Completed state [/etc/iptables/rules.v4] at time 20:40:34.298387 duration_in_ms=87.597
2019-05-16 20:40:34,299 [salt.state       :1780][INFO    ][12512] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:40:34.299246
2019-05-16 20:40:34,299 [salt.state       :1813][INFO    ][12512] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-16 20:40:34,299 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-16 20:40:34,317 [salt.state       :300 ][INFO    ][12512] onlyif execution failed
2019-05-16 20:40:34,318 [salt.state       :1951][INFO    ][12512] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:40:34.318158 duration_in_ms=18.912
2019-05-16 20:40:34,318 [salt.state       :1780][INFO    ][12512] Running state [netfilter-persistent] at time 20:40:34.318946
2019-05-16 20:40:34,319 [salt.state       :1813][INFO    ][12512] Executing state service.running for [netfilter-persistent]
2019-05-16 20:40:34,319 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:34,338 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-16 20:40:34,354 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-16 20:40:34,371 [salt.state       :300 ][INFO    ][12512] The service netfilter-persistent is already running
2019-05-16 20:40:34,371 [salt.state       :1951][INFO    ][12512] Completed state [netfilter-persistent] at time 20:40:34.371481 duration_in_ms=52.534
2019-05-16 20:40:34,372 [salt.state       :1780][INFO    ][12512] Running state [iptables_extra.remove_stale_tables] at time 20:40:34.372206
2019-05-16 20:40:34,372 [salt.state       :1813][INFO    ][12512] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-16 20:40:34,372 [salt.state       :300 ][INFO    ][12512] No changes made for iptables_extra.remove_stale_tables
2019-05-16 20:40:34,373 [salt.state       :1951][INFO    ][12512] Completed state [iptables_extra.remove_stale_tables] at time 20:40:34.373035 duration_in_ms=0.829
2019-05-16 20:40:34,373 [salt.state       :1780][INFO    ][12512] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:40:34.373261
2019-05-16 20:40:34,373 [salt.state       :1813][INFO    ][12512] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-16 20:40:34,374 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12512] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-16 20:40:34,388 [salt.state       :300 ][INFO    ][12512] onlyif execution failed
2019-05-16 20:40:34,388 [salt.state       :1951][INFO    ][12512] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:40:34.388425 duration_in_ms=15.163
2019-05-16 20:40:34,389 [salt.state       :1780][INFO    ][12512] Running state [/etc/iptables/rules.v6] at time 20:40:34.389420
2019-05-16 20:40:34,389 [salt.state       :1813][INFO    ][12512] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-16 20:40:34,390 [salt.state       :300 ][INFO    ][12512] File /etc/iptables/rules.v6 is not present
2019-05-16 20:40:34,390 [salt.state       :1951][INFO    ][12512] Completed state [/etc/iptables/rules.v6] at time 20:40:34.390495 duration_in_ms=1.075
2019-05-16 20:40:34,391 [salt.state       :1780][INFO    ][12512] Running state [iptables_extra.flush_all] at time 20:40:34.391188
2019-05-16 20:40:34,391 [salt.state       :1813][INFO    ][12512] Executing state module.wait for [iptables_extra.flush_all]
2019-05-16 20:40:34,391 [salt.state       :300 ][INFO    ][12512] No changes made for iptables_extra.flush_all
2019-05-16 20:40:34,392 [salt.state       :1951][INFO    ][12512] Completed state [iptables_extra.flush_all] at time 20:40:34.392019 duration_in_ms=0.831
2019-05-16 20:40:34,395 [salt.minion      :1711][INFO    ][12512] Returning information for job: 20190516204026658037
2019-05-16 20:40:35,028 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204035014958
2019-05-16 20:40:35,050 [salt.minion      :1432][INFO    ][12594] Starting a new job with PID 12594
2019-05-16 20:40:35,827 [salt.state       :915 ][INFO    ][12594] Loading fresh modules for state activity
2019-05-16 20:40:36,482 [salt.state       :1780][INFO    ][12594] Running state [maas-rack-controller] at time 20:40:36.481946
2019-05-16 20:40:36,482 [salt.state       :1813][INFO    ][12594] Executing state pkg.installed for [maas-rack-controller]
2019-05-16 20:40:36,482 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12594] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-16 20:40:36,562 [salt.state       :300 ][INFO    ][12594] All specified packages are already installed
2019-05-16 20:40:36,562 [salt.state       :1951][INFO    ][12594] Completed state [maas-rack-controller] at time 20:40:36.562320 duration_in_ms=80.374
2019-05-16 20:40:36,562 [salt.state       :1780][INFO    ][12594] Running state [ipmitool] at time 20:40:36.562565
2019-05-16 20:40:36,562 [salt.state       :1813][INFO    ][12594] Executing state pkg.installed for [ipmitool]
2019-05-16 20:40:36,567 [salt.state       :300 ][INFO    ][12594] All specified packages are already installed
2019-05-16 20:40:36,567 [salt.state       :1951][INFO    ][12594] Completed state [ipmitool] at time 20:40:36.567348 duration_in_ms=4.783
2019-05-16 20:40:36,569 [salt.state       :1780][INFO    ][12594] Running state [/etc/maas/rackd.conf] at time 20:40:36.569609
2019-05-16 20:40:36,569 [salt.state       :1813][INFO    ][12594] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-16 20:40:36,570 [salt.state       :300 ][INFO    ][12594] No changes needed to be made
2019-05-16 20:40:36,570 [salt.state       :1951][INFO    ][12594] Completed state [/etc/maas/rackd.conf] at time 20:40:36.570716 duration_in_ms=1.106
2019-05-16 20:40:36,570 [salt.state       :1780][INFO    ][12594] Running state [/etc/maas/rackd.conf] at time 20:40:36.570880
2019-05-16 20:40:36,571 [salt.state       :1813][INFO    ][12594] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-16 20:40:36,571 [salt.loaded.int.states.file:2298][WARNING ][12594] 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-05-16 20:40:36,571 [salt.state       :300 ][INFO    ][12594] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-16 20:40:36,571 [salt.state       :1951][INFO    ][12594] Completed state [/etc/maas/rackd.conf] at time 20:40:36.571754 duration_in_ms=0.875
2019-05-16 20:40:36,572 [salt.state       :1780][INFO    ][12594] Running state [maas-rackd] at time 20:40:36.572424
2019-05-16 20:40:36,572 [salt.state       :1813][INFO    ][12594] Executing state service.running for [maas-rackd]
2019-05-16 20:40:36,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12594] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:36,605 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12594] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-16 20:40:36,621 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12594] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-16 20:40:36,636 [salt.state       :300 ][INFO    ][12594] The service maas-rackd is already running
2019-05-16 20:40:36,637 [salt.state       :1951][INFO    ][12594] Completed state [maas-rackd] at time 20:40:36.637134 duration_in_ms=64.71
2019-05-16 20:40:36,638 [salt.minion      :1711][INFO    ][12594] Returning information for job: 20190516204035014958
2019-05-16 20:40:37,221 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204037208262
2019-05-16 20:40:37,243 [salt.minion      :1432][INFO    ][12618] Starting a new job with PID 12618
2019-05-16 20:40:38,015 [salt.state       :915 ][INFO    ][12618] Loading fresh modules for state activity
2019-05-16 20:40:38,776 [salt.state       :1780][INFO    ][12618] Running state [maas-region-controller] at time 20:40:38.775963
2019-05-16 20:40:38,776 [salt.state       :1813][INFO    ][12618] Executing state pkg.installed for [maas-region-controller]
2019-05-16 20:40:38,776 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-16 20:40:38,861 [salt.state       :300 ][INFO    ][12618] All specified packages are already installed
2019-05-16 20:40:38,862 [salt.state       :1951][INFO    ][12618] Completed state [maas-region-controller] at time 20:40:38.862073 duration_in_ms=86.111
2019-05-16 20:40:38,862 [salt.state       :1780][INFO    ][12618] Running state [python-oauth] at time 20:40:38.862362
2019-05-16 20:40:38,862 [salt.state       :1813][INFO    ][12618] Executing state pkg.installed for [python-oauth]
2019-05-16 20:40:38,868 [salt.state       :300 ][INFO    ][12618] All specified packages are already installed
2019-05-16 20:40:38,868 [salt.state       :1951][INFO    ][12618] Completed state [python-oauth] at time 20:40:38.868403 duration_in_ms=6.041
2019-05-16 20:40:38,871 [salt.state       :1780][INFO    ][12618] Running state [/etc/maas/regiond.conf] at time 20:40:38.871163
2019-05-16 20:40:38,871 [salt.state       :1813][INFO    ][12618] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-16 20:40:38,916 [salt.state       :300 ][INFO    ][12618] No changes needed to be made
2019-05-16 20:40:38,916 [salt.state       :1951][INFO    ][12618] Completed state [/etc/maas/regiond.conf] at time 20:40:38.916525 duration_in_ms=45.361
2019-05-16 20:40:38,917 [salt.state       :1780][INFO    ][12618] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:40:38.917223
2019-05-16 20:40:38,917 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-16 20:40:38,999 [salt.state       :300 ][INFO    ][12618] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-16 20:40:39,000 [salt.state       :1951][INFO    ][12618] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:40:39.000397 duration_in_ms=83.172
2019-05-16 20:40:39,001 [salt.state       :1780][INFO    ][12618] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:40:39.001221
2019-05-16 20:40:39,001 [salt.state       :1813][INFO    ][12618] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-16 20:40:39,018 [salt.state       :300 ][INFO    ][12618] No changes needed to be made
2019-05-16 20:40:39,019 [salt.state       :1951][INFO    ][12618] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:40:39.019212 duration_in_ms=17.99
2019-05-16 20:40:39,019 [salt.state       :1780][INFO    ][12618] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:40:39.019781
2019-05-16 20:40:39,020 [salt.state       :1813][INFO    ][12618] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-16 20:40:39,043 [salt.state       :300 ][INFO    ][12618] No changes needed to be made
2019-05-16 20:40:39,043 [salt.state       :1951][INFO    ][12618] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:40:39.043563 duration_in_ms=23.781
2019-05-16 20:40:39,044 [salt.state       :1780][INFO    ][12618] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:40:39.044253
2019-05-16 20:40:39,044 [salt.state       :1813][INFO    ][12618] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-16 20:40:39,079 [salt.state       :300 ][INFO    ][12618] No changes needed to be made
2019-05-16 20:40:39,079 [salt.state       :1951][INFO    ][12618] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:40:39.079728 duration_in_ms=35.474
2019-05-16 20:40:39,080 [salt.state       :1780][INFO    ][12618] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:40:39.080309
2019-05-16 20:40:39,080 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-16 20:40:39,095 [salt.state       :300 ][INFO    ][12618] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-16 20:40:39,095 [salt.state       :1951][INFO    ][12618] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:40:39.095414 duration_in_ms=15.106
2019-05-16 20:40:39,097 [salt.state       :1780][INFO    ][12618] Running state [a2enmod headers] at time 20:40:39.097821
2019-05-16 20:40:39,098 [salt.state       :1813][INFO    ][12618] Executing state cmd.run for [a2enmod headers]
2019-05-16 20:40:39,099 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command 'a2enmod headers' in directory '/root'
2019-05-16 20:40:39,167 [salt.state       :300 ][INFO    ][12618] {'pid': 12641, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-16 20:40:39,168 [salt.state       :1951][INFO    ][12618] Completed state [a2enmod headers] at time 20:40:39.168124 duration_in_ms=70.302
2019-05-16 20:40:39,168 [salt.state       :1780][INFO    ][12618] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:40:39.168732
2019-05-16 20:40:39,169 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-16 20:40:39,188 [salt.state       :300 ][INFO    ][12618] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-16 20:40:39,188 [salt.state       :1951][INFO    ][12618] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:40:39.188451 duration_in_ms=19.718
2019-05-16 20:40:39,189 [salt.state       :1780][INFO    ][12618] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:40:39.189338
2019-05-16 20:40:39,189 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-16 20:40:39,269 [salt.state       :300 ][INFO    ][12618] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-16 20:40:39,269 [salt.state       :1951][INFO    ][12618] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:40:39.269341 duration_in_ms=80.003
2019-05-16 20:40:39,270 [salt.state       :1780][INFO    ][12618] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:40:39.270032
2019-05-16 20:40:39,270 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-16 20:40:39,340 [salt.state       :300 ][INFO    ][12618] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-16 20:40:39,341 [salt.state       :1951][INFO    ][12618] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:40:39.340995 duration_in_ms=70.963
2019-05-16 20:40:39,341 [salt.state       :1780][INFO    ][12618] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:40:39.341606
2019-05-16 20:40:39,341 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-16 20:40:39,418 [salt.state       :300 ][INFO    ][12618] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-16 20:40:39,419 [salt.state       :1951][INFO    ][12618] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:40:39.419272 duration_in_ms=77.665
2019-05-16 20:40:39,419 [salt.state       :1780][INFO    ][12618] Running state [/root/.pgpass] at time 20:40:39.419709
2019-05-16 20:40:39,420 [salt.state       :1813][INFO    ][12618] Executing state file.managed for [/root/.pgpass]
2019-05-16 20:40:39,478 [salt.state       :300 ][INFO    ][12618] File /root/.pgpass is in the correct state
2019-05-16 20:40:39,478 [salt.state       :1951][INFO    ][12618] Completed state [/root/.pgpass] at time 20:40:39.478912 duration_in_ms=59.203
2019-05-16 20:40:39,486 [salt.state       :1780][INFO    ][12618] Running state [maas-region syncdb --noinput] at time 20:40:39.486146
2019-05-16 20:40:39,486 [salt.state       :1813][INFO    ][12618] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-16 20:40:39,487 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-16 20:40:41,507 [salt.state       :300 ][INFO    ][12618] {'pid': 12654, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: metadataserver, piston3, sites, contenttypes, auth, sessions, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-16 20:40:41,507 [salt.state       :1951][INFO    ][12618] Completed state [maas-region syncdb --noinput] at time 20:40:41.507814 duration_in_ms=2021.667
2019-05-16 20:40:41,508 [salt.state       :2022][WARNING ][12618] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-16 20:40:41,511 [salt.state       :1780][INFO    ][12618] Running state [maas-regiond] at time 20:40:41.511339
2019-05-16 20:40:41,511 [salt.state       :1813][INFO    ][12618] Executing state service.running for [maas-regiond]
2019-05-16 20:40:41,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:41,553 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-16 20:40:41,570 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-16 20:40:41,591 [salt.state       :300 ][INFO    ][12618] The service maas-regiond is already running
2019-05-16 20:40:41,592 [salt.state       :1951][INFO    ][12618] Completed state [maas-regiond] at time 20:40:41.591962 duration_in_ms=80.624
2019-05-16 20:40:41,594 [salt.state       :1780][INFO    ][12618] Running state [bind9] at time 20:40:41.594109
2019-05-16 20:40:41,594 [salt.state       :1813][INFO    ][12618] Executing state service.running for [bind9]
2019-05-16 20:40:41,595 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:41,616 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-16 20:40:41,635 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-16 20:40:41,654 [salt.state       :300 ][INFO    ][12618] The service bind9 is already running
2019-05-16 20:40:41,654 [salt.state       :1951][INFO    ][12618] Completed state [bind9] at time 20:40:41.654698 duration_in_ms=60.589
2019-05-16 20:40:41,657 [salt.state       :1780][INFO    ][12618] Running state [apache2] at time 20:40:41.657526
2019-05-16 20:40:41,658 [salt.state       :1813][INFO    ][12618] Executing state service.running for [apache2]
2019-05-16 20:40:41,659 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-16 20:40:41,680 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-16 20:40:41,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-16 20:40:41,723 [salt.state       :300 ][INFO    ][12618] The service apache2 is already running
2019-05-16 20:40:41,723 [salt.state       :1951][INFO    ][12618] Completed state [apache2] at time 20:40:41.723697 duration_in_ms=66.171
2019-05-16 20:40:41,726 [salt.state       :1780][INFO    ][12618] Running state [maasng.wait_for_http_code] at time 20:40:41.726114
2019-05-16 20:40:41,726 [salt.state       :1813][INFO    ][12618] Executing state module.run for [maasng.wait_for_http_code]
2019-05-16 20:40:41,727 [salt.utils.decorators:613 ][WARNING ][12618] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:40:41,737 [salt.state       :300 ][INFO    ][12618] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-16 20:40:41,738 [salt.state       :1951][INFO    ][12618] Completed state [maasng.wait_for_http_code] at time 20:40:41.738389 duration_in_ms=12.275
2019-05-16 20:40:41,739 [salt.state       :1780][INFO    ][12618] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:40:41.739776
2019-05-16 20:40:41,740 [salt.state       :1813][INFO    ][12618] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-16 20:40:41,741 [salt.state       :300 ][INFO    ][12618] /var/lib/maas/.setup_admin exists
2019-05-16 20:40:41,741 [salt.state       :1951][INFO    ][12618] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:40:41.741375 duration_in_ms=1.6
2019-05-16 20:40:41,742 [salt.state       :1780][INFO    ][12618] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:40:41.742555
2019-05-16 20:40:41,743 [salt.state       :1813][INFO    ][12618] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:40:41,743 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12618] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:40:43,209 [salt.state       :300 ][INFO    ][12618] {'pid': 12673, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:40:43,210 [salt.state       :1951][INFO    ][12618] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:40:43.209947 duration_in_ms=1467.391
2019-05-16 20:40:43,217 [salt.state       :1780][INFO    ][12618] Running state [maas_region_boot_source_resources_mirror] at time 20:40:43.217657
2019-05-16 20:40:43,218 [salt.state       :1813][INFO    ][12618] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-16 20:40:43,340 [salt.state       :300 ][INFO    ][12618] {'changes': {}}
2019-05-16 20:40:43,340 [salt.state       :1951][INFO    ][12618] Completed state [maas_region_boot_source_resources_mirror] at time 20:40:43.340359 duration_in_ms=122.702
2019-05-16 20:40:43,341 [salt.state       :1780][INFO    ][12618] Running state [maasng.boot_resources_import] at time 20:40:43.341380
2019-05-16 20:40:43,341 [salt.state       :1813][INFO    ][12618] Executing state module.run for [maasng.boot_resources_import]
2019-05-16 20:40:43,342 [salt.utils.decorators:613 ][WARNING ][12618] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:40:43,467 [salt.loaded.ext.module.maasng:1600][INFO    ][12618] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-16 20:40:48,519 [salt.loaded.ext.module.maasng:1600][INFO    ][12618] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-16 20:40:52,297 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204052284821
2019-05-16 20:40:52,320 [salt.minion      :1432][INFO    ][12702] Starting a new job with PID 12702
2019-05-16 20:40:52,345 [salt.minion      :1711][INFO    ][12702] Returning information for job: 20190516204052284821
2019-05-16 20:40:53,580 [salt.loaded.ext.module.maasng:1600][INFO    ][12618] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-16 20:40:58,694 [salt.state       :300 ][INFO    ][12618] {'ret': True}
2019-05-16 20:40:58,694 [salt.state       :1951][INFO    ][12618] Completed state [maasng.boot_resources_import] at time 20:40:58.694496 duration_in_ms=15353.096
2019-05-16 20:40:58,695 [salt.state       :1780][INFO    ][12618] Running state [maas_region_boot_sources_selection_xenial] at time 20:40:58.695698
2019-05-16 20:40:58,696 [salt.state       :1813][INFO    ][12618] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-16 20:40:58,897 [salt.state       :300 ][INFO    ][12618] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-16 20:40:58,897 [salt.state       :1951][INFO    ][12618] Completed state [maas_region_boot_sources_selection_xenial] at time 20:40:58.897803 duration_in_ms=202.103
2019-05-16 20:40:58,899 [salt.state       :1780][INFO    ][12618] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:40:58.899269
2019-05-16 20:40:58,899 [salt.state       :1813][INFO    ][12618] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-16 20:40:58,900 [salt.utils.decorators:613 ][WARNING ][12618] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:40:58,901 [salt.loaded.ext.module.maasng:1771][INFO    ][12618] boot-sources sync initiated for ALL Rack's
2019-05-16 20:40:59,861 [salt.state       :300 ][INFO    ][12618] {'ret': True}
2019-05-16 20:40:59,861 [salt.state       :1951][INFO    ][12618] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:40:59.861435 duration_in_ms=962.165
2019-05-16 20:40:59,863 [salt.state       :1780][INFO    ][12618] Running state [maas.process_maas_config] at time 20:40:59.863568
2019-05-16 20:40:59,864 [salt.state       :1813][INFO    ][12618] Executing state module.run for [maas.process_maas_config]
2019-05-16 20:40:59,864 [salt.utils.decorators:613 ][WARNING ][12618] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:40:59,865 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=enable_http_proxy value=True
2019-05-16 20:40:59,923 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=upstream_dns value=8.8.8.8
2019-05-16 20:40:59,987 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=commissioning_distro_series value=xenial
2019-05-16 20:41:00,052 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=default_osystem value=ubuntu
2019-05-16 20:41:00,106 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=active_discovery_interval value=600
2019-05-16 20:41:00,160 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=dnssec_validation value=no
2019-05-16 20:41:03,039 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=maas_name value=mas01
2019-05-16 20:41:03,105 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=network_discovery value=enabled
2019-05-16 20:41:03,230 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=enable_third_party_drivers value=True
2019-05-16 20:41:03,283 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=default_storage_layout value=lvm
2019-05-16 20:41:03,330 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=ntp_external_only value=True
2019-05-16 20:41:03,378 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-16 20:41:03,424 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=default_distro_series value=xenial
2019-05-16 20:41:03,478 [salt.loaded.ext.module.maas:92  ][INFO    ][12618] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-16 20:41:03,638 [salt.state       :300 ][INFO    ][12618] {'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-05-16 20:41:03,638 [salt.state       :1951][INFO    ][12618] Completed state [maas.process_maas_config] at time 20:41:03.638642 duration_in_ms=3775.073
2019-05-16 20:41:03,639 [salt.state       :1780][INFO    ][12618] Running state [pxe_admin] at time 20:41:03.639567
2019-05-16 20:41:03,640 [salt.state       :1813][INFO    ][12618] Executing state maasng.fabric_present for [pxe_admin]
2019-05-16 20:41:03,718 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, 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'name': u'pxe_admin', u'class_type': u''}]
2019-05-16 20:41:03,789 [salt.loaded.ext.module.maasng:1008][WARNING ][12618] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-16 20:41:03,789 [salt.loaded.ext.module.maasng:1011][WARNING ][12618] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-16 20:41:03,868 [salt.state       :300 ][INFO    ][12618] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-16 20:41:03,869 [salt.state       :1951][INFO    ][12618] Completed state [pxe_admin] at time 20:41:03.869042 duration_in_ms=229.475
2019-05-16 20:41:03,869 [salt.state       :1780][INFO    ][12618] Running state [vlan 0] at time 20:41:03.869404
2019-05-16 20:41:03,869 [salt.state       :1813][INFO    ][12618] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-16 20:41:03,938 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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-05-16 20:41:04,085 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, 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'name': u'pxe_admin', u'class_type': u''}]
2019-05-16 20:41:04,361 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, 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'name': u'pxe_admin', u'class_type': u''}]
2019-05-16 20:41:04,463 [salt.state       :300 ][INFO    ][12618] {'new': 'Vlan untagged was updated'}
2019-05-16 20:41:04,463 [salt.state       :1951][INFO    ][12618] Completed state [vlan 0] at time 20:41:04.463716 duration_in_ms=594.311
2019-05-16 20:41:04,465 [salt.state       :1780][INFO    ][12618] Running state [192.168.11.0/24] at time 20:41:04.465279
2019-05-16 20:41:04,465 [salt.state       :1813][INFO    ][12618] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-16 20:41:04,675 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'x3rd3s', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', 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-05-16 20:41:04,676 [salt.loaded.ext.module.maasng:1235][WARNING ][12618] Ignoring parameter vlan:0
2019-05-16 20:41:04,753 [salt.state       :300 ][INFO    ][12618] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-16 20:41:04,754 [salt.state       :1951][INFO    ][12618] Completed state [192.168.11.0/24] at time 20:41:04.754231 duration_in_ms=288.951
2019-05-16 20:41:04,755 [salt.state       :1780][INFO    ][12618] Running state [maas_create_iprange_1] at time 20:41:04.755576
2019-05-16 20:41:04,756 [salt.state       :1813][INFO    ][12618] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-16 20:41:04,819 [salt.state       :300 ][INFO    ][12618] Iprange maas_create_iprange_1 already exist.
2019-05-16 20:41:04,820 [salt.state       :1951][INFO    ][12618] Completed state [maas_create_iprange_1] at time 20:41:04.820181 duration_in_ms=64.607
2019-05-16 20:41:04,820 [salt.state       :1780][INFO    ][12618] Running state [vlan 0] at time 20:41:04.820602
2019-05-16 20:41:04,821 [salt.state       :1813][INFO    ][12618] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-16 20:41:04,873 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{u'id': 0, 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, 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'x3rd3s', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-16 20:41:04,976 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'x3rd3s', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-16 20:41:05,211 [salt.loaded.ext.module.maasng:945 ][INFO    ][12618] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'x3rd3s', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-16 20:41:05,305 [salt.state       :300 ][INFO    ][12618] {'new': 'Vlan untagged was updated'}
2019-05-16 20:41:05,305 [salt.state       :1951][INFO    ][12618] Completed state [vlan 0] at time 20:41:05.305878 duration_in_ms=485.274
2019-05-16 20:41:05,306 [salt.state       :1780][INFO    ][12618] Running state [opnfv] at time 20:41:05.306653
2019-05-16 20:41:05,307 [salt.state       :1813][INFO    ][12618] Executing state maasng.sshkey_present for [opnfv]
2019-05-16 20:41:05,355 [salt.loaded.ext.module.maasng:1903][INFO    ][12618] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-16 20:41:05,355 [salt.state       :300 ][INFO    ][12618] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-16 20:41:05,356 [salt.state       :1951][INFO    ][12618] Completed state [opnfv] at time 20:41:05.355941 duration_in_ms=49.287
2019-05-16 20:41:05,359 [salt.minion      :1711][INFO    ][12618] Returning information for job: 20190516204037208262
2019-05-16 20:41:05,905 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204105896594
2019-05-16 20:41:05,924 [salt.minion      :1432][INFO    ][13092] Starting a new job with PID 13092
2019-05-16 20:41:09,597 [salt.state       :915 ][INFO    ][13092] Loading fresh modules for state activity
2019-05-16 20:41:09,686 [salt.state       :1780][INFO    ][13092] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:09.686139
2019-05-16 20:41:09,686 [salt.state       :1813][INFO    ][13092] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:41:09,688 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13092] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:41:11,057 [salt.state       :300 ][INFO    ][13092] {'pid': 13123, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:41:11,058 [salt.state       :1951][INFO    ][13092] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:11.058108 duration_in_ms=1371.969
2019-05-16 20:41:11,059 [salt.state       :1780][INFO    ][13092] Running state [maas.process_machines] at time 20:41:11.059211
2019-05-16 20:41:11,059 [salt.state       :1813][INFO    ][13092] Executing state module.run for [maas.process_machines]
2019-05-16 20:41:11,060 [salt.utils.decorators:613 ][WARNING ][13092] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:41:11,850 [salt.loaded.ext.module.maas:412 ][WARNING ][13092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:41:11,850 [salt.loaded.ext.module.maas:92  ][INFO    ][13092] 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=kxdama architecture=amd64/generic power_parameters_power_user=admin
2019-05-16 20:41:13,103 [salt.loaded.ext.module.maas:412 ][WARNING ][13092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:41:13,104 [salt.loaded.ext.module.maas:92  ][INFO    ][13092] 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=6fqcmp architecture=amd64/generic power_parameters_power_user=admin
2019-05-16 20:41:14,366 [salt.loaded.ext.module.maas:412 ][WARNING ][13092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:41:14,367 [salt.loaded.ext.module.maas:92  ][INFO    ][13092] 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=t48grb architecture=amd64/generic power_parameters_power_user=admin
2019-05-16 20:41:15,551 [salt.loaded.ext.module.maas:412 ][WARNING ][13092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:41:15,552 [salt.loaded.ext.module.maas:92  ][INFO    ][13092] 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=redr88 architecture=amd64/generic power_parameters_power_user=admin
2019-05-16 20:41:16,821 [salt.loaded.ext.module.maas:412 ][WARNING ][13092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-16 20:41:16,822 [salt.loaded.ext.module.maas:92  ][INFO    ][13092] 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=d7srrm architecture=amd64/generic power_parameters_power_user=admin
2019-05-16 20:41:18,091 [salt.state       :300 ][INFO    ][13092] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-16 20:41:18,092 [salt.state       :1951][INFO    ][13092] Completed state [maas.process_machines] at time 20:41:18.092306 duration_in_ms=7033.093
2019-05-16 20:41:18,096 [salt.minion      :1711][INFO    ][13092] Returning information for job: 20190516204105896594
2019-05-16 20:41:51,083 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204151076371
2019-05-16 20:41:51,098 [salt.minion      :1432][INFO    ][13357] Starting a new job with PID 13357
2019-05-16 20:41:54,946 [salt.state       :915 ][INFO    ][13357] Loading fresh modules for state activity
2019-05-16 20:41:55,037 [salt.state       :1780][INFO    ][13357] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:55.037155
2019-05-16 20:41:55,037 [salt.state       :1813][INFO    ][13357] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:41:55,039 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13357] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:41:56,589 [salt.state       :300 ][INFO    ][13357] {'pid': 13364, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:41:56,590 [salt.state       :1951][INFO    ][13357] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:41:56.589974 duration_in_ms=1552.819
2019-05-16 20:41:56,593 [salt.state       :1780][INFO    ][13357] Running state [maas.wait_for_machine_status] at time 20:41:56.593353
2019-05-16 20:41:56,594 [salt.state       :1813][INFO    ][13357] Executing state module.run for [maas.wait_for_machine_status]
2019-05-16 20:41:56,594 [salt.utils.decorators:613 ][WARNING ][13357] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:41:58,810 [salt.loaded.ext.module.maas:993 ][INFO    ][13357] Machine t48grb mark broken
2019-05-16 20:41:59,407 [salt.loaded.ext.module.maas:996 ][INFO    ][13357] Machine t48grb mark fixed
2019-05-16 20:42:00,263 [salt.loaded.ext.module.maas:684 ][INFO    ][13357] deploymachines hwe_kernel=hwe-16.04 system_id=t48grb distro_series=xenial
2019-05-16 20:42:03,910 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.69488287s left)
2019-05-16 20:42:06,170 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204206117160
2019-05-16 20:42:06,192 [salt.minion      :1432][INFO    ][13469] Starting a new job with PID 13469
2019-05-16 20:42:06,216 [salt.minion      :1711][INFO    ][13469] Returning information for job: 20190516204206117160
2019-05-16 20:42:36,213 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204236200011
2019-05-16 20:42:36,235 [salt.minion      :1432][INFO    ][13497] Starting a new job with PID 13497
2019-05-16 20:42:36,262 [salt.minion      :1711][INFO    ][13497] Returning information for job: 20190516204236200011
2019-05-16 20:42:37,420 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1459.18436003s left)
2019-05-16 20:43:06,270 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204306257841
2019-05-16 20:43:06,293 [salt.minion      :1432][INFO    ][13549] Starting a new job with PID 13549
2019-05-16 20:43:06,318 [salt.minion      :1711][INFO    ][13549] Returning information for job: 20190516204306257841
2019-05-16 20:43:10,887 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.71799207s left)
2019-05-16 20:43:36,324 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204336308359
2019-05-16 20:43:36,347 [salt.minion      :1432][INFO    ][13571] Starting a new job with PID 13571
2019-05-16 20:43:36,372 [salt.minion      :1711][INFO    ][13571] Returning information for job: 20190516204336308359
2019-05-16 20:43:44,030 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.57434797s left)
2019-05-16 20:44:06,383 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204406368180
2019-05-16 20:44:06,406 [salt.minion      :1432][INFO    ][13711] Starting a new job with PID 13711
2019-05-16 20:44:06,432 [salt.minion      :1711][INFO    ][13711] Returning information for job: 20190516204406368180
2019-05-16 20:44:17,648 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1358.95632696s left)
2019-05-16 20:44:36,446 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204436433410
2019-05-16 20:44:36,469 [salt.minion      :1432][INFO    ][13758] Starting a new job with PID 13758
2019-05-16 20:44:36,494 [salt.minion      :1711][INFO    ][13758] Returning information for job: 20190516204436433410
2019-05-16 20:44:51,132 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.47309899s left)
2019-05-16 20:45:06,504 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204506492039
2019-05-16 20:45:06,521 [salt.minion      :1432][INFO    ][13903] Starting a new job with PID 13903
2019-05-16 20:45:06,540 [salt.minion      :1711][INFO    ][13903] Returning information for job: 20190516204506492039
2019-05-16 20:45:24,792 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1291.81251907s left)
2019-05-16 20:45:36,551 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204536538611
2019-05-16 20:45:36,573 [salt.minion      :1432][INFO    ][13948] Starting a new job with PID 13948
2019-05-16 20:45:36,600 [salt.minion      :1711][INFO    ][13948] Returning information for job: 20190516204536538611
2019-05-16 20:45:58,199 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.40514708s left)
2019-05-16 20:46:06,625 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204606611213
2019-05-16 20:46:06,647 [salt.minion      :1432][INFO    ][14037] Starting a new job with PID 14037
2019-05-16 20:46:06,675 [salt.minion      :1711][INFO    ][14037] Returning information for job: 20190516204606611213
2019-05-16 20:46:31,673 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1224.93145585s left)
2019-05-16 20:46:36,688 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204636674938
2019-05-16 20:46:36,711 [salt.minion      :1432][INFO    ][14077] Starting a new job with PID 14077
2019-05-16 20:46:36,738 [salt.minion      :1711][INFO    ][14077] Returning information for job: 20190516204636674938
2019-05-16 20:47:05,343 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.26203299s left)
2019-05-16 20:47:06,765 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204706752360
2019-05-16 20:47:06,788 [salt.minion      :1432][INFO    ][14193] Starting a new job with PID 14193
2019-05-16 20:47:06,814 [salt.minion      :1711][INFO    ][14193] Returning information for job: 20190516204706752360
2019-05-16 20:47:36,846 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204736831118
2019-05-16 20:47:36,867 [salt.minion      :1432][INFO    ][14240] Starting a new job with PID 14240
2019-05-16 20:47:36,892 [salt.minion      :1711][INFO    ][14240] Returning information for job: 20190516204736831118
2019-05-16 20:47:38,967 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1157.63769197s left)
2019-05-16 20:48:06,925 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204806912007
2019-05-16 20:48:06,948 [salt.minion      :1432][INFO    ][14339] Starting a new job with PID 14339
2019-05-16 20:48:06,973 [salt.minion      :1711][INFO    ][14339] Returning information for job: 20190516204806912007
2019-05-16 20:48:12,476 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.12901187s left)
2019-05-16 20:48:37,016 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204837003098
2019-05-16 20:48:37,040 [salt.minion      :1432][INFO    ][14381] Starting a new job with PID 14381
2019-05-16 20:48:37,066 [salt.minion      :1711][INFO    ][14381] Returning information for job: 20190516204837003098
2019-05-16 20:48:46,171 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1090.43377304s left)
2019-05-16 20:49:07,117 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204907103417
2019-05-16 20:49:07,139 [salt.minion      :1432][INFO    ][14465] Starting a new job with PID 14465
2019-05-16 20:49:07,165 [salt.minion      :1711][INFO    ][14465] Returning information for job: 20190516204907103417
2019-05-16 20:49:19,668 [salt.loaded.ext.module.maas:1023][INFO    ][13357] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1056.93646789s left)
2019-05-16 20:49:37,176 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command saltutil.find_job with jid 20190516204937163665
2019-05-16 20:49:37,199 [salt.minion      :1432][INFO    ][14522] Starting a new job with PID 14522
2019-05-16 20:49:37,223 [salt.minion      :1711][INFO    ][14522] Returning information for job: 20190516204937163665
2019-05-16 20:49:53,287 [salt.state       :300 ][INFO    ][13357] {'ret': True}
2019-05-16 20:49:53,288 [salt.state       :1951][INFO    ][13357] Completed state [maas.wait_for_machine_status] at time 20:49:53.287989 duration_in_ms=476694.634
2019-05-16 20:49:53,291 [salt.minion      :1711][INFO    ][13357] Returning information for job: 20190516204151076371
2019-05-16 20:49:53,882 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516204953868898
2019-05-16 20:49:53,903 [salt.minion      :1432][INFO    ][14552] Starting a new job with PID 14552
2019-05-16 20:49:57,697 [salt.state       :915 ][INFO    ][14552] Loading fresh modules for state activity
2019-05-16 20:49:57,829 [salt.state       :1780][INFO    ][14552] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:49:57.829809
2019-05-16 20:49:57,830 [salt.state       :1813][INFO    ][14552] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:49:57,831 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14552] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:49:59,269 [salt.state       :300 ][INFO    ][14552] {'pid': 14559, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:49:59,270 [salt.state       :1951][INFO    ][14552] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:49:59.270104 duration_in_ms=1440.296
2019-05-16 20:49:59,271 [salt.state       :1780][INFO    ][14552] Running state [maas_machines_storage_cmp002_lvm] at time 20:49:59.271592
2019-05-16 20:49:59,271 [salt.state       :1813][INFO    ][14552] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-16 20:49:59,891 [salt.state       :300 ][INFO    ][14552] Machine cmp002 is not in Ready state.
2019-05-16 20:49:59,892 [salt.state       :1951][INFO    ][14552] Completed state [maas_machines_storage_cmp002_lvm] at time 20:49:59.892295 duration_in_ms=620.699
2019-05-16 20:49:59,893 [salt.state       :1780][INFO    ][14552] Running state [maas_machines_storage_cmp001_lvm] at time 20:49:59.893202
2019-05-16 20:49:59,893 [salt.state       :1813][INFO    ][14552] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-16 20:50:00,644 [salt.state       :300 ][INFO    ][14552] Machine cmp001 is not in Ready state.
2019-05-16 20:50:00,644 [salt.state       :1951][INFO    ][14552] Completed state [maas_machines_storage_cmp001_lvm] at time 20:50:00.644742 duration_in_ms=751.538
2019-05-16 20:50:00,649 [salt.minion      :1711][INFO    ][14552] Returning information for job: 20190516204953868898
2019-05-16 20:50:01,277 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516205001263820
2019-05-16 20:50:01,296 [salt.minion      :1432][INFO    ][14586] Starting a new job with PID 14586
2019-05-16 20:50:02,025 [salt.state       :915 ][INFO    ][14586] Loading fresh modules for state activity
2019-05-16 20:50:02,115 [salt.state       :1780][INFO    ][14586] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:50:02.115684
2019-05-16 20:50:02,116 [salt.state       :1813][INFO    ][14586] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:50:02,118 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14586] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:50:03,713 [salt.state       :300 ][INFO    ][14586] {'pid': 14593, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:50:03,714 [salt.state       :1951][INFO    ][14586] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:50:03.713999 duration_in_ms=1598.314
2019-05-16 20:50:03,716 [salt.state       :1780][INFO    ][14586] Running state [maas.deploy_machines] at time 20:50:03.716535
2019-05-16 20:50:03,717 [salt.state       :1813][INFO    ][14586] Executing state module.run for [maas.deploy_machines]
2019-05-16 20:50:03,718 [salt.utils.decorators:613 ][WARNING ][14586] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:50:04,459 [salt.state       :300 ][INFO    ][14586] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-16 20:50:04,459 [salt.state       :1951][INFO    ][14586] Completed state [maas.deploy_machines] at time 20:50:04.459872 duration_in_ms=743.337
2019-05-16 20:50:04,463 [salt.minion      :1711][INFO    ][14586] Returning information for job: 20190516205001263820
2019-05-16 20:50:05,080 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command state.apply with jid 20190516205005066138
2019-05-16 20:50:05,103 [salt.minion      :1432][INFO    ][14602] Starting a new job with PID 14602
2019-05-16 20:50:05,846 [salt.state       :915 ][INFO    ][14602] Loading fresh modules for state activity
2019-05-16 20:50:05,895 [salt.state       :1780][INFO    ][14602] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:50:05.895590
2019-05-16 20:50:05,895 [salt.state       :1813][INFO    ][14602] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-16 20:50:05,897 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14602] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-16 20:50:07,084 [salt.state       :300 ][INFO    ][14602] {'pid': 14669, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-16 20:50:07,085 [salt.state       :1951][INFO    ][14602] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:50:07.085168 duration_in_ms=1189.578
2019-05-16 20:50:07,087 [salt.state       :1780][INFO    ][14602] Running state [maas.wait_for_machine_status] at time 20:50:07.087457
2019-05-16 20:50:07,087 [salt.state       :1813][INFO    ][14602] Executing state module.run for [maas.wait_for_machine_status]
2019-05-16 20:50:07,088 [salt.utils.decorators:613 ][WARNING ][14602] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-16 20:50:10,689 [salt.state       :300 ][INFO    ][14602] {'ret': True}
2019-05-16 20:50:10,690 [salt.state       :1951][INFO    ][14602] Completed state [maas.wait_for_machine_status] at time 20:50:10.690208 duration_in_ms=3602.748
2019-05-16 20:50:10,694 [salt.minion      :1711][INFO    ][14602] Returning information for job: 20190516205005066138
2019-05-16 21:20:18,478 [salt.utils.schedule:1377][INFO    ][6428] Running scheduled job: __mine_interval
2019-05-16 22:14:19,860 [salt.minion      :1308][INFO    ][6428] User sudo_ubuntu Executing command cp.push_dir with jid 20190516221419847250
2019-05-16 22:14:19,879 [salt.minion      :1432][INFO    ][20636] Starting a new job with PID 20636
