2019-09-25 05:09:33,269 [salt.utils.decorators:613 ][WARNING ][2274] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:09:33,769 [salt.utils.decorators:613 ][WARNING ][2274] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:09:35,877 [salt.loaded.int.states.file:2298][WARNING ][2512] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-09-25 05:10:00,497 [salt.state       :2022][WARNING ][3095] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-25 05:10:02,905 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:10:25,214 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:01,260 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:02,255 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:05,702 [salt.loaded.ext.module.maasng:1008][WARNING ][3095] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-09-25 05:11:05,702 [salt.loaded.ext.module.maasng:1011][WARNING ][3095] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-09-25 05:11:06,180 [salt.loaded.ext.module.maasng:1235][WARNING ][3095] Ignoring parameter vlan:0
2019-09-25 05:11:06,895 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:12,577 [salt.utils.decorators:613 ][WARNING ][6243] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:12,632 [salt.loaded.ext.module.maas:412 ][WARNING ][6243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:11:14,117 [salt.loaded.ext.module.maas:412 ][WARNING ][6243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:11:15,250 [salt.loaded.ext.module.maas:412 ][WARNING ][6243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:11:16,622 [salt.loaded.ext.module.maas:412 ][WARNING ][6243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:11:17,980 [salt.loaded.ext.module.maas:412 ][WARNING ][6243] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:11:21,480 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6824] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-25 05:11:21,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6824] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-09-25 05:11:21,537 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-09-25 05:11:22,582 [salt.cli.daemons :293 ][INFO    ][6875] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-09-25 05:11:22,676 [salt.cli.daemons :82  ][INFO    ][6875] Starting up the Salt Minion
2019-09-25 05:11:22,677 [salt.utils.event :1017][INFO    ][6875] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-09-25 05:11:23,547 [salt.minion      :976 ][INFO    ][6875] Creating minion process manager
2019-09-25 05:11:25,090 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6875] Executing command ['date', '+%z'] in directory '/root'
2019-09-25 05:11:25,110 [salt.utils.schedule:568 ][INFO    ][6875] Updating job settings for scheduled job: __mine_interval
2019-09-25 05:11:25,112 [salt.minion      :1108][INFO    ][6875] Added mine.update to scheduler
2019-09-25 05:11:25,116 [salt.minion      :1975][INFO    ][6875] Minion is starting as user 'root'
2019-09-25 05:11:25,127 [salt.minion      :2336][INFO    ][6875] Minion is ready to receive requests!
2019-09-25 05:11:50,127 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925051150114850
2019-09-25 05:11:50,150 [salt.minion      :1432][INFO    ][7138] Starting a new job with PID 7138
2019-09-25 05:11:53,844 [salt.state       :915 ][INFO    ][7138] Loading fresh modules for state activity
2019-09-25 05:11:53,895 [salt.fileclient  :1219][INFO    ][7138] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-09-25 05:11:53,936 [salt.state       :1780][INFO    ][7138] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:53.936313
2019-09-25 05:11:53,936 [salt.state       :1813][INFO    ][7138] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:11:53,938 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7138] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:11:55,364 [salt.state       :300 ][INFO    ][7138] {'pid': 7145, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:11:55,365 [salt.state       :1951][INFO    ][7138] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:11:55.365285 duration_in_ms=1428.973
2019-09-25 05:11:55,366 [salt.state       :1780][INFO    ][7138] Running state [maas.wait_for_machine_status] at time 05:11:55.366756
2019-09-25 05:11:55,367 [salt.state       :1813][INFO    ][7138] Executing state module.run for [maas.wait_for_machine_status]
2019-09-25 05:11:55,367 [salt.utils.decorators:613 ][WARNING ][7138] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:11:56,232 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.13973904s left)
2019-09-25 05:12:05,238 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051205225328
2019-09-25 05:12:05,260 [salt.minion      :1432][INFO    ][7211] Starting a new job with PID 7211
2019-09-25 05:12:05,284 [salt.minion      :1711][INFO    ][7211] Returning information for job: 20190925051205225328
2019-09-25 05:12:27,230 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.14107609s left)
2019-09-25 05:12:35,299 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051235283758
2019-09-25 05:12:35,322 [salt.minion      :1432][INFO    ][7241] Starting a new job with PID 7241
2019-09-25 05:12:35,345 [salt.minion      :1711][INFO    ][7241] Returning information for job: 20190925051235283758
2019-09-25 05:12:58,249 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.12193012s left)
2019-09-25 05:13:05,357 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051305345431
2019-09-25 05:13:05,376 [salt.minion      :1432][INFO    ][7389] Starting a new job with PID 7389
2019-09-25 05:13:05,387 [salt.minion      :1711][INFO    ][7389] Returning information for job: 20190925051305345431
2019-09-25 05:13:29,664 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.70762205s left)
2019-09-25 05:13:35,391 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051335378790
2019-09-25 05:13:35,413 [salt.minion      :1432][INFO    ][7601] Starting a new job with PID 7601
2019-09-25 05:13:35,437 [salt.minion      :1711][INFO    ][7601] Returning information for job: 20190925051335378790
2019-09-25 05:14:01,264 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.10691404s left)
2019-09-25 05:14:05,454 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051405444408
2019-09-25 05:14:05,468 [salt.minion      :1432][INFO    ][8131] Starting a new job with PID 8131
2019-09-25 05:14:05,480 [salt.minion      :1711][INFO    ][8131] Returning information for job: 20190925051405444408
2019-09-25 05:14:33,056 [salt.loaded.ext.module.maas:1023][INFO    ][7138] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.31549001s left)
2019-09-25 05:14:35,494 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051435477005
2019-09-25 05:14:35,516 [salt.minion      :1432][INFO    ][8297] Starting a new job with PID 8297
2019-09-25 05:14:35,542 [salt.minion      :1711][INFO    ][8297] Returning information for job: 20190925051435477005
2019-09-25 05:15:05,565 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051505549408
2019-09-25 05:15:05,590 [salt.minion      :1432][INFO    ][8484] Starting a new job with PID 8484
2019-09-25 05:15:05,612 [salt.minion      :1711][INFO    ][8484] Returning information for job: 20190925051505549408
2019-09-25 05:15:06,465 [salt.state       :300 ][INFO    ][7138] {'ret': True}
2019-09-25 05:15:06,465 [salt.state       :1951][INFO    ][7138] Completed state [maas.wait_for_machine_status] at time 05:15:06.465758 duration_in_ms=191099.0
2019-09-25 05:15:06,470 [salt.minion      :1711][INFO    ][7138] Returning information for job: 20190925051150114850
2019-09-25 05:15:07,121 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925051507108825
2019-09-25 05:15:07,142 [salt.minion      :1432][INFO    ][8492] Starting a new job with PID 8492
2019-09-25 05:15:11,136 [salt.state       :915 ][INFO    ][8492] Loading fresh modules for state activity
2019-09-25 05:15:11,190 [salt.fileclient  :1219][INFO    ][8492] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-09-25 05:15:11,275 [salt.state       :1780][INFO    ][8492] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:11.275129
2019-09-25 05:15:11,275 [salt.state       :1813][INFO    ][8492] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:15:11,277 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8492] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:15:12,844 [salt.state       :300 ][INFO    ][8492] {'pid': 8501, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:15:12,845 [salt.state       :1951][INFO    ][8492] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:12.845244 duration_in_ms=1570.114
2019-09-25 05:15:12,848 [salt.state       :1780][INFO    ][8492] Running state [maas_machines_storage_cmp002_lvm] at time 05:15:12.848634
2019-09-25 05:15:12,849 [salt.state       :1813][INFO    ][8492] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-25 05:15:14,137 [salt.loaded.ext.module.maasng:610 ][INFO    ][8492] tbker4
2019-09-25 05:15:14,137 [salt.loaded.ext.module.maasng:626 ][INFO    ][8492] sda
2019-09-25 05:15:14,865 [salt.loaded.ext.module.maasng:361 ][INFO    ][8492] tbker4
2019-09-25 05:15:14,984 [salt.loaded.ext.module.maasng:367 ][INFO    ][8492] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'99aceea6-d927-4e89-83b0-8f668d06876c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'tbker4', u'device_id': 4, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'b6de82cd-7a9a-41cc-81b8-aaf28a1d440d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'tbker4', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/'}, {u'size': 2397988454400, u'model': None, u'uuid': u'0570cf6c-4d6a-4132-9b23-1751777e7973', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'tbker4', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'd01389fc-bff3-4690-ac68-85de66ea013a', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/11/'}]
2019-09-25 05:15:14,985 [salt.loaded.ext.module.maasng:632 ][INFO    ][8492] vgroot
2019-09-25 05:15:14,985 [salt.loaded.ext.module.maasng:635 ][INFO    ][8492] lvroot
2019-09-25 05:15:14,985 [salt.loaded.ext.module.maasng:639 ][INFO    ][8492] 107374182400
2019-09-25 05:15:15,548 [salt.loaded.ext.module.maasng:645 ][INFO    ][8492] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'72c2a8cb-6d36-4b01-99ac-f36dec2c47c4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'tbker4', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'25aa927c-fda3-4078-b657-60839089f4c9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/partition/8'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'tbker4', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', 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'resource_uri': u'/MAAS/api/2.0/machines/tbker4/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'status_action': u'', u'system_id': u'tbker4', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"From 'Testing' to 'Ready'", u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/13/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'94cdf33b-dc0a-435c-aac0-bd29352a33d3', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'6ea3b3ed-8c29-46c1-89c9-f9fdfdb610f8', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'tbker4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'72c2a8cb-6d36-4b01-99ac-f36dec2c47c4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'tbker4', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'25aa927c-fda3-4078-b657-60839089f4c9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/partition/8'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'tbker4', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/13/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'94cdf33b-dc0a-435c-aac0-bd29352a33d3', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'6ea3b3ed-8c29-46c1-89c9-f9fdfdb610f8', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'tbker4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'on', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'72c2a8cb-6d36-4b01-99ac-f36dec2c47c4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'tbker4', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'25aa927c-fda3-4078-b657-60839089f4c9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/blockdevices/4/partition/8'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'tbker4', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'tbker4', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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.42', u'id': 39, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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.42'}], u'parents': [], u'system_id': u'tbker4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/interfaces/4/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'enp7s0', u'links': [{u'id': 40, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6b', u'enabled': True, u'id': 18, u'discovered': None, u'parents': [], u'system_id': u'tbker4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/interfaces/18/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'enp9s0', u'links': [{u'id': 41, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6d', u'enabled': True, u'id': 19, u'discovered': None, u'parents': [], u'system_id': u'tbker4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/interfaces/19/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'enp8s0', u'links': [{u'id': 42, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6c', u'enabled': True, u'id': 21, u'discovered': None, u'parents': [], u'system_id': u'tbker4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/interfaces/21/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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.42', u'id': 39, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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.42'}], u'parents': [], u'system_id': u'tbker4', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/tbker4/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-09-25 05:15:15,551 [salt.state       :300 ][INFO    ][8492] {'new': {'storage_layout': 'lvm'}}
2019-09-25 05:15:15,551 [salt.state       :1951][INFO    ][8492] Completed state [maas_machines_storage_cmp002_lvm] at time 05:15:15.551423 duration_in_ms=2702.788
2019-09-25 05:15:15,552 [salt.state       :1780][INFO    ][8492] Running state [maas_machines_storage_cmp001_lvm] at time 05:15:15.552016
2019-09-25 05:15:15,552 [salt.state       :1813][INFO    ][8492] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-25 05:15:16,825 [salt.loaded.ext.module.maasng:610 ][INFO    ][8492] kqxb4b
2019-09-25 05:15:16,826 [salt.loaded.ext.module.maasng:626 ][INFO    ][8492] sda
2019-09-25 05:15:17,532 [salt.loaded.ext.module.maasng:361 ][INFO    ][8492] kqxb4b
2019-09-25 05:15:17,658 [salt.loaded.ext.module.maasng:367 ][INFO    ][8492] [{u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'4b8fdd87-fd69-4336-aa94-876ed2f49815', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kqxb4b', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'd22f844f-238d-49bc-ba18-5ccaf4e93fe5', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/partition/5'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kqxb4b', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/10/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'dac8cd3e-8652-4280-82be-22061ef2f43a', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'c7b51ae2-d973-40b6-ac2e-7fafc2d74776', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'kqxb4b', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'serial': None, u'size': 2397988454400}]
2019-09-25 05:15:17,659 [salt.loaded.ext.module.maasng:632 ][INFO    ][8492] vgroot
2019-09-25 05:15:17,659 [salt.loaded.ext.module.maasng:635 ][INFO    ][8492] lvroot
2019-09-25 05:15:17,659 [salt.loaded.ext.module.maasng:639 ][INFO    ][8492] 107374182400
2019-09-25 05:15:18,318 [salt.loaded.ext.module.maasng:645 ][INFO    ][8492] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'ac6ac797-b573-43a9-9ec1-241e9f647eae', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kqxb4b', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'af5fe875-7eda-4dec-9529-24722b6c57f8', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/partition/9'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kqxb4b', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', 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'resource_uri': u'/MAAS/api/2.0/machines/kqxb4b/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'status_action': u'', u'system_id': u'kqxb4b', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/14/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'c4b7b809-d9bb-4e79-ac18-036255e1c571', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'ae315f27-ecaf-4116-88e0-cb439764718a', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'kqxb4b', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 14, u'serial': None, u'size': 107374182400}], u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'ac6ac797-b573-43a9-9ec1-241e9f647eae', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kqxb4b', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'af5fe875-7eda-4dec-9529-24722b6c57f8', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/partition/9'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kqxb4b', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/14/', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'c4b7b809-d9bb-4e79-ac18-036255e1c571', u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'ae315f27-ecaf-4116-88e0-cb439764718a', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'kqxb4b', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 14, u'serial': None, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'ac6ac797-b573-43a9-9ec1-241e9f647eae', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'kqxb4b', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'af5fe875-7eda-4dec-9529-24722b6c57f8', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/blockdevices/1/partition/9'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'kqxb4b', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'ip_addresses': [u'192.168.11.38'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'kqxb4b', u'id': 9}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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': 33, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'system_id': u'kqxb4b', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/interfaces/5/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'enp7s0', u'links': [{u'id': 34, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'id': 15, u'discovered': None, u'parents': [], u'system_id': u'kqxb4b', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/interfaces/15/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'name': u'enp8s0', u'links': [{u'id': 35, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'id': 16, u'discovered': None, u'parents': [], u'system_id': u'kqxb4b', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/interfaces/16/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'enp9s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'id': 17, u'discovered': None, u'parents': [], u'system_id': u'kqxb4b', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/interfaces/17/'}], 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'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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': 33, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'system_id': u'kqxb4b', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/kqxb4b/interfaces/5/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-09-25 05:15:18,320 [salt.state       :300 ][INFO    ][8492] {'new': {'storage_layout': 'lvm'}}
2019-09-25 05:15:18,320 [salt.state       :1951][INFO    ][8492] Completed state [maas_machines_storage_cmp001_lvm] at time 05:15:18.320552 duration_in_ms=2768.536
2019-09-25 05:15:18,324 [salt.minion      :1711][INFO    ][8492] Returning information for job: 20190925051507108825
2019-09-25 05:15:18,961 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925051518951573
2019-09-25 05:15:18,984 [salt.minion      :1432][INFO    ][8544] Starting a new job with PID 8544
2019-09-25 05:15:19,855 [salt.state       :915 ][INFO    ][8544] Loading fresh modules for state activity
2019-09-25 05:15:19,896 [salt.fileclient  :1219][INFO    ][8544] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-09-25 05:15:19,933 [salt.state       :1780][INFO    ][8544] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:19.933098
2019-09-25 05:15:19,933 [salt.state       :1813][INFO    ][8544] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:15:19,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8544] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:15:21,153 [salt.state       :300 ][INFO    ][8544] {'pid': 8567, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:15:21,153 [salt.state       :1951][INFO    ][8544] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:21.153870 duration_in_ms=1220.772
2019-09-25 05:15:21,156 [salt.state       :1780][INFO    ][8544] Running state [maas.deploy_machines] at time 05:15:21.156379
2019-09-25 05:15:21,157 [salt.state       :1813][INFO    ][8544] Executing state module.run for [maas.deploy_machines]
2019-09-25 05:15:21,158 [salt.utils.decorators:613 ][WARNING ][8544] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:15:21,586 [salt.loaded.ext.module.maas:684 ][INFO    ][8544] deploymachines hwe_kernel=hwe-16.04 system_id=tbker4 distro_series=xenial
2019-09-25 05:15:23,959 [salt.loaded.ext.module.maas:684 ][INFO    ][8544] deploymachines hwe_kernel=hwe-16.04 system_id=kqxb4b distro_series=xenial
2019-09-25 05:15:26,695 [salt.loaded.ext.module.maas:684 ][INFO    ][8544] deploymachines hwe_kernel=hwe-16.04 system_id=86twkk distro_series=xenial
2019-09-25 05:15:28,950 [salt.loaded.ext.module.maas:684 ][INFO    ][8544] deploymachines hwe_kernel=hwe-16.04 system_id=cwb8sr distro_series=xenial
2019-09-25 05:15:31,549 [salt.loaded.ext.module.maas:684 ][INFO    ][8544] deploymachines hwe_kernel=hwe-16.04 system_id=nm88fy distro_series=xenial
2019-09-25 05:15:33,682 [salt.state       :300 ][INFO    ][8544] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-09-25 05:15:33,683 [salt.state       :1951][INFO    ][8544] Completed state [maas.deploy_machines] at time 05:15:33.683573 duration_in_ms=12527.191
2019-09-25 05:15:33,710 [salt.minion      :1711][INFO    ][8544] Returning information for job: 20190925051518951573
2019-09-25 05:15:34,362 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925051534346101
2019-09-25 05:15:34,384 [salt.minion      :1432][INFO    ][8853] Starting a new job with PID 8853
2019-09-25 05:15:38,109 [salt.state       :915 ][INFO    ][8853] Loading fresh modules for state activity
2019-09-25 05:15:38,137 [salt.fileclient  :1219][INFO    ][8853] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-09-25 05:15:38,164 [salt.state       :1780][INFO    ][8853] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:38.164220
2019-09-25 05:15:38,164 [salt.state       :1813][INFO    ][8853] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:15:38,165 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8853] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:15:39,771 [salt.state       :300 ][INFO    ][8853] {'pid': 8866, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:15:39,772 [salt.state       :1951][INFO    ][8853] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:39.772433 duration_in_ms=1608.212
2019-09-25 05:15:39,775 [salt.state       :1780][INFO    ][8853] Running state [maas.wait_for_machine_status] at time 05:15:39.775454
2019-09-25 05:15:39,776 [salt.state       :1813][INFO    ][8853] Executing state module.run for [maas.wait_for_machine_status]
2019-09-25 05:15:39,776 [salt.utils.decorators:613 ][WARNING ][8853] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:15:43,411 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.37474394s left)
2019-09-25 05:15:49,402 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051549389441
2019-09-25 05:15:49,426 [salt.minion      :1432][INFO    ][8879] Starting a new job with PID 8879
2019-09-25 05:15:49,449 [salt.minion      :1711][INFO    ][8879] Returning information for job: 20190925051549389441
2019-09-25 05:16:17,070 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.71571994s left)
2019-09-25 05:16:19,463 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051619447642
2019-09-25 05:16:19,486 [salt.minion      :1432][INFO    ][8918] Starting a new job with PID 8918
2019-09-25 05:16:19,508 [salt.minion      :1711][INFO    ][8918] Returning information for job: 20190925051619447642
2019-09-25 05:16:49,562 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051649548633
2019-09-25 05:16:49,582 [salt.minion      :1432][INFO    ][8952] Starting a new job with PID 8952
2019-09-25 05:16:49,606 [salt.minion      :1711][INFO    ][8952] Returning information for job: 20190925051649548633
2019-09-25 05:16:50,742 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.04407406s left)
2019-09-25 05:17:19,609 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051719596930
2019-09-25 05:17:19,626 [salt.minion      :1432][INFO    ][9080] Starting a new job with PID 9080
2019-09-25 05:17:19,638 [salt.minion      :1711][INFO    ][9080] Returning information for job: 20190925051719596930
2019-09-25 05:17:24,250 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2145.5356319s left)
2019-09-25 05:17:49,647 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051749634234
2019-09-25 05:17:49,670 [salt.minion      :1432][INFO    ][9280] Starting a new job with PID 9280
2019-09-25 05:17:49,694 [salt.minion      :1711][INFO    ][9280] Returning information for job: 20190925051749634234
2019-09-25 05:17:57,390 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.39575601s left)
2019-09-25 05:18:19,709 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051819695347
2019-09-25 05:18:19,732 [salt.minion      :1432][INFO    ][9800] Starting a new job with PID 9800
2019-09-25 05:18:19,755 [salt.minion      :1711][INFO    ][9800] Returning information for job: 20190925051819695347
2019-09-25 05:18:30,260 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.52576303s left)
2019-09-25 05:18:49,771 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051849758896
2019-09-25 05:18:49,794 [salt.minion      :1432][INFO    ][10013] Starting a new job with PID 10013
2019-09-25 05:18:49,817 [salt.minion      :1711][INFO    ][10013] Returning information for job: 20190925051849758896
2019-09-25 05:19:03,504 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.28176498s left)
2019-09-25 05:19:19,835 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051919822167
2019-09-25 05:19:19,858 [salt.minion      :1432][INFO    ][10199] Starting a new job with PID 10199
2019-09-25 05:19:19,881 [salt.minion      :1711][INFO    ][10199] Returning information for job: 20190925051919822167
2019-09-25 05:19:36,986 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.79998302s left)
2019-09-25 05:19:49,900 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925051949887097
2019-09-25 05:19:49,923 [salt.minion      :1432][INFO    ][10264] Starting a new job with PID 10264
2019-09-25 05:19:49,947 [salt.minion      :1711][INFO    ][10264] Returning information for job: 20190925051949887097
2019-09-25 05:20:10,311 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.47505999s left)
2019-09-25 05:20:19,973 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052019959347
2019-09-25 05:20:19,996 [salt.minion      :1432][INFO    ][10618] Starting a new job with PID 10618
2019-09-25 05:20:20,019 [salt.minion      :1711][INFO    ][10618] Returning information for job: 20190925052019959347
2019-09-25 05:20:43,330 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.45572495s left)
2019-09-25 05:20:50,051 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052050038983
2019-09-25 05:20:50,074 [salt.minion      :1432][INFO    ][10788] Starting a new job with PID 10788
2019-09-25 05:20:50,100 [salt.minion      :1711][INFO    ][10788] Returning information for job: 20190925052050038983
2019-09-25 05:21:16,681 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.10495901s left)
2019-09-25 05:21:20,131 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052120119290
2019-09-25 05:21:20,155 [salt.minion      :1432][INFO    ][11184] Starting a new job with PID 11184
2019-09-25 05:21:20,180 [salt.minion      :1711][INFO    ][11184] Returning information for job: 20190925052120119290
2019-09-25 05:21:49,798 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.98729992s left)
2019-09-25 05:21:50,216 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052150203700
2019-09-25 05:21:50,240 [salt.minion      :1432][INFO    ][11287] Starting a new job with PID 11287
2019-09-25 05:21:50,265 [salt.minion      :1711][INFO    ][11287] Returning information for job: 20190925052150203700
2019-09-25 05:22:20,307 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052220294842
2019-09-25 05:22:20,330 [salt.minion      :1432][INFO    ][11383] Starting a new job with PID 11383
2019-09-25 05:22:20,352 [salt.minion      :1711][INFO    ][11383] Returning information for job: 20190925052220294842
2019-09-25 05:22:23,467 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.31821585s left)
2019-09-25 05:22:50,410 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052250395145
2019-09-25 05:22:50,425 [salt.minion      :1432][INFO    ][11499] Starting a new job with PID 11499
2019-09-25 05:22:50,452 [salt.minion      :1711][INFO    ][11499] Returning information for job: 20190925052250395145
2019-09-25 05:22:56,782 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.00379086s left)
2019-09-25 05:23:20,581 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052320570021
2019-09-25 05:23:20,604 [salt.minion      :1432][INFO    ][11714] Starting a new job with PID 11714
2019-09-25 05:23:20,629 [salt.minion      :1711][INFO    ][11714] Returning information for job: 20190925052320570021
2019-09-25 05:23:30,201 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1779.58507991s left)
2019-09-25 05:23:50,698 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052350686274
2019-09-25 05:23:50,722 [salt.minion      :1432][INFO    ][11889] Starting a new job with PID 11889
2019-09-25 05:23:50,746 [salt.minion      :1711][INFO    ][11889] Returning information for job: 20190925052350686274
2019-09-25 05:24:03,480 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1746.30579901s left)
2019-09-25 05:24:20,813 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052420800362
2019-09-25 05:24:20,836 [salt.minion      :1432][INFO    ][12212] Starting a new job with PID 12212
2019-09-25 05:24:20,858 [salt.minion      :1711][INFO    ][12212] Returning information for job: 20190925052420800362
2019-09-25 05:24:36,806 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1712.97943306s left)
2019-09-25 05:24:50,931 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052450918890
2019-09-25 05:24:50,953 [salt.minion      :1432][INFO    ][12247] Starting a new job with PID 12247
2019-09-25 05:24:50,978 [salt.minion      :1711][INFO    ][12247] Returning information for job: 20190925052450918890
2019-09-25 05:25:10,312 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1679.4736979s left)
2019-09-25 05:25:21,063 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052521049988
2019-09-25 05:25:21,085 [salt.minion      :1432][INFO    ][12288] Starting a new job with PID 12288
2019-09-25 05:25:21,108 [salt.minion      :1711][INFO    ][12288] Returning information for job: 20190925052521049988
2019-09-25 05:25:43,987 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1645.79903007s left)
2019-09-25 05:25:51,199 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052551185893
2019-09-25 05:25:51,222 [salt.minion      :1432][INFO    ][12324] Starting a new job with PID 12324
2019-09-25 05:25:51,246 [salt.minion      :1711][INFO    ][12324] Returning information for job: 20190925052551185893
2019-09-25 05:26:17,653 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1612.13276792s left)
2019-09-25 05:26:21,339 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052621325989
2019-09-25 05:26:21,361 [salt.minion      :1432][INFO    ][12365] Starting a new job with PID 12365
2019-09-25 05:26:21,386 [salt.minion      :1711][INFO    ][12365] Returning information for job: 20190925052621325989
2019-09-25 05:26:50,968 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1578.81756496s left)
2019-09-25 05:26:51,499 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052651486507
2019-09-25 05:26:51,522 [salt.minion      :1432][INFO    ][12404] Starting a new job with PID 12404
2019-09-25 05:26:51,545 [salt.minion      :1711][INFO    ][12404] Returning information for job: 20190925052651486507
2019-09-25 05:27:21,669 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052721653572
2019-09-25 05:27:21,689 [salt.minion      :1432][INFO    ][12447] Starting a new job with PID 12447
2019-09-25 05:27:21,713 [salt.minion      :1711][INFO    ][12447] Returning information for job: 20190925052721653572
2019-09-25 05:27:24,462 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1545.323982s left)
2019-09-25 05:27:51,846 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052751830944
2019-09-25 05:27:51,869 [salt.minion      :1432][INFO    ][12489] Starting a new job with PID 12489
2019-09-25 05:27:51,892 [salt.minion      :1711][INFO    ][12489] Returning information for job: 20190925052751830944
2019-09-25 05:27:57,930 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1511.8554759s left)
2019-09-25 05:28:22,029 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052822016246
2019-09-25 05:28:22,052 [salt.minion      :1432][INFO    ][12531] Starting a new job with PID 12531
2019-09-25 05:28:22,074 [salt.minion      :1711][INFO    ][12531] Returning information for job: 20190925052822016246
2019-09-25 05:28:31,409 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1478.3767879s left)
2019-09-25 05:28:52,221 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052852208974
2019-09-25 05:28:52,244 [salt.minion      :1432][INFO    ][12567] Starting a new job with PID 12567
2019-09-25 05:28:52,267 [salt.minion      :1711][INFO    ][12567] Returning information for job: 20190925052852208974
2019-09-25 05:29:04,875 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1444.91024804s left)
2019-09-25 05:29:22,428 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052922415542
2019-09-25 05:29:22,452 [salt.minion      :1432][INFO    ][12608] Starting a new job with PID 12608
2019-09-25 05:29:22,476 [salt.minion      :1711][INFO    ][12608] Returning information for job: 20190925052922415542
2019-09-25 05:29:38,307 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1411.47841001s left)
2019-09-25 05:29:52,640 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925052952627459
2019-09-25 05:29:52,663 [salt.minion      :1432][INFO    ][12647] Starting a new job with PID 12647
2019-09-25 05:29:52,688 [salt.minion      :1711][INFO    ][12647] Returning information for job: 20190925052952627459
2019-09-25 05:30:11,318 [salt.loaded.ext.module.maas:1023][INFO    ][8853] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1378.46739602s left)
2019-09-25 05:30:22,864 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053022852030
2019-09-25 05:30:22,886 [salt.minion      :1432][INFO    ][12833] Starting a new job with PID 12833
2019-09-25 05:30:22,909 [salt.minion      :1711][INFO    ][12833] Returning information for job: 20190925053022852030
2019-09-25 05:30:43,607 [salt.loaded.ext.module.maas:993 ][INFO    ][8853] Machine 86twkk mark broken
2019-09-25 05:30:44,374 [salt.loaded.ext.module.maas:996 ][INFO    ][8853] Machine 86twkk mark fixed
2019-09-25 05:30:45,595 [salt.loaded.ext.module.maas:684 ][INFO    ][8853] deploymachines hwe_kernel=hwe-16.04 system_id=86twkk distro_series=xenial
2019-09-25 05:30:48,261 [salt.loaded.ext.module.maas:160 ][ERROR   ][8853] 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-09-25 05:30:48,263 [salt.state       :302 ][ERROR   ][8853] 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-09-25 05:30:48,263 [salt.state       :1951][INFO    ][8853] Completed state [maas.wait_for_machine_status] at time 05:30:48.263555 duration_in_ms=908488.095
2019-09-25 05:30:48,273 [salt.minion      :1711][INFO    ][8853] Returning information for job: 20190925051534346101
2019-09-25 05:30:59,043 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command pillar.get with jid 20190925053059030987
2019-09-25 05:30:59,064 [salt.minion      :1432][INFO    ][12956] Starting a new job with PID 12956
2019-09-25 05:30:59,069 [salt.minion      :1711][INFO    ][12956] Returning information for job: 20190925053059030987
2019-09-25 05:30:59,569 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command service.status with jid 20190925053059557077
2019-09-25 05:30:59,591 [salt.minion      :1432][INFO    ][12961] Starting a new job with PID 12961
2019-09-25 05:30:59,987 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12961] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:00,021 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12961] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-25 05:31:00,037 [salt.minion      :1711][INFO    ][12961] Returning information for job: 20190925053059557077
2019-09-25 05:31:00,572 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925053100560732
2019-09-25 05:31:00,591 [salt.minion      :1432][INFO    ][12972] Starting a new job with PID 12972
2019-09-25 05:31:04,155 [salt.state       :915 ][INFO    ][12972] Loading fresh modules for state activity
2019-09-25 05:31:04,596 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'salt-minion --version' in directory '/root'
2019-09-25 05:31:04,962 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'salt-minion --version' in directory '/root'
2019-09-25 05:31:05,860 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'salt-minion --version' in directory '/root'
2019-09-25 05:31:06,222 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'salt-minion --version' in directory '/root'
2019-09-25 05:31:07,602 [salt.state       :1780][INFO    ][12972] Running state [salt-minion] at time 05:31:07.602683
2019-09-25 05:31:07,603 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [salt-minion]
2019-09-25 05:31:07,603 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-25 05:31:07,693 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:07,693 [salt.state       :1951][INFO    ][12972] Completed state [salt-minion] at time 05:31:07.693790 duration_in_ms=91.108
2019-09-25 05:31:07,694 [salt.state       :1780][INFO    ][12972] Running state [salt_minion_dependency_packages] at time 05:31:07.694110
2019-09-25 05:31:07,694 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-25 05:31:07,700 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:07,701 [salt.state       :1951][INFO    ][12972] Completed state [salt_minion_dependency_packages] at time 05:31:07.701011 duration_in_ms=6.901
2019-09-25 05:31:07,703 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/minion.d/minion.conf] at time 05:31:07.703935
2019-09-25 05:31:07,704 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-25 05:31:07,897 [salt.state       :300 ][INFO    ][12972] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-25 05:31:07,897 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/minion.d/minion.conf] at time 05:31:07.897635 duration_in_ms=193.699
2019-09-25 05:31:07,897 [salt.state       :1780][INFO    ][12972] Running state [python-netaddr] at time 05:31:07.897872
2019-09-25 05:31:07,898 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [python-netaddr]
2019-09-25 05:31:07,904 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:07,904 [salt.state       :1951][INFO    ][12972] Completed state [python-netaddr] at time 05:31:07.904936 duration_in_ms=7.064
2019-09-25 05:31:07,907 [salt.state       :1780][INFO    ][12972] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:31:07.907941
2019-09-25 05:31:07,908 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-25 05:31:07,918 [salt.state       :300 ][INFO    ][12972] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-25 05:31:07,919 [salt.state       :1951][INFO    ][12972] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:31:07.919167 duration_in_ms=11.226
2019-09-25 05:31:07,920 [salt.state       :1780][INFO    ][12972] Running state [salt-minion] at time 05:31:07.920126
2019-09-25 05:31:07,920 [salt.state       :1813][INFO    ][12972] Executing state service.running for [salt-minion]
2019-09-25 05:31:07,921 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:07,957 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-25 05:31:07,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-25 05:31:07,991 [salt.state       :300 ][INFO    ][12972] The service salt-minion is already running
2019-09-25 05:31:07,992 [salt.state       :1951][INFO    ][12972] Completed state [salt-minion] at time 05:31:07.992290 duration_in_ms=72.163
2019-09-25 05:31:07,994 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains.d] at time 05:31:07.994610
2019-09-25 05:31:07,995 [salt.state       :1813][INFO    ][12972] Executing state file.directory for [/etc/salt/grains.d]
2019-09-25 05:31:07,996 [salt.state       :300 ][INFO    ][12972] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-25 05:31:07,996 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains.d] at time 05:31:07.996767 duration_in_ms=2.156
2019-09-25 05:31:07,997 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains] at time 05:31:07.997767
2019-09-25 05:31:07,998 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/grains]
2019-09-25 05:31:07,999 [salt.state       :300 ][INFO    ][12972] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-25 05:31:07,999 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains] at time 05:31:07.999298 duration_in_ms=1.531
2019-09-25 05:31:08,000 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains.d/placeholder] at time 05:31:07.999966
2019-09-25 05:31:08,000 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-25 05:31:08,001 [salt.state       :300 ][INFO    ][12972] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-25 05:31:08,001 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains.d/placeholder] at time 05:31:08.001362 duration_in_ms=1.396
2019-09-25 05:31:08,002 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains.d/sphinx] at time 05:31:08.002021
2019-09-25 05:31:08,002 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-25 05:31:08,017 [salt.state       :300 ][INFO    ][12972] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-25 05:31:08,017 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains.d/sphinx] at time 05:31:08.017592 duration_in_ms=15.571
2019-09-25 05:31:08,020 [salt.state       :1780][INFO    ][12972] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.020629
2019-09-25 05:31:08,021 [salt.state       :1813][INFO    ][12972] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-25 05:31:08,021 [salt.state       :300 ][INFO    ][12972] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-25 05:31:08,021 [salt.state       :1951][INFO    ][12972] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.021829 duration_in_ms=1.2
2019-09-25 05:31:08,022 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains.d/dns_records] at time 05:31:08.022505
2019-09-25 05:31:08,022 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-25 05:31:08,035 [salt.state       :300 ][INFO    ][12972] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-25 05:31:08,035 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains.d/dns_records] at time 05:31:08.035301 duration_in_ms=12.795
2019-09-25 05:31:08,036 [salt.state       :1780][INFO    ][12972] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.036622
2019-09-25 05:31:08,037 [salt.state       :1813][INFO    ][12972] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-25 05:31:08,037 [salt.state       :300 ][INFO    ][12972] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-25 05:31:08,037 [salt.state       :1951][INFO    ][12972] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.037804 duration_in_ms=1.182
2019-09-25 05:31:08,038 [salt.state       :1780][INFO    ][12972] Running state [/etc/salt/grains.d/salt] at time 05:31:08.038457
2019-09-25 05:31:08,038 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-25 05:31:08,050 [salt.state       :300 ][INFO    ][12972] File /etc/salt/grains.d/salt is in the correct state
2019-09-25 05:31:08,050 [salt.state       :1951][INFO    ][12972] Completed state [/etc/salt/grains.d/salt] at time 05:31:08.050696 duration_in_ms=12.239
2019-09-25 05:31:08,051 [salt.state       :1780][INFO    ][12972] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.051924
2019-09-25 05:31:08,052 [salt.state       :1813][INFO    ][12972] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-25 05:31:08,052 [salt.state       :300 ][INFO    ][12972] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-25 05:31:08,053 [salt.state       :1951][INFO    ][12972] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:31:08.053100 duration_in_ms=1.177
2019-09-25 05:31:08,055 [salt.state       :1780][INFO    ][12972] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:31:08.055761
2019-09-25 05:31:08,056 [salt.state       :1813][INFO    ][12972] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-25 05:31:08,056 [salt.state       :300 ][INFO    ][12972] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-25 05:31:08,057 [salt.state       :1951][INFO    ][12972] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:31:08.056935 duration_in_ms=1.174
2019-09-25 05:31:08,057 [salt.state       :1780][INFO    ][12972] Running state [mine.update] at time 05:31:08.057888
2019-09-25 05:31:08,058 [salt.state       :1813][INFO    ][12972] Executing state module.wait for [mine.update]
2019-09-25 05:31:08,058 [salt.state       :300 ][INFO    ][12972] No changes made for mine.update
2019-09-25 05:31:08,059 [salt.state       :1951][INFO    ][12972] Completed state [mine.update] at time 05:31:08.058979 duration_in_ms=1.091
2019-09-25 05:31:08,059 [salt.state       :1780][INFO    ][12972] Running state [ca-certificates] at time 05:31:08.059318
2019-09-25 05:31:08,059 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [ca-certificates]
2019-09-25 05:31:08,069 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:08,070 [salt.state       :1951][INFO    ][12972] Completed state [ca-certificates] at time 05:31:08.069997 duration_in_ms=10.678
2019-09-25 05:31:08,071 [salt.state       :1780][INFO    ][12972] Running state [update-ca-certificates] at time 05:31:08.070942
2019-09-25 05:31:08,071 [salt.state       :1813][INFO    ][12972] Executing state cmd.wait for [update-ca-certificates]
2019-09-25 05:31:08,071 [salt.state       :300 ][INFO    ][12972] No changes made for update-ca-certificates
2019-09-25 05:31:08,072 [salt.state       :1951][INFO    ][12972] Completed state [update-ca-certificates] at time 05:31:08.072027 duration_in_ms=1.086
2019-09-25 05:31:08,072 [salt.state       :1780][INFO    ][12972] Running state [iptables] at time 05:31:08.072345
2019-09-25 05:31:08,072 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [iptables]
2019-09-25 05:31:08,081 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:08,081 [salt.state       :1951][INFO    ][12972] Completed state [iptables] at time 05:31:08.081901 duration_in_ms=9.555
2019-09-25 05:31:08,082 [salt.state       :1780][INFO    ][12972] Running state [iptables-persistent] at time 05:31:08.082217
2019-09-25 05:31:08,082 [salt.state       :1813][INFO    ][12972] Executing state pkg.installed for [iptables-persistent]
2019-09-25 05:31:08,091 [salt.state       :300 ][INFO    ][12972] All specified packages are already installed
2019-09-25 05:31:08,091 [salt.state       :1951][INFO    ][12972] Completed state [iptables-persistent] at time 05:31:08.091364 duration_in_ms=9.147
2019-09-25 05:31:08,092 [salt.state       :1780][INFO    ][12972] Running state [iptables_modules_v4_load] at time 05:31:08.092629
2019-09-25 05:31:08,093 [salt.state       :1813][INFO    ][12972] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-25 05:31:08,093 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'lsmod' in directory '/root'
2019-09-25 05:31:08,117 [salt.state       :300 ][INFO    ][12972] Kernel modules iptable_filter, ip_tables are already present
2019-09-25 05:31:08,118 [salt.state       :1951][INFO    ][12972] Completed state [iptables_modules_v4_load] at time 05:31:08.118164 duration_in_ms=25.535
2019-09-25 05:31:08,119 [salt.state       :1780][INFO    ][12972] Running state [/etc/iptables/rules.v4] at time 05:31:08.119007
2019-09-25 05:31:08,119 [salt.state       :1813][INFO    ][12972] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-25 05:31:08,224 [salt.state       :300 ][INFO    ][12972] File /etc/iptables/rules.v4 is in the correct state
2019-09-25 05:31:08,224 [salt.state       :1951][INFO    ][12972] Completed state [/etc/iptables/rules.v4] at time 05:31:08.224430 duration_in_ms=105.423
2019-09-25 05:31:08,225 [salt.state       :1780][INFO    ][12972] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:31:08.225519
2019-09-25 05:31:08,225 [salt.state       :1813][INFO    ][12972] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-25 05:31:08,226 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-25 05:31:08,245 [salt.state       :300 ][INFO    ][12972] onlyif execution failed
2019-09-25 05:31:08,246 [salt.state       :1951][INFO    ][12972] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:31:08.246163 duration_in_ms=20.642
2019-09-25 05:31:08,248 [salt.state       :1780][INFO    ][12972] Running state [netfilter-persistent] at time 05:31:08.247974
2019-09-25 05:31:08,248 [salt.state       :1813][INFO    ][12972] Executing state service.running for [netfilter-persistent]
2019-09-25 05:31:08,249 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:08,271 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-25 05:31:08,290 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-25 05:31:08,308 [salt.state       :300 ][INFO    ][12972] The service netfilter-persistent is already running
2019-09-25 05:31:08,309 [salt.state       :1951][INFO    ][12972] Completed state [netfilter-persistent] at time 05:31:08.309234 duration_in_ms=61.26
2019-09-25 05:31:08,310 [salt.state       :1780][INFO    ][12972] Running state [iptables_extra.remove_stale_tables] at time 05:31:08.310580
2019-09-25 05:31:08,311 [salt.state       :1813][INFO    ][12972] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-25 05:31:08,311 [salt.state       :300 ][INFO    ][12972] No changes made for iptables_extra.remove_stale_tables
2019-09-25 05:31:08,312 [salt.state       :1951][INFO    ][12972] Completed state [iptables_extra.remove_stale_tables] at time 05:31:08.311958 duration_in_ms=1.378
2019-09-25 05:31:08,312 [salt.state       :1780][INFO    ][12972] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:31:08.312344
2019-09-25 05:31:08,312 [salt.state       :1813][INFO    ][12972] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-25 05:31:08,313 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12972] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-25 05:31:08,328 [salt.state       :300 ][INFO    ][12972] onlyif execution failed
2019-09-25 05:31:08,329 [salt.state       :1951][INFO    ][12972] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:31:08.329274 duration_in_ms=16.93
2019-09-25 05:31:08,330 [salt.state       :1780][INFO    ][12972] Running state [/etc/iptables/rules.v6] at time 05:31:08.330703
2019-09-25 05:31:08,331 [salt.state       :1813][INFO    ][12972] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-25 05:31:08,331 [salt.state       :300 ][INFO    ][12972] File /etc/iptables/rules.v6 is not present
2019-09-25 05:31:08,332 [salt.state       :1951][INFO    ][12972] Completed state [/etc/iptables/rules.v6] at time 05:31:08.332173 duration_in_ms=1.47
2019-09-25 05:31:08,333 [salt.state       :1780][INFO    ][12972] Running state [iptables_extra.flush_all] at time 05:31:08.333173
2019-09-25 05:31:08,333 [salt.state       :1813][INFO    ][12972] Executing state module.wait for [iptables_extra.flush_all]
2019-09-25 05:31:08,334 [salt.state       :300 ][INFO    ][12972] No changes made for iptables_extra.flush_all
2019-09-25 05:31:08,334 [salt.state       :1951][INFO    ][12972] Completed state [iptables_extra.flush_all] at time 05:31:08.334341 duration_in_ms=1.168
2019-09-25 05:31:08,373 [salt.minion      :1711][INFO    ][12972] Returning information for job: 20190925053100560732
2019-09-25 05:31:09,005 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925053108993771
2019-09-25 05:31:09,026 [salt.minion      :1432][INFO    ][13067] Starting a new job with PID 13067
2019-09-25 05:31:09,770 [salt.state       :915 ][INFO    ][13067] Loading fresh modules for state activity
2019-09-25 05:31:10,381 [salt.state       :1780][INFO    ][13067] Running state [maas-rack-controller] at time 05:31:10.380969
2019-09-25 05:31:10,381 [salt.state       :1813][INFO    ][13067] Executing state pkg.installed for [maas-rack-controller]
2019-09-25 05:31:10,381 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13067] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-25 05:31:10,466 [salt.state       :300 ][INFO    ][13067] All specified packages are already installed
2019-09-25 05:31:10,467 [salt.state       :1951][INFO    ][13067] Completed state [maas-rack-controller] at time 05:31:10.467154 duration_in_ms=86.185
2019-09-25 05:31:10,467 [salt.state       :1780][INFO    ][13067] Running state [ipmitool] at time 05:31:10.467449
2019-09-25 05:31:10,467 [salt.state       :1813][INFO    ][13067] Executing state pkg.installed for [ipmitool]
2019-09-25 05:31:10,473 [salt.state       :300 ][INFO    ][13067] All specified packages are already installed
2019-09-25 05:31:10,473 [salt.state       :1951][INFO    ][13067] Completed state [ipmitool] at time 05:31:10.473590 duration_in_ms=6.141
2019-09-25 05:31:10,476 [salt.state       :1780][INFO    ][13067] Running state [/etc/maas/rackd.conf] at time 05:31:10.476289
2019-09-25 05:31:10,476 [salt.state       :1813][INFO    ][13067] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-25 05:31:10,477 [salt.state       :300 ][INFO    ][13067] No changes needed to be made
2019-09-25 05:31:10,477 [salt.state       :1951][INFO    ][13067] Completed state [/etc/maas/rackd.conf] at time 05:31:10.477661 duration_in_ms=1.372
2019-09-25 05:31:10,477 [salt.state       :1780][INFO    ][13067] Running state [/etc/maas/rackd.conf] at time 05:31:10.477861
2019-09-25 05:31:10,478 [salt.state       :1813][INFO    ][13067] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-25 05:31:10,478 [salt.loaded.int.states.file:2298][WARNING ][13067] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-09-25 05:31:10,478 [salt.state       :300 ][INFO    ][13067] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-25 05:31:10,478 [salt.state       :1951][INFO    ][13067] Completed state [/etc/maas/rackd.conf] at time 05:31:10.478940 duration_in_ms=1.079
2019-09-25 05:31:10,479 [salt.state       :1780][INFO    ][13067] Running state [maas-rackd] at time 05:31:10.479776
2019-09-25 05:31:10,480 [salt.state       :1813][INFO    ][13067] Executing state service.running for [maas-rackd]
2019-09-25 05:31:10,480 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13067] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:10,514 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13067] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-25 05:31:10,531 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13067] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-25 05:31:10,548 [salt.state       :300 ][INFO    ][13067] The service maas-rackd is already running
2019-09-25 05:31:10,548 [salt.state       :1951][INFO    ][13067] Completed state [maas-rackd] at time 05:31:10.548691 duration_in_ms=68.915
2019-09-25 05:31:10,550 [salt.minion      :1711][INFO    ][13067] Returning information for job: 20190925053108993771
2019-09-25 05:31:11,184 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925053111171358
2019-09-25 05:31:11,207 [salt.minion      :1432][INFO    ][13091] Starting a new job with PID 13091
2019-09-25 05:31:11,990 [salt.state       :915 ][INFO    ][13091] Loading fresh modules for state activity
2019-09-25 05:31:12,830 [salt.state       :1780][INFO    ][13091] Running state [maas-region-controller] at time 05:31:12.830055
2019-09-25 05:31:12,830 [salt.state       :1813][INFO    ][13091] Executing state pkg.installed for [maas-region-controller]
2019-09-25 05:31:12,830 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-25 05:31:12,953 [salt.state       :300 ][INFO    ][13091] All specified packages are already installed
2019-09-25 05:31:12,954 [salt.state       :1951][INFO    ][13091] Completed state [maas-region-controller] at time 05:31:12.954677 duration_in_ms=124.62
2019-09-25 05:31:12,955 [salt.state       :1780][INFO    ][13091] Running state [python-oauth] at time 05:31:12.955288
2019-09-25 05:31:12,955 [salt.state       :1813][INFO    ][13091] Executing state pkg.installed for [python-oauth]
2019-09-25 05:31:12,964 [salt.state       :300 ][INFO    ][13091] All specified packages are already installed
2019-09-25 05:31:12,965 [salt.state       :1951][INFO    ][13091] Completed state [python-oauth] at time 05:31:12.965019 duration_in_ms=9.73
2019-09-25 05:31:12,972 [salt.state       :1780][INFO    ][13091] Running state [/etc/maas/regiond.conf] at time 05:31:12.972538
2019-09-25 05:31:12,972 [salt.state       :1813][INFO    ][13091] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-25 05:31:12,992 [salt.state       :300 ][INFO    ][13091] No changes needed to be made
2019-09-25 05:31:12,992 [salt.state       :1951][INFO    ][13091] Completed state [/etc/maas/regiond.conf] at time 05:31:12.992384 duration_in_ms=19.845
2019-09-25 05:31:12,993 [salt.state       :1780][INFO    ][13091] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:31:12.993067
2019-09-25 05:31:12,993 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-25 05:31:13,068 [salt.state       :300 ][INFO    ][13091] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-25 05:31:13,069 [salt.state       :1951][INFO    ][13091] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:31:13.069127 duration_in_ms=76.06
2019-09-25 05:31:13,069 [salt.state       :1780][INFO    ][13091] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:13.069759
2019-09-25 05:31:13,070 [salt.state       :1813][INFO    ][13091] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-25 05:31:13,082 [salt.state       :300 ][INFO    ][13091] No changes needed to be made
2019-09-25 05:31:13,082 [salt.state       :1951][INFO    ][13091] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:13.082672 duration_in_ms=12.913
2019-09-25 05:31:13,083 [salt.state       :1780][INFO    ][13091] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:13.083255
2019-09-25 05:31:13,083 [salt.state       :1813][INFO    ][13091] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-25 05:31:13,106 [salt.state       :300 ][INFO    ][13091] No changes needed to be made
2019-09-25 05:31:13,106 [salt.state       :1951][INFO    ][13091] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:13.106678 duration_in_ms=23.422
2019-09-25 05:31:13,107 [salt.state       :1780][INFO    ][13091] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:31:13.107280
2019-09-25 05:31:13,107 [salt.state       :1813][INFO    ][13091] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-25 05:31:13,136 [salt.state       :300 ][INFO    ][13091] No changes needed to be made
2019-09-25 05:31:13,137 [salt.state       :1951][INFO    ][13091] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:31:13.137017 duration_in_ms=29.738
2019-09-25 05:31:13,137 [salt.state       :1780][INFO    ][13091] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:31:13.137555
2019-09-25 05:31:13,137 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-25 05:31:13,150 [salt.state       :300 ][INFO    ][13091] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-25 05:31:13,151 [salt.state       :1951][INFO    ][13091] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:31:13.151031 duration_in_ms=13.476
2019-09-25 05:31:13,152 [salt.state       :1780][INFO    ][13091] Running state [a2enmod headers] at time 05:31:13.152506
2019-09-25 05:31:13,152 [salt.state       :1813][INFO    ][13091] Executing state cmd.run for [a2enmod headers]
2019-09-25 05:31:13,153 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command 'a2enmod headers' in directory '/root'
2019-09-25 05:31:13,226 [salt.state       :300 ][INFO    ][13091] {'pid': 13110, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-25 05:31:13,227 [salt.state       :1951][INFO    ][13091] Completed state [a2enmod headers] at time 05:31:13.227312 duration_in_ms=74.805
2019-09-25 05:31:13,228 [salt.state       :1780][INFO    ][13091] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:31:13.227948
2019-09-25 05:31:13,228 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-25 05:31:13,248 [salt.state       :300 ][INFO    ][13091] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-25 05:31:13,248 [salt.state       :1951][INFO    ][13091] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:31:13.248606 duration_in_ms=20.658
2019-09-25 05:31:13,249 [salt.state       :1780][INFO    ][13091] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:31:13.249427
2019-09-25 05:31:13,249 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-25 05:31:13,362 [salt.state       :300 ][INFO    ][13091] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-25 05:31:13,363 [salt.state       :1951][INFO    ][13091] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:31:13.363128 duration_in_ms=113.701
2019-09-25 05:31:13,364 [salt.state       :1780][INFO    ][13091] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:31:13.363970
2019-09-25 05:31:13,364 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-25 05:31:13,434 [salt.state       :300 ][INFO    ][13091] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-25 05:31:13,434 [salt.state       :1951][INFO    ][13091] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:31:13.434477 duration_in_ms=70.507
2019-09-25 05:31:13,435 [salt.state       :1780][INFO    ][13091] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:31:13.435098
2019-09-25 05:31:13,435 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-25 05:31:13,500 [salt.state       :300 ][INFO    ][13091] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-25 05:31:13,500 [salt.state       :1951][INFO    ][13091] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:31:13.500274 duration_in_ms=65.176
2019-09-25 05:31:13,500 [salt.state       :1780][INFO    ][13091] Running state [/root/.pgpass] at time 05:31:13.500613
2019-09-25 05:31:13,500 [salt.state       :1813][INFO    ][13091] Executing state file.managed for [/root/.pgpass]
2019-09-25 05:31:13,547 [salt.state       :300 ][INFO    ][13091] File /root/.pgpass is in the correct state
2019-09-25 05:31:13,548 [salt.state       :1951][INFO    ][13091] Completed state [/root/.pgpass] at time 05:31:13.548203 duration_in_ms=47.59
2019-09-25 05:31:13,553 [salt.state       :1780][INFO    ][13091] Running state [maas-region syncdb --noinput] at time 05:31:13.553861
2019-09-25 05:31:13,554 [salt.state       :1813][INFO    ][13091] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-25 05:31:13,554 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-25 05:31:15,703 [salt.state       :300 ][INFO    ][13091] {'pid': 13123, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, piston3, sessions, auth, sites, maasserver, contenttypes\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-09-25 05:31:15,704 [salt.state       :1951][INFO    ][13091] Completed state [maas-region syncdb --noinput] at time 05:31:15.704071 duration_in_ms=2150.209
2019-09-25 05:31:15,704 [salt.state       :2022][WARNING ][13091] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-25 05:31:15,706 [salt.state       :1780][INFO    ][13091] Running state [maas-regiond] at time 05:31:15.706861
2019-09-25 05:31:15,707 [salt.state       :1813][INFO    ][13091] Executing state service.running for [maas-regiond]
2019-09-25 05:31:15,708 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:15,745 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-25 05:31:15,762 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-25 05:31:15,778 [salt.state       :300 ][INFO    ][13091] The service maas-regiond is already running
2019-09-25 05:31:15,779 [salt.state       :1951][INFO    ][13091] Completed state [maas-regiond] at time 05:31:15.779325 duration_in_ms=72.464
2019-09-25 05:31:15,781 [salt.state       :1780][INFO    ][13091] Running state [bind9] at time 05:31:15.781817
2019-09-25 05:31:15,782 [salt.state       :1813][INFO    ][13091] Executing state service.running for [bind9]
2019-09-25 05:31:15,783 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:15,800 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-25 05:31:15,816 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-25 05:31:15,831 [salt.state       :300 ][INFO    ][13091] The service bind9 is already running
2019-09-25 05:31:15,832 [salt.state       :1951][INFO    ][13091] Completed state [bind9] at time 05:31:15.832290 duration_in_ms=50.472
2019-09-25 05:31:15,834 [salt.state       :1780][INFO    ][13091] Running state [apache2] at time 05:31:15.834638
2019-09-25 05:31:15,835 [salt.state       :1813][INFO    ][13091] Executing state service.running for [apache2]
2019-09-25 05:31:15,836 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-25 05:31:15,853 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-25 05:31:15,868 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-25 05:31:15,888 [salt.state       :300 ][INFO    ][13091] The service apache2 is already running
2019-09-25 05:31:15,889 [salt.state       :1951][INFO    ][13091] Completed state [apache2] at time 05:31:15.889159 duration_in_ms=54.521
2019-09-25 05:31:15,891 [salt.state       :1780][INFO    ][13091] Running state [maasng.wait_for_http_code] at time 05:31:15.891121
2019-09-25 05:31:15,891 [salt.state       :1813][INFO    ][13091] Executing state module.run for [maasng.wait_for_http_code]
2019-09-25 05:31:15,892 [salt.utils.decorators:613 ][WARNING ][13091] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:15,902 [salt.state       :300 ][INFO    ][13091] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-25 05:31:15,902 [salt.state       :1951][INFO    ][13091] Completed state [maasng.wait_for_http_code] at time 05:31:15.902387 duration_in_ms=11.265
2019-09-25 05:31:15,903 [salt.state       :1780][INFO    ][13091] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:31:15.903720
2019-09-25 05:31:15,904 [salt.state       :1813][INFO    ][13091] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-25 05:31:15,904 [salt.state       :300 ][INFO    ][13091] /var/lib/maas/.setup_admin exists
2019-09-25 05:31:15,905 [salt.state       :1951][INFO    ][13091] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:31:15.905242 duration_in_ms=1.522
2019-09-25 05:31:15,906 [salt.state       :1780][INFO    ][13091] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:15.906343
2019-09-25 05:31:15,906 [salt.state       :1813][INFO    ][13091] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:31:15,907 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13091] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:31:17,375 [salt.state       :300 ][INFO    ][13091] {'pid': 13142, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:31:17,376 [salt.state       :1951][INFO    ][13091] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:17.376788 duration_in_ms=1470.445
2019-09-25 05:31:17,385 [salt.state       :1780][INFO    ][13091] Running state [maas_region_boot_source_resources_mirror] at time 05:31:17.384930
2019-09-25 05:31:17,385 [salt.state       :1813][INFO    ][13091] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-25 05:31:17,499 [salt.state       :300 ][INFO    ][13091] {'changes': {}}
2019-09-25 05:31:17,500 [salt.state       :1951][INFO    ][13091] Completed state [maas_region_boot_source_resources_mirror] at time 05:31:17.499955 duration_in_ms=115.025
2019-09-25 05:31:17,501 [salt.state       :1780][INFO    ][13091] Running state [maasng.boot_resources_import] at time 05:31:17.501102
2019-09-25 05:31:17,501 [salt.state       :1813][INFO    ][13091] Executing state module.run for [maasng.boot_resources_import]
2019-09-25 05:31:17,502 [salt.utils.decorators:613 ][WARNING ][13091] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:17,614 [salt.loaded.ext.module.maasng:1600][INFO    ][13091] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-25 05:31:22,656 [salt.loaded.ext.module.maasng:1600][INFO    ][13091] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-25 05:31:26,258 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053126246421
2019-09-25 05:31:26,282 [salt.minion      :1432][INFO    ][13170] Starting a new job with PID 13170
2019-09-25 05:31:26,307 [salt.minion      :1711][INFO    ][13170] Returning information for job: 20190925053126246421
2019-09-25 05:31:27,717 [salt.loaded.ext.module.maasng:1600][INFO    ][13091] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-25 05:31:32,825 [salt.state       :300 ][INFO    ][13091] {'ret': True}
2019-09-25 05:31:32,826 [salt.state       :1951][INFO    ][13091] Completed state [maasng.boot_resources_import] at time 05:31:32.826120 duration_in_ms=15325.017
2019-09-25 05:31:32,827 [salt.state       :1780][INFO    ][13091] Running state [maas_region_boot_sources_selection_xenial] at time 05:31:32.827283
2019-09-25 05:31:32,827 [salt.state       :1813][INFO    ][13091] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-25 05:31:33,034 [salt.state       :300 ][INFO    ][13091] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-25 05:31:33,035 [salt.state       :1951][INFO    ][13091] Completed state [maas_region_boot_sources_selection_xenial] at time 05:31:33.034979 duration_in_ms=207.695
2019-09-25 05:31:33,036 [salt.state       :1780][INFO    ][13091] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:31:33.036389
2019-09-25 05:31:33,036 [salt.state       :1813][INFO    ][13091] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-25 05:31:33,037 [salt.utils.decorators:613 ][WARNING ][13091] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:33,038 [salt.loaded.ext.module.maasng:1771][INFO    ][13091] boot-sources sync initiated for ALL Rack's
2019-09-25 05:31:34,046 [salt.state       :300 ][INFO    ][13091] {'ret': True}
2019-09-25 05:31:34,047 [salt.state       :1951][INFO    ][13091] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:31:34.047023 duration_in_ms=1010.633
2019-09-25 05:31:34,049 [salt.state       :1780][INFO    ][13091] Running state [maas.process_maas_config] at time 05:31:34.049071
2019-09-25 05:31:34,049 [salt.state       :1813][INFO    ][13091] Executing state module.run for [maas.process_maas_config]
2019-09-25 05:31:34,050 [salt.utils.decorators:613 ][WARNING ][13091] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:34,051 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=enable_http_proxy value=True
2019-09-25 05:31:34,125 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=upstream_dns value=8.8.8.8
2019-09-25 05:31:34,190 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=commissioning_distro_series value=xenial
2019-09-25 05:31:37,128 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=default_osystem value=ubuntu
2019-09-25 05:31:37,203 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=active_discovery_interval value=600
2019-09-25 05:31:37,271 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=dnssec_validation value=no
2019-09-25 05:31:37,328 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=maas_name value=mas01
2019-09-25 05:31:37,388 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=network_discovery value=enabled
2019-09-25 05:31:37,502 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=enable_third_party_drivers value=True
2019-09-25 05:31:37,556 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=default_storage_layout value=lvm
2019-09-25 05:31:37,616 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=ntp_external_only value=True
2019-09-25 05:31:37,689 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-25 05:31:37,735 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=default_distro_series value=xenial
2019-09-25 05:31:37,814 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-09-25 05:31:37,952 [salt.state       :300 ][INFO    ][13091] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-09-25 05:31:37,952 [salt.state       :1951][INFO    ][13091] Completed state [maas.process_maas_config] at time 05:31:37.952275 duration_in_ms=3903.205
2019-09-25 05:31:37,952 [salt.state       :1780][INFO    ][13091] Running state [pxe_admin] at time 05:31:37.952867
2019-09-25 05:31:37,953 [salt.state       :1813][INFO    ][13091] Executing state maasng.fabric_present for [pxe_admin]
2019-09-25 05:31:38,010 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-09-25 05:31:38,081 [salt.loaded.ext.module.maasng:1008][WARNING ][13091] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-25 05:31:38,082 [salt.loaded.ext.module.maasng:1011][WARNING ][13091] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-25 05:31:38,153 [salt.state       :300 ][INFO    ][13091] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-25 05:31:38,154 [salt.state       :1951][INFO    ][13091] Completed state [pxe_admin] at time 05:31:38.154190 duration_in_ms=201.322
2019-09-25 05:31:38,154 [salt.state       :1780][INFO    ][13091] Running state [vlan 0] at time 05:31:38.154527
2019-09-25 05:31:38,154 [salt.state       :1813][INFO    ][13091] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-25 05:31:38,232 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'7f6cxe', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-09-25 05:31:38,364 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-25 05:31:38,634 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-09-25 05:31:38,730 [salt.state       :300 ][INFO    ][13091] {'new': 'Vlan untagged was updated'}
2019-09-25 05:31:38,731 [salt.state       :1951][INFO    ][13091] Completed state [vlan 0] at time 05:31:38.731204 duration_in_ms=576.675
2019-09-25 05:31:38,732 [salt.state       :1780][INFO    ][13091] Running state [192.168.11.0/24] at time 05:31:38.732831
2019-09-25 05:31:38,733 [salt.state       :1813][INFO    ][13091] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-25 05:31:38,932 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-09-25 05:31:38,932 [salt.loaded.ext.module.maasng:1235][WARNING ][13091] Ignoring parameter vlan:0
2019-09-25 05:31:39,004 [salt.state       :300 ][INFO    ][13091] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-25 05:31:39,005 [salt.state       :1951][INFO    ][13091] Completed state [192.168.11.0/24] at time 05:31:39.005306 duration_in_ms=272.475
2019-09-25 05:31:39,006 [salt.state       :1780][INFO    ][13091] Running state [maas_create_iprange_1] at time 05:31:39.006776
2019-09-25 05:31:39,007 [salt.state       :1813][INFO    ][13091] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-25 05:31:39,083 [salt.state       :300 ][INFO    ][13091] Iprange maas_create_iprange_1 already exist.
2019-09-25 05:31:39,084 [salt.state       :1951][INFO    ][13091] Completed state [maas_create_iprange_1] at time 05:31:39.084179 duration_in_ms=77.403
2019-09-25 05:31:39,084 [salt.state       :1780][INFO    ][13091] Running state [vlan 0] at time 05:31:39.084531
2019-09-25 05:31:39,084 [salt.state       :1813][INFO    ][13091] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-25 05:31:39,154 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'7f6cxe', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-09-25 05:31:39,299 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'7f6cxe', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-09-25 05:31:39,568 [salt.loaded.ext.module.maasng:945 ][INFO    ][13091] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7f6cxe', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-25 05:31:39,652 [salt.state       :300 ][INFO    ][13091] {'new': 'Vlan untagged was updated'}
2019-09-25 05:31:39,652 [salt.state       :1951][INFO    ][13091] Completed state [vlan 0] at time 05:31:39.652704 duration_in_ms=568.172
2019-09-25 05:31:39,653 [salt.state       :1780][INFO    ][13091] Running state [opnfv] at time 05:31:39.653403
2019-09-25 05:31:39,653 [salt.state       :1813][INFO    ][13091] Executing state maasng.sshkey_present for [opnfv]
2019-09-25 05:31:39,712 [salt.loaded.ext.module.maasng:1903][INFO    ][13091] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-09-25 05:31:39,713 [salt.state       :300 ][INFO    ][13091] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-25 05:31:39,713 [salt.state       :1951][INFO    ][13091] Completed state [opnfv] at time 05:31:39.713813 duration_in_ms=60.408
2019-09-25 05:31:39,715 [salt.state       :1780][INFO    ][13091] Running state [maas.process_tags] at time 05:31:39.714978
2019-09-25 05:31:39,715 [salt.state       :1813][INFO    ][13091] Executing state module.run for [maas.process_tags]
2019-09-25 05:31:39,716 [salt.utils.decorators:613 ][WARNING ][13091] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:39,778 [salt.loaded.ext.module.maas:92  ][INFO    ][13091] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-09-25 05:31:39,838 [salt.state       :300 ][INFO    ][13091] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-09-25 05:31:39,838 [salt.state       :1951][INFO    ][13091] Completed state [maas.process_tags] at time 05:31:39.838829 duration_in_ms=123.851
2019-09-25 05:31:39,843 [salt.minion      :1711][INFO    ][13091] Returning information for job: 20190925053111171358
2019-09-25 05:31:40,395 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925053140382898
2019-09-25 05:31:40,413 [salt.minion      :1432][INFO    ][13543] Starting a new job with PID 13543
2019-09-25 05:31:44,124 [salt.state       :915 ][INFO    ][13543] Loading fresh modules for state activity
2019-09-25 05:31:44,219 [salt.state       :1780][INFO    ][13543] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:44.219386
2019-09-25 05:31:44,219 [salt.state       :1813][INFO    ][13543] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:31:44,222 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13543] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:31:45,636 [salt.state       :300 ][INFO    ][13543] {'pid': 13570, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:31:45,637 [salt.state       :1951][INFO    ][13543] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:45.637203 duration_in_ms=1417.817
2019-09-25 05:31:45,638 [salt.state       :1780][INFO    ][13543] Running state [maas.process_machines] at time 05:31:45.638387
2019-09-25 05:31:45,638 [salt.state       :1813][INFO    ][13543] Executing state module.run for [maas.process_machines]
2019-09-25 05:31:45,639 [salt.utils.decorators:613 ][WARNING ][13543] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:31:46,350 [salt.loaded.ext.module.maas:412 ][WARNING ][13543] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:31:46,350 [salt.loaded.ext.module.maas:92  ][INFO    ][13543] 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=tbker4 architecture=amd64/generic power_parameters_power_user=admin
2019-09-25 05:31:47,664 [salt.loaded.ext.module.maas:412 ][WARNING ][13543] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:31:47,665 [salt.loaded.ext.module.maas:92  ][INFO    ][13543] 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=kqxb4b architecture=amd64/generic power_parameters_power_user=admin
2019-09-25 05:31:48,951 [salt.loaded.ext.module.maas:412 ][WARNING ][13543] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:31:48,952 [salt.loaded.ext.module.maas:92  ][INFO    ][13543] 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=86twkk architecture=amd64/generic power_parameters_power_user=admin
2019-09-25 05:31:50,215 [salt.loaded.ext.module.maas:412 ][WARNING ][13543] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:31:50,215 [salt.loaded.ext.module.maas:92  ][INFO    ][13543] 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=cwb8sr architecture=amd64/generic power_parameters_power_user=admin
2019-09-25 05:31:51,478 [salt.loaded.ext.module.maas:412 ][WARNING ][13543] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-25 05:31:51,479 [salt.loaded.ext.module.maas:92  ][INFO    ][13543] 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=nm88fy architecture=amd64/generic power_parameters_power_user=admin
2019-09-25 05:31:52,628 [salt.state       :300 ][INFO    ][13543] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-25 05:31:52,629 [salt.state       :1951][INFO    ][13543] Completed state [maas.process_machines] at time 05:31:52.629015 duration_in_ms=6990.626
2019-09-25 05:31:52,632 [salt.minion      :1711][INFO    ][13543] Returning information for job: 20190925053140382898
2019-09-25 05:32:25,747 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925053225734664
2019-09-25 05:32:25,770 [salt.minion      :1432][INFO    ][13824] Starting a new job with PID 13824
2019-09-25 05:32:29,481 [salt.state       :915 ][INFO    ][13824] Loading fresh modules for state activity
2019-09-25 05:32:29,562 [salt.state       :1780][INFO    ][13824] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:32:29.562544
2019-09-25 05:32:29,562 [salt.state       :1813][INFO    ][13824] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:32:29,564 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13824] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:32:30,806 [salt.state       :300 ][INFO    ][13824] {'pid': 13832, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:32:30,807 [salt.state       :1951][INFO    ][13824] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:32:30.807196 duration_in_ms=1244.652
2019-09-25 05:32:30,808 [salt.state       :1780][INFO    ][13824] Running state [maas.wait_for_machine_status] at time 05:32:30.808608
2019-09-25 05:32:30,808 [salt.state       :1813][INFO    ][13824] Executing state module.run for [maas.wait_for_machine_status]
2019-09-25 05:32:30,809 [salt.utils.decorators:613 ][WARNING ][13824] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:32:32,445 [salt.loaded.ext.module.maas:993 ][INFO    ][13824] Machine 86twkk mark broken
2019-09-25 05:32:32,789 [salt.loaded.ext.module.maas:996 ][INFO    ][13824] Machine 86twkk mark fixed
2019-09-25 05:32:34,042 [salt.loaded.ext.module.maas:684 ][INFO    ][13824] deploymachines hwe_kernel=hwe-16.04 system_id=86twkk distro_series=xenial
2019-09-25 05:32:38,016 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.79671812s left)
2019-09-25 05:32:40,887 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053240836126
2019-09-25 05:32:40,905 [salt.minion      :1432][INFO    ][13923] Starting a new job with PID 13923
2019-09-25 05:32:40,929 [salt.minion      :1711][INFO    ][13923] Returning information for job: 20190925053240836126
2019-09-25 05:33:10,936 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053310923598
2019-09-25 05:33:10,956 [salt.minion      :1432][INFO    ][13968] Starting a new job with PID 13968
2019-09-25 05:33:10,981 [salt.minion      :1711][INFO    ][13968] Returning information for job: 20190925053310923598
2019-09-25 05:33:11,778 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1459.03475404s left)
2019-09-25 05:33:41,037 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053341024740
2019-09-25 05:33:41,060 [salt.minion      :1432][INFO    ][13998] Starting a new job with PID 13998
2019-09-25 05:33:41,087 [salt.minion      :1711][INFO    ][13998] Returning information for job: 20190925053341024740
2019-09-25 05:33:45,078 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.73483419s left)
2019-09-25 05:34:11,089 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053411077716
2019-09-25 05:34:11,112 [salt.minion      :1432][INFO    ][14044] Starting a new job with PID 14044
2019-09-25 05:34:11,137 [salt.minion      :1711][INFO    ][14044] Returning information for job: 20190925053411077716
2019-09-25 05:34:17,908 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.90466118s left)
2019-09-25 05:34:41,143 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053441130881
2019-09-25 05:34:41,166 [salt.minion      :1432][INFO    ][14126] Starting a new job with PID 14126
2019-09-25 05:34:41,188 [salt.minion      :1711][INFO    ][14126] Returning information for job: 20190925053441130881
2019-09-25 05:34:51,591 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.22200012s left)
2019-09-25 05:35:11,195 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053511182349
2019-09-25 05:35:11,218 [salt.minion      :1432][INFO    ][14264] Starting a new job with PID 14264
2019-09-25 05:35:11,244 [salt.minion      :1711][INFO    ][14264] Returning information for job: 20190925053511182349
2019-09-25 05:35:24,706 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1326.10724807s left)
2019-09-25 05:35:41,255 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053541243812
2019-09-25 05:35:41,275 [salt.minion      :1432][INFO    ][14341] Starting a new job with PID 14341
2019-09-25 05:35:41,300 [salt.minion      :1711][INFO    ][14341] Returning information for job: 20190925053541243812
2019-09-25 05:35:58,259 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.55424309s left)
2019-09-25 05:36:11,314 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053611301766
2019-09-25 05:36:11,338 [salt.minion      :1432][INFO    ][14416] Starting a new job with PID 14416
2019-09-25 05:36:11,364 [salt.minion      :1711][INFO    ][14416] Returning information for job: 20190925053611301766
2019-09-25 05:36:31,834 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.97929406s left)
2019-09-25 05:36:41,379 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053641366650
2019-09-25 05:36:41,402 [salt.minion      :1432][INFO    ][14464] Starting a new job with PID 14464
2019-09-25 05:36:41,428 [salt.minion      :1711][INFO    ][14464] Returning information for job: 20190925053641366650
2019-09-25 05:37:05,029 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1225.78435421s left)
2019-09-25 05:37:11,450 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053711437589
2019-09-25 05:37:11,473 [salt.minion      :1432][INFO    ][14564] Starting a new job with PID 14564
2019-09-25 05:37:11,499 [salt.minion      :1711][INFO    ][14564] Returning information for job: 20190925053711437589
2019-09-25 05:37:38,607 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1192.20589018s left)
2019-09-25 05:37:41,523 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053741510707
2019-09-25 05:37:41,547 [salt.minion      :1432][INFO    ][14631] Starting a new job with PID 14631
2019-09-25 05:37:41,573 [salt.minion      :1711][INFO    ][14631] Returning information for job: 20190925053741510707
2019-09-25 05:38:11,603 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053811590955
2019-09-25 05:38:11,626 [salt.minion      :1432][INFO    ][14746] Starting a new job with PID 14746
2019-09-25 05:38:11,649 [salt.minion      :1711][INFO    ][14746] Returning information for job: 20190925053811590955
2019-09-25 05:38:11,720 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1159.09244919s left)
2019-09-25 05:38:41,685 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053841672324
2019-09-25 05:38:41,707 [salt.minion      :1432][INFO    ][14779] Starting a new job with PID 14779
2019-09-25 05:38:41,733 [salt.minion      :1711][INFO    ][14779] Returning information for job: 20190925053841672324
2019-09-25 05:38:45,374 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1125.43930316s left)
2019-09-25 05:39:11,772 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053911758942
2019-09-25 05:39:11,795 [salt.minion      :1432][INFO    ][14820] Starting a new job with PID 14820
2019-09-25 05:39:11,821 [salt.minion      :1711][INFO    ][14820] Returning information for job: 20190925053911758942
2019-09-25 05:39:18,990 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.8229301s left)
2019-09-25 05:39:41,871 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925053941857926
2019-09-25 05:39:41,893 [salt.minion      :1432][INFO    ][14875] Starting a new job with PID 14875
2019-09-25 05:39:41,918 [salt.minion      :1711][INFO    ][14875] Returning information for job: 20190925053941857926
2019-09-25 05:39:52,456 [salt.loaded.ext.module.maas:1023][INFO    ][13824] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1058.35722804s left)
2019-09-25 05:40:11,908 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command saltutil.find_job with jid 20190925054011895734
2019-09-25 05:40:11,931 [salt.minion      :1432][INFO    ][14982] Starting a new job with PID 14982
2019-09-25 05:40:11,958 [salt.minion      :1711][INFO    ][14982] Returning information for job: 20190925054011895734
2019-09-25 05:40:25,835 [salt.state       :300 ][INFO    ][13824] {'ret': True}
2019-09-25 05:40:25,836 [salt.state       :1951][INFO    ][13824] Completed state [maas.wait_for_machine_status] at time 05:40:25.836296 duration_in_ms=475027.686
2019-09-25 05:40:25,839 [salt.minion      :1711][INFO    ][13824] Returning information for job: 20190925053225734664
2019-09-25 05:40:26,534 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925054026521586
2019-09-25 05:40:26,556 [salt.minion      :1432][INFO    ][15026] Starting a new job with PID 15026
2019-09-25 05:40:30,274 [salt.state       :915 ][INFO    ][15026] Loading fresh modules for state activity
2019-09-25 05:40:30,412 [salt.state       :1780][INFO    ][15026] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:30.412901
2019-09-25 05:40:30,413 [salt.state       :1813][INFO    ][15026] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:40:30,414 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15026] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:40:31,842 [salt.state       :300 ][INFO    ][15026] {'pid': 15034, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:40:31,843 [salt.state       :1951][INFO    ][15026] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:31.843804 duration_in_ms=1430.902
2019-09-25 05:40:31,847 [salt.state       :1780][INFO    ][15026] Running state [maas_machines_storage_cmp002_lvm] at time 05:40:31.847092
2019-09-25 05:40:31,847 [salt.state       :1813][INFO    ][15026] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-25 05:40:32,809 [salt.state       :300 ][INFO    ][15026] Machine cmp002 is not in Ready state.
2019-09-25 05:40:32,810 [salt.state       :1951][INFO    ][15026] Completed state [maas_machines_storage_cmp002_lvm] at time 05:40:32.810234 duration_in_ms=963.143
2019-09-25 05:40:32,810 [salt.state       :1780][INFO    ][15026] Running state [maas_machines_storage_cmp001_lvm] at time 05:40:32.810592
2019-09-25 05:40:32,810 [salt.state       :1813][INFO    ][15026] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-25 05:40:33,361 [salt.state       :300 ][INFO    ][15026] Machine cmp001 is not in Ready state.
2019-09-25 05:40:33,361 [salt.state       :1951][INFO    ][15026] Completed state [maas_machines_storage_cmp001_lvm] at time 05:40:33.361849 duration_in_ms=551.256
2019-09-25 05:40:33,365 [salt.minion      :1711][INFO    ][15026] Returning information for job: 20190925054026521586
2019-09-25 05:40:33,959 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925054033945801
2019-09-25 05:40:33,981 [salt.minion      :1432][INFO    ][15087] Starting a new job with PID 15087
2019-09-25 05:40:34,731 [salt.state       :915 ][INFO    ][15087] Loading fresh modules for state activity
2019-09-25 05:40:34,817 [salt.state       :1780][INFO    ][15087] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:34.817295
2019-09-25 05:40:34,817 [salt.state       :1813][INFO    ][15087] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:40:34,819 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15087] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:40:36,287 [salt.state       :300 ][INFO    ][15087] {'pid': 15094, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:40:36,287 [salt.state       :1951][INFO    ][15087] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:36.287579 duration_in_ms=1470.285
2019-09-25 05:40:36,288 [salt.state       :1780][INFO    ][15087] Running state [maas.deploy_machines] at time 05:40:36.288793
2019-09-25 05:40:36,289 [salt.state       :1813][INFO    ][15087] Executing state module.run for [maas.deploy_machines]
2019-09-25 05:40:36,289 [salt.utils.decorators:613 ][WARNING ][15087] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:40:37,117 [salt.state       :300 ][INFO    ][15087] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-25 05:40:37,117 [salt.state       :1951][INFO    ][15087] Completed state [maas.deploy_machines] at time 05:40:37.117603 duration_in_ms=828.809
2019-09-25 05:40:37,120 [salt.minion      :1711][INFO    ][15087] Returning information for job: 20190925054033945801
2019-09-25 05:40:37,756 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command state.apply with jid 20190925054037746440
2019-09-25 05:40:37,777 [salt.minion      :1432][INFO    ][15103] Starting a new job with PID 15103
2019-09-25 05:40:38,578 [salt.state       :915 ][INFO    ][15103] Loading fresh modules for state activity
2019-09-25 05:40:38,672 [salt.state       :1780][INFO    ][15103] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:38.672435
2019-09-25 05:40:38,672 [salt.state       :1813][INFO    ][15103] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-25 05:40:38,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15103] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-25 05:40:40,102 [salt.state       :300 ][INFO    ][15103] {'pid': 15110, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-25 05:40:40,103 [salt.state       :1951][INFO    ][15103] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:40.102988 duration_in_ms=1430.555
2019-09-25 05:40:40,104 [salt.state       :1780][INFO    ][15103] Running state [maas.wait_for_machine_status] at time 05:40:40.104489
2019-09-25 05:40:40,104 [salt.state       :1813][INFO    ][15103] Executing state module.run for [maas.wait_for_machine_status]
2019-09-25 05:40:40,105 [salt.utils.decorators:613 ][WARNING ][15103] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-25 05:40:43,729 [salt.state       :300 ][INFO    ][15103] {'ret': True}
2019-09-25 05:40:43,729 [salt.state       :1951][INFO    ][15103] Completed state [maas.wait_for_machine_status] at time 05:40:43.729469 duration_in_ms=3624.977
2019-09-25 05:40:43,733 [salt.minion      :1711][INFO    ][15103] Returning information for job: 20190925054037746440
2019-09-25 06:11:26,129 [salt.utils.schedule:1377][INFO    ][6875] Running scheduled job: __mine_interval
2019-09-25 07:10:00,291 [salt.minion      :1308][INFO    ][6875] User sudo_ubuntu Executing command cp.push_dir with jid 20190925071000279551
2019-09-25 07:10:00,314 [salt.minion      :1432][INFO    ][21676] Starting a new job with PID 21676
