2019-12-02 02:09:25,036 [salt.utils.decorators:613 ][WARNING ][2019] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:09:25,645 [salt.utils.decorators:613 ][WARNING ][2019] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:09:27,570 [salt.loaded.int.states.file:2298][WARNING ][2326] 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-12-02 02:09:59,330 [salt.state       :2022][WARNING ][3060] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-02 02:10:01,943 [salt.utils.decorators:613 ][WARNING ][3060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:10:17,525 [salt.utils.decorators:613 ][WARNING ][3060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:10:56,429 [salt.utils.decorators:613 ][WARNING ][3060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:11:18,376 [salt.utils.decorators:613 ][WARNING ][3060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:11:22,531 [salt.loaded.ext.module.maasng:1008][WARNING ][3060] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-12-02 02:11:22,531 [salt.loaded.ext.module.maasng:1011][WARNING ][3060] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-12-02 02:11:23,249 [salt.loaded.ext.module.maasng:1235][WARNING ][3060] Ignoring parameter vlan:0
2019-12-02 02:11:25,945 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6594] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-02 02:11:25,979 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6594] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-12-02 02:11:26,002 [salt.utils.parsers:1051][WARNING ][323] Minion received a SIGTERM. Exiting.
2019-12-02 02:11:26,988 [salt.cli.daemons :293 ][INFO    ][6669] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-12-02 02:11:27,079 [salt.cli.daemons :82  ][INFO    ][6669] Starting up the Salt Minion
2019-12-02 02:11:27,079 [salt.utils.event :1017][INFO    ][6669] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-12-02 02:11:27,929 [salt.minion      :976 ][INFO    ][6669] Creating minion process manager
2019-12-02 02:11:29,182 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6669] Executing command ['date', '+%z'] in directory '/root'
2019-12-02 02:11:29,200 [salt.utils.schedule:568 ][INFO    ][6669] Updating job settings for scheduled job: __mine_interval
2019-12-02 02:11:29,202 [salt.minion      :1108][INFO    ][6669] Added mine.update to scheduler
2019-12-02 02:11:29,205 [salt.minion      :1975][INFO    ][6669] Minion is starting as user 'root'
2019-12-02 02:11:29,217 [salt.minion      :2336][INFO    ][6669] Minion is ready to receive requests!
2019-12-02 02:11:29,570 [salt.utils.decorators:613 ][WARNING ][6602] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:11:29,635 [salt.loaded.ext.module.maas:412 ][WARNING ][6602] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:11:30,965 [salt.loaded.ext.module.maas:412 ][WARNING ][6602] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:11:32,157 [salt.loaded.ext.module.maas:412 ][WARNING ][6602] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:11:33,460 [salt.loaded.ext.module.maas:412 ][WARNING ][6602] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:11:34,784 [salt.loaded.ext.module.maas:412 ][WARNING ][6602] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:12:07,337 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202021207324041
2019-12-02 02:12:07,358 [salt.minion      :1432][INFO    ][7073] Starting a new job with PID 7073
2019-12-02 02:12:10,938 [salt.state       :915 ][INFO    ][7073] Loading fresh modules for state activity
2019-12-02 02:12:10,989 [salt.fileclient  :1219][INFO    ][7073] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-12-02 02:12:11,032 [salt.state       :1780][INFO    ][7073] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:12:11.032856
2019-12-02 02:12:11,033 [salt.state       :1813][INFO    ][7073] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:12:11,035 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7073] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:12:12,475 [salt.state       :300 ][INFO    ][7073] {'pid': 7080, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:12:12,475 [salt.state       :1951][INFO    ][7073] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:12:12.475547 duration_in_ms=1442.692
2019-12-02 02:12:12,476 [salt.state       :1780][INFO    ][7073] Running state [maas.wait_for_machine_status] at time 02:12:12.476644
2019-12-02 02:12:12,476 [salt.state       :1813][INFO    ][7073] Executing state module.run for [maas.wait_for_machine_status]
2019-12-02 02:12:12,477 [salt.utils.decorators:613 ][WARNING ][7073] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:12:13,427 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.053756s left)
2019-12-02 02:12:22,448 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021222432262
2019-12-02 02:12:22,470 [salt.minion      :1432][INFO    ][7111] Starting a new job with PID 7111
2019-12-02 02:12:22,494 [salt.minion      :1711][INFO    ][7111] Returning information for job: 20191202021222432262
2019-12-02 02:12:44,396 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.08466887s left)
2019-12-02 02:12:52,503 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021252487711
2019-12-02 02:12:52,525 [salt.minion      :1432][INFO    ][7138] Starting a new job with PID 7138
2019-12-02 02:12:52,549 [salt.minion      :1711][INFO    ][7138] Returning information for job: 20191202021252487711
2019-12-02 02:13:15,643 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.83846188s left)
2019-12-02 02:13:22,573 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021322558428
2019-12-02 02:13:22,594 [salt.minion      :1432][INFO    ][7277] Starting a new job with PID 7277
2019-12-02 02:13:22,617 [salt.minion      :1711][INFO    ][7277] Returning information for job: 20191202021322558428
2019-12-02 02:13:47,042 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.43859005s left)
2019-12-02 02:13:52,623 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021352606728
2019-12-02 02:13:52,645 [salt.minion      :1432][INFO    ][7417] Starting a new job with PID 7417
2019-12-02 02:13:52,667 [salt.minion      :1711][INFO    ][7417] Returning information for job: 20191202021352606728
2019-12-02 02:14:18,748 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.73345709s left)
2019-12-02 02:14:22,680 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021422667305
2019-12-02 02:14:22,702 [salt.minion      :1432][INFO    ][8112] Starting a new job with PID 8112
2019-12-02 02:14:22,724 [salt.minion      :1711][INFO    ][8112] Returning information for job: 20191202021422667305
2019-12-02 02:14:50,604 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.87656689s left)
2019-12-02 02:14:52,732 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021452718409
2019-12-02 02:14:52,754 [salt.minion      :1432][INFO    ][8154] Starting a new job with PID 8154
2019-12-02 02:14:52,777 [salt.minion      :1711][INFO    ][8154] Returning information for job: 20191202021452718409
2019-12-02 02:15:22,801 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021522782660
2019-12-02 02:15:22,823 [salt.minion      :1432][INFO    ][8377] Starting a new job with PID 8377
2019-12-02 02:15:22,846 [salt.minion      :1711][INFO    ][8377] Returning information for job: 20191202021522782660
2019-12-02 02:15:23,877 [salt.loaded.ext.module.maas:1023][INFO    ][7073] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1308.60426998s left)
2019-12-02 02:15:52,861 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021552848425
2019-12-02 02:15:52,882 [salt.minion      :1432][INFO    ][8484] Starting a new job with PID 8484
2019-12-02 02:15:52,906 [salt.minion      :1711][INFO    ][8484] Returning information for job: 20191202021552848425
2019-12-02 02:15:57,094 [salt.state       :300 ][INFO    ][7073] {'ret': True}
2019-12-02 02:15:57,094 [salt.state       :1951][INFO    ][7073] Completed state [maas.wait_for_machine_status] at time 02:15:57.094864 duration_in_ms=224618.217
2019-12-02 02:15:57,098 [salt.minion      :1711][INFO    ][7073] Returning information for job: 20191202021207324041
2019-12-02 02:15:57,712 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202021557695587
2019-12-02 02:15:57,733 [salt.minion      :1432][INFO    ][8496] Starting a new job with PID 8496
2019-12-02 02:16:01,597 [salt.state       :915 ][INFO    ][8496] Loading fresh modules for state activity
2019-12-02 02:16:01,650 [salt.fileclient  :1219][INFO    ][8496] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-12-02 02:16:01,738 [salt.state       :1780][INFO    ][8496] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:01.738472
2019-12-02 02:16:01,738 [salt.state       :1813][INFO    ][8496] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:16:01,740 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8496] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:16:03,211 [salt.state       :300 ][INFO    ][8496] {'pid': 8514, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:16:03,211 [salt.state       :1951][INFO    ][8496] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:03.211858 duration_in_ms=1473.384
2019-12-02 02:16:03,214 [salt.state       :1780][INFO    ][8496] Running state [maas_machines_storage_cmp002_lvm] at time 02:16:03.214781
2019-12-02 02:16:03,215 [salt.state       :1813][INFO    ][8496] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-02 02:16:04,517 [salt.loaded.ext.module.maasng:610 ][INFO    ][8496] bq8spq
2019-12-02 02:16:04,518 [salt.loaded.ext.module.maasng:626 ][INFO    ][8496] sda
2019-12-02 02:16:05,250 [salt.loaded.ext.module.maasng:361 ][INFO    ][8496] bq8spq
2019-12-02 02:16:05,376 [salt.loaded.ext.module.maasng:367 ][INFO    ][8496] [{u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/4/', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 4, u'partitions': [{u'uuid': u'070661ec-0882-41f7-8e4b-14eadc0cda55', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bq8spq', u'device_id': 4, u'filesystem': {u'uuid': u'25f20638-4302-4fea-8af9-9ea647e35235', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'name': u'sda', u'system_id': u'bq8spq', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/11/', u'available_size': 0, u'uuid': u'e213770d-d178-40a6-9a75-d21cbe464ed5', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 11, u'partitions': [], u'name': u'vgroot-lvroot', u'system_id': u'bq8spq', u'partition_table_type': None, u'filesystem': {u'uuid': u'50f2e013-0945-4984-a305-6df61b36d6ff', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'size': 2397988454400}]
2019-12-02 02:16:05,377 [salt.loaded.ext.module.maasng:632 ][INFO    ][8496] vgroot
2019-12-02 02:16:05,377 [salt.loaded.ext.module.maasng:635 ][INFO    ][8496] lvroot
2019-12-02 02:16:05,378 [salt.loaded.ext.module.maasng:639 ][INFO    ][8496] 107374182400
2019-12-02 02:16:06,037 [salt.loaded.ext.module.maasng:645 ][INFO    ][8496] {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'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.41'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'bq8spq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'ab6aea20-8018-4cc7-821c-4624e453f8ad', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bq8spq', u'filesystem': {u'mount_options': None, u'uuid': u'f21b5eec-502c-4df1-9063-3aa04e886630', u'fstype': u'lvm-pv', u'mount_point': None, 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/bq8spq/blockdevices/4/partition/8'}]}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'bq8spq', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'ab6aea20-8018-4cc7-821c-4624e453f8ad', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bq8spq', u'filesystem': {u'mount_options': None, u'uuid': u'f21b5eec-502c-4df1-9063-3aa04e886630', u'fstype': u'lvm-pv', u'mount_point': None, 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/bq8spq/blockdevices/4/partition/8'}]}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/13/', u'type': u'virtual', u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'28e87c76-3560-43c3-9a40-04c503b3ae3b', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'uuid': u'23183e05-067b-4782-bee6-55710dbd3d26', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bq8spq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 13, u'partitions': []}], u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'bq8spq', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'bq8spq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'size': 2397992648704, u'uuid': u'ab6aea20-8018-4cc7-821c-4624e453f8ad', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bq8spq', u'filesystem': {u'mount_options': None, u'uuid': u'f21b5eec-502c-4df1-9063-3aa04e886630', u'fstype': u'lvm-pv', u'mount_point': None, 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/bq8spq/blockdevices/4/partition/8'}]}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'bq8spq', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_interface': {u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 38}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'bq8spq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/interfaces/4/'}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/blockdevices/13/', u'type': u'virtual', u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'28e87c76-3560-43c3-9a40-04c503b3ae3b', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'uuid': u'23183e05-067b-4782-bee6-55710dbd3d26', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bq8spq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 13, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'interface_set': [{u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 38}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'bq8spq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/interfaces/4/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 39}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 18, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'system_id': u'bq8spq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/interfaces/18/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 40}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 19, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'system_id': u'bq8spq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/interfaces/19/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 41}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 20, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'system_id': u'bq8spq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bq8spq/interfaces/20/'}], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/bq8spq/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-12-02 02:16:06,039 [salt.state       :300 ][INFO    ][8496] {'new': {'storage_layout': 'lvm'}}
2019-12-02 02:16:06,039 [salt.state       :1951][INFO    ][8496] Completed state [maas_machines_storage_cmp002_lvm] at time 02:16:06.039542 duration_in_ms=2824.76
2019-12-02 02:16:06,040 [salt.state       :1780][INFO    ][8496] Running state [maas_machines_storage_cmp001_lvm] at time 02:16:06.040091
2019-12-02 02:16:06,040 [salt.state       :1813][INFO    ][8496] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-02 02:16:07,346 [salt.loaded.ext.module.maasng:610 ][INFO    ][8496] q3dpgd
2019-12-02 02:16:07,347 [salt.loaded.ext.module.maasng:626 ][INFO    ][8496] sda
2019-12-02 02:16:08,094 [salt.loaded.ext.module.maasng:361 ][INFO    ][8496] q3dpgd
2019-12-02 02:16:08,215 [salt.loaded.ext.module.maasng:367 ][INFO    ][8496] [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'1421f1b5-dfee-463f-b5c9-211a153bdf60', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'q3dpgd', u'device_id': 1, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'31a98b46-ef72-4f66-953d-f1e3430e8c20', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/1/partition/1'}], u'filesystem': None, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'q3dpgd', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'used_for': u'GPT partitioned with 1 partition', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/1/'}, {u'size': 2397988454400, u'uuid': u'1f4e528d-ad73-4a19-a82c-452cbe053fb2', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'4b9bd342-6bfc-4cea-bfd5-6c2570d703e9', u'label': u'root'}, u'id': 6, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'q3dpgd', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'model': None, u'block_size': 4096, u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/6/'}]
2019-12-02 02:16:08,216 [salt.loaded.ext.module.maasng:632 ][INFO    ][8496] vgroot
2019-12-02 02:16:08,216 [salt.loaded.ext.module.maasng:635 ][INFO    ][8496] lvroot
2019-12-02 02:16:08,216 [salt.loaded.ext.module.maasng:639 ][INFO    ][8496] 107374182400
2019-12-02 02:16:08,949 [salt.loaded.ext.module.maasng:645 ][INFO    ][8496] {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'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'fqdn': u'cmp001.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'q3dpgd', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'0eb4f38e-6da9-44f9-8448-d910cc0b88c1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'q3dpgd', u'filesystem': {u'mount_options': None, u'uuid': u'7b9d7baa-25b2-481f-b3db-43feb3a3d958', u'fstype': u'lvm-pv', u'mount_point': None, 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/q3dpgd/blockdevices/1/partition/9'}]}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'q3dpgd', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'0eb4f38e-6da9-44f9-8448-d910cc0b88c1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'q3dpgd', u'filesystem': {u'mount_options': None, u'uuid': u'7b9d7baa-25b2-481f-b3db-43feb3a3d958', u'fstype': u'lvm-pv', u'mount_point': None, 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/q3dpgd/blockdevices/1/partition/9'}]}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/14/', u'type': u'virtual', u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'385bebc4-f25d-4695-8dec-c4c5f7d75490', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'uuid': u'847fdd7c-0862-4ce9-8426-35ec1c4c8b4d', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'q3dpgd', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 14, u'partitions': []}], u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'q3dpgd', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'q3dpgd', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'0eb4f38e-6da9-44f9-8448-d910cc0b88c1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'q3dpgd', u'filesystem': {u'mount_options': None, u'uuid': u'7b9d7baa-25b2-481f-b3db-43feb3a3d958', u'fstype': u'lvm-pv', u'mount_point': None, 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/q3dpgd/blockdevices/1/partition/9'}]}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'q3dpgd', u'id': 9}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_interface': {u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 17}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'q3dpgd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/interfaces/5/'}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/blockdevices/14/', u'type': u'virtual', u'tags': [], u'filesystem': {u'mount_options': None, u'uuid': u'385bebc4-f25d-4695-8dec-c4c5f7d75490', u'fstype': u'ext4', u'mount_point': u'/', u'label': u'root'}, u'uuid': u'847fdd7c-0862-4ce9-8426-35ec1c4c8b4d', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'q3dpgd', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 14, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'interface_set': [{u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 17}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'q3dpgd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/interfaces/5/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 20}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 11, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'q3dpgd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/interfaces/11/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 9, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'q3dpgd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/interfaces/9/'}, {u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 19}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 10, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'q3dpgd', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/q3dpgd/interfaces/10/'}], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/q3dpgd/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-12-02 02:16:08,951 [salt.state       :300 ][INFO    ][8496] {'new': {'storage_layout': 'lvm'}}
2019-12-02 02:16:08,951 [salt.state       :1951][INFO    ][8496] Completed state [maas_machines_storage_cmp001_lvm] at time 02:16:08.951303 duration_in_ms=2911.212
2019-12-02 02:16:08,954 [salt.minion      :1711][INFO    ][8496] Returning information for job: 20191202021557695587
2019-12-02 02:16:09,599 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202021609584876
2019-12-02 02:16:09,621 [salt.minion      :1432][INFO    ][8539] Starting a new job with PID 8539
2019-12-02 02:16:10,516 [salt.state       :915 ][INFO    ][8539] Loading fresh modules for state activity
2019-12-02 02:16:10,569 [salt.fileclient  :1219][INFO    ][8539] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-12-02 02:16:10,609 [salt.state       :1780][INFO    ][8539] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:10.609870
2019-12-02 02:16:10,610 [salt.state       :1813][INFO    ][8539] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:16:10,612 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8539] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:16:12,075 [salt.state       :300 ][INFO    ][8539] {'pid': 8546, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:16:12,076 [salt.state       :1951][INFO    ][8539] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:12.076195 duration_in_ms=1466.326
2019-12-02 02:16:12,077 [salt.state       :1780][INFO    ][8539] Running state [maas.deploy_machines] at time 02:16:12.077429
2019-12-02 02:16:12,077 [salt.state       :1813][INFO    ][8539] Executing state module.run for [maas.deploy_machines]
2019-12-02 02:16:12,078 [salt.utils.decorators:613 ][WARNING ][8539] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:16:12,799 [salt.loaded.ext.module.maas:684 ][INFO    ][8539] deploymachines hwe_kernel=ga-16.04 system_id=bq8spq distro_series=xenial
2019-12-02 02:16:15,541 [salt.loaded.ext.module.maas:684 ][INFO    ][8539] deploymachines hwe_kernel=ga-16.04 system_id=q3dpgd distro_series=xenial
2019-12-02 02:16:18,227 [salt.loaded.ext.module.maas:684 ][INFO    ][8539] deploymachines hwe_kernel=ga-16.04 system_id=at386h distro_series=xenial
2019-12-02 02:16:20,568 [salt.loaded.ext.module.maas:684 ][INFO    ][8539] deploymachines hwe_kernel=ga-16.04 system_id=tnfy7m distro_series=xenial
2019-12-02 02:16:22,938 [salt.loaded.ext.module.maas:684 ][INFO    ][8539] deploymachines hwe_kernel=ga-16.04 system_id=7gp3bc distro_series=xenial
2019-12-02 02:16:24,674 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021624661565
2019-12-02 02:16:24,696 [salt.minion      :1432][INFO    ][8819] Starting a new job with PID 8819
2019-12-02 02:16:24,719 [salt.minion      :1711][INFO    ][8819] Returning information for job: 20191202021624661565
2019-12-02 02:16:25,610 [salt.state       :300 ][INFO    ][8539] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-12-02 02:16:25,610 [salt.state       :1951][INFO    ][8539] Completed state [maas.deploy_machines] at time 02:16:25.610540 duration_in_ms=13533.109
2019-12-02 02:16:25,613 [salt.minion      :1711][INFO    ][8539] Returning information for job: 20191202021609584876
2019-12-02 02:16:26,297 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202021626283786
2019-12-02 02:16:26,318 [salt.minion      :1432][INFO    ][8835] Starting a new job with PID 8835
2019-12-02 02:16:29,924 [salt.state       :915 ][INFO    ][8835] Loading fresh modules for state activity
2019-12-02 02:16:29,972 [salt.fileclient  :1219][INFO    ][8835] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-12-02 02:16:30,014 [salt.state       :1780][INFO    ][8835] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:30.014870
2019-12-02 02:16:30,015 [salt.state       :1813][INFO    ][8835] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:16:30,017 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8835] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:16:31,532 [salt.state       :300 ][INFO    ][8835] {'pid': 8849, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:16:31,533 [salt.state       :1951][INFO    ][8835] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:16:31.533784 duration_in_ms=1518.914
2019-12-02 02:16:31,536 [salt.state       :1780][INFO    ][8835] Running state [maas.wait_for_machine_status] at time 02:16:31.536678
2019-12-02 02:16:31,537 [salt.state       :1813][INFO    ][8835] Executing state module.run for [maas.wait_for_machine_status]
2019-12-02 02:16:31,538 [salt.utils.decorators:613 ][WARNING ][8835] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:16:34,783 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.76326799s left)
2019-12-02 02:16:41,325 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021641311942
2019-12-02 02:16:41,348 [salt.minion      :1432][INFO    ][8864] Starting a new job with PID 8864
2019-12-02 02:16:41,373 [salt.minion      :1711][INFO    ][8864] Returning information for job: 20191202021641311942
2019-12-02 02:17:08,246 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.30001998s left)
2019-12-02 02:17:11,380 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021711367596
2019-12-02 02:17:11,402 [salt.minion      :1432][INFO    ][8906] Starting a new job with PID 8906
2019-12-02 02:17:11,426 [salt.minion      :1711][INFO    ][8906] Returning information for job: 20191202021711367596
2019-12-02 02:17:41,409 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.13744497s left)
2019-12-02 02:17:41,479 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021741466088
2019-12-02 02:17:41,500 [salt.minion      :1432][INFO    ][8941] Starting a new job with PID 8941
2019-12-02 02:17:41,523 [salt.minion      :1711][INFO    ][8941] Returning information for job: 20191202021741466088
2019-12-02 02:18:11,517 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021811504710
2019-12-02 02:18:11,537 [salt.minion      :1432][INFO    ][9073] Starting a new job with PID 9073
2019-12-02 02:18:11,559 [salt.minion      :1711][INFO    ][9073] Returning information for job: 20191202021811504710
2019-12-02 02:18:15,249 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.29785585s left)
2019-12-02 02:18:41,564 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021841551598
2019-12-02 02:18:41,587 [salt.minion      :1432][INFO    ][9280] Starting a new job with PID 9280
2019-12-02 02:18:41,610 [salt.minion      :1711][INFO    ][9280] Returning information for job: 20191202021841551598
2019-12-02 02:18:48,375 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.17104292s left)
2019-12-02 02:19:11,628 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021911616370
2019-12-02 02:19:11,651 [salt.minion      :1432][INFO    ][9865] Starting a new job with PID 9865
2019-12-02 02:19:11,673 [salt.minion      :1711][INFO    ][9865] Returning information for job: 20191202021911616370
2019-12-02 02:19:21,623 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.92315197s left)
2019-12-02 02:19:41,691 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202021941676990
2019-12-02 02:19:41,712 [salt.minion      :1432][INFO    ][10089] Starting a new job with PID 10089
2019-12-02 02:19:41,733 [salt.minion      :1711][INFO    ][10089] Returning information for job: 20191202021941676990
2019-12-02 02:19:54,961 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.58525991s left)
2019-12-02 02:20:11,752 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022011740421
2019-12-02 02:20:11,774 [salt.minion      :1432][INFO    ][10208] Starting a new job with PID 10208
2019-12-02 02:20:11,796 [salt.minion      :1711][INFO    ][10208] Returning information for job: 20191202022011740421
2019-12-02 02:20:28,422 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.12407994s left)
2019-12-02 02:20:41,819 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022041804651
2019-12-02 02:20:41,841 [salt.minion      :1432][INFO    ][10267] Starting a new job with PID 10267
2019-12-02 02:20:41,865 [salt.minion      :1711][INFO    ][10267] Returning information for job: 20191202022041804651
2019-12-02 02:21:02,108 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.43803096s left)
2019-12-02 02:21:11,891 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022111878273
2019-12-02 02:21:11,913 [salt.minion      :1432][INFO    ][10526] Starting a new job with PID 10526
2019-12-02 02:21:11,936 [salt.minion      :1711][INFO    ][10526] Returning information for job: 20191202022111878273
2019-12-02 02:21:35,682 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.86465502s left)
2019-12-02 02:21:41,965 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022141952433
2019-12-02 02:21:41,987 [salt.minion      :1432][INFO    ][10619] Starting a new job with PID 10619
2019-12-02 02:21:42,009 [salt.minion      :1711][INFO    ][10619] Returning information for job: 20191202022141952433
2019-12-02 02:22:09,124 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.42204881s left)
2019-12-02 02:22:12,039 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022212027209
2019-12-02 02:22:12,061 [salt.minion      :1432][INFO    ][10863] Starting a new job with PID 10863
2019-12-02 02:22:12,082 [salt.minion      :1711][INFO    ][10863] Returning information for job: 20191202022212027209
2019-12-02 02:22:42,119 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022242106610
2019-12-02 02:22:42,137 [salt.minion      :1432][INFO    ][10948] Starting a new job with PID 10948
2019-12-02 02:22:42,159 [salt.minion      :1711][INFO    ][10948] Returning information for job: 20191202022242106610
2019-12-02 02:22:42,555 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.99125099s left)
2019-12-02 02:23:12,200 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022312187116
2019-12-02 02:23:12,222 [salt.minion      :1432][INFO    ][11272] Starting a new job with PID 11272
2019-12-02 02:23:12,246 [salt.minion      :1711][INFO    ][11272] Returning information for job: 20191202022312187116
2019-12-02 02:23:15,934 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.61282992s left)
2019-12-02 02:23:42,296 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022342283287
2019-12-02 02:23:42,317 [salt.minion      :1432][INFO    ][11377] Starting a new job with PID 11377
2019-12-02 02:23:42,339 [salt.minion      :1711][INFO    ][11377] Returning information for job: 20191202022342283287
2019-12-02 02:23:49,250 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.29620385s left)
2019-12-02 02:24:12,389 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022412376301
2019-12-02 02:24:12,411 [salt.minion      :1432][INFO    ][11418] Starting a new job with PID 11418
2019-12-02 02:24:12,435 [salt.minion      :1711][INFO    ][11418] Returning information for job: 20191202022412376301
2019-12-02 02:24:22,943 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1778.60305786s left)
2019-12-02 02:24:42,497 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022442484472
2019-12-02 02:24:42,519 [salt.minion      :1432][INFO    ][11526] Starting a new job with PID 11526
2019-12-02 02:24:42,541 [salt.minion      :1711][INFO    ][11526] Returning information for job: 20191202022442484472
2019-12-02 02:24:55,927 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1745.6195159s left)
2019-12-02 02:25:12,520 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022512507726
2019-12-02 02:25:12,543 [salt.minion      :1432][INFO    ][11843] Starting a new job with PID 11843
2019-12-02 02:25:12,565 [salt.minion      :1711][INFO    ][11843] Returning information for job: 20191202022512507726
2019-12-02 02:25:29,474 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1712.07284498s left)
2019-12-02 02:25:42,640 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022542627316
2019-12-02 02:25:42,661 [salt.minion      :1432][INFO    ][11987] Starting a new job with PID 11987
2019-12-02 02:25:42,685 [salt.minion      :1711][INFO    ][11987] Returning information for job: 20191202022542627316
2019-12-02 02:26:02,583 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1678.9634769s left)
2019-12-02 02:26:12,772 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022612755717
2019-12-02 02:26:12,794 [salt.minion      :1432][INFO    ][12252] Starting a new job with PID 12252
2019-12-02 02:26:12,817 [salt.minion      :1711][INFO    ][12252] Returning information for job: 20191202022612755717
2019-12-02 02:26:36,354 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1645.19268084s left)
2019-12-02 02:26:42,907 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022642894315
2019-12-02 02:26:42,930 [salt.minion      :1432][INFO    ][12305] Starting a new job with PID 12305
2019-12-02 02:26:42,954 [salt.minion      :1711][INFO    ][12305] Returning information for job: 20191202022642894315
2019-12-02 02:27:09,916 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1611.63008499s left)
2019-12-02 02:27:13,053 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022713038286
2019-12-02 02:27:13,075 [salt.minion      :1432][INFO    ][12346] Starting a new job with PID 12346
2019-12-02 02:27:13,099 [salt.minion      :1711][INFO    ][12346] Returning information for job: 20191202022713038286
2019-12-02 02:27:43,206 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022743193807
2019-12-02 02:27:43,225 [salt.minion      :1432][INFO    ][12382] Starting a new job with PID 12382
2019-12-02 02:27:43,233 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.31367397s left)
2019-12-02 02:27:43,244 [salt.minion      :1711][INFO    ][12382] Returning information for job: 20191202022743193807
2019-12-02 02:28:13,356 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022813342572
2019-12-02 02:28:13,380 [salt.minion      :1432][INFO    ][12419] Starting a new job with PID 12419
2019-12-02 02:28:13,403 [salt.minion      :1711][INFO    ][12419] Returning information for job: 20191202022813342572
2019-12-02 02:28:16,784 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1544.76204085s left)
2019-12-02 02:28:43,525 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022843512767
2019-12-02 02:28:43,547 [salt.minion      :1432][INFO    ][12456] Starting a new job with PID 12456
2019-12-02 02:28:43,570 [salt.minion      :1711][INFO    ][12456] Returning information for job: 20191202022843512767
2019-12-02 02:28:50,359 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1511.18777204s left)
2019-12-02 02:29:13,694 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022913681372
2019-12-02 02:29:13,716 [salt.minion      :1432][INFO    ][12504] Starting a new job with PID 12504
2019-12-02 02:29:13,738 [salt.minion      :1711][INFO    ][12504] Returning information for job: 20191202022913681372
2019-12-02 02:29:23,599 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1477.94715095s left)
2019-12-02 02:29:43,884 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202022943871251
2019-12-02 02:29:43,907 [salt.minion      :1432][INFO    ][12546] Starting a new job with PID 12546
2019-12-02 02:29:43,931 [salt.minion      :1711][INFO    ][12546] Returning information for job: 20191202022943871251
2019-12-02 02:29:57,133 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1444.41340089s left)
2019-12-02 02:30:14,088 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023014075471
2019-12-02 02:30:14,110 [salt.minion      :1432][INFO    ][12731] Starting a new job with PID 12731
2019-12-02 02:30:14,135 [salt.minion      :1711][INFO    ][12731] Returning information for job: 20191202023014075471
2019-12-02 02:30:30,303 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1411.24377799s left)
2019-12-02 02:30:44,300 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023044287921
2019-12-02 02:30:44,322 [salt.minion      :1432][INFO    ][12776] Starting a new job with PID 12776
2019-12-02 02:30:44,346 [salt.minion      :1711][INFO    ][12776] Returning information for job: 20191202023044287921
2019-12-02 02:31:03,767 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1377.77930498s left)
2019-12-02 02:31:14,522 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023114510572
2019-12-02 02:31:14,538 [salt.minion      :1432][INFO    ][12817] Starting a new job with PID 12817
2019-12-02 02:31:14,560 [salt.minion      :1711][INFO    ][12817] Returning information for job: 20191202023114510572
2019-12-02 02:31:37,302 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1344.24479604s left)
2019-12-02 02:31:44,751 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023144738566
2019-12-02 02:31:44,773 [salt.minion      :1432][INFO    ][12853] Starting a new job with PID 12853
2019-12-02 02:31:44,796 [salt.minion      :1711][INFO    ][12853] Returning information for job: 20191202023144738566
2019-12-02 02:32:10,764 [salt.loaded.ext.module.maas:1023][INFO    ][8835] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1310.78264689s left)
2019-12-02 02:32:14,782 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023214769840
2019-12-02 02:32:14,805 [salt.minion      :1432][INFO    ][12892] Starting a new job with PID 12892
2019-12-02 02:32:14,829 [salt.minion      :1711][INFO    ][12892] Returning information for job: 20191202023214769840
2019-12-02 02:32:43,413 [salt.loaded.ext.module.maas:993 ][INFO    ][8835] Machine tnfy7m mark broken
2019-12-02 02:32:44,125 [salt.loaded.ext.module.maas:996 ][INFO    ][8835] Machine tnfy7m mark fixed
2019-12-02 02:32:44,827 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023244814276
2019-12-02 02:32:44,846 [salt.minion      :1432][INFO    ][12944] Starting a new job with PID 12944
2019-12-02 02:32:44,868 [salt.minion      :1711][INFO    ][12944] Returning information for job: 20191202023244814276
2019-12-02 02:32:45,387 [salt.loaded.ext.module.maas:684 ][INFO    ][8835] deploymachines hwe_kernel=ga-16.04 system_id=tnfy7m distro_series=xenial
2019-12-02 02:32:48,085 [salt.loaded.ext.module.maas:160 ][ERROR   ][8835] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-12-02 02:32:48,087 [salt.state       :302 ][ERROR   ][8835] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-12-02 02:32:48,088 [salt.state       :1951][INFO    ][8835] Completed state [maas.wait_for_machine_status] at time 02:32:48.088371 duration_in_ms=976551.687
2019-12-02 02:32:48,098 [salt.minion      :1711][INFO    ][8835] Returning information for job: 20191202021626283786
2019-12-02 02:32:58,902 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command pillar.get with jid 20191202023258890459
2019-12-02 02:32:58,924 [salt.minion      :1432][INFO    ][13016] Starting a new job with PID 13016
2019-12-02 02:32:58,933 [salt.minion      :1711][INFO    ][13016] Returning information for job: 20191202023258890459
2019-12-02 02:32:59,446 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command service.status with jid 20191202023259433345
2019-12-02 02:32:59,467 [salt.minion      :1432][INFO    ][13021] Starting a new job with PID 13021
2019-12-02 02:32:59,858 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13021] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-12-02 02:32:59,891 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13021] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-12-02 02:32:59,907 [salt.minion      :1711][INFO    ][13021] Returning information for job: 20191202023259433345
2019-12-02 02:33:00,404 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202023300391178
2019-12-02 02:33:00,425 [salt.minion      :1432][INFO    ][13032] Starting a new job with PID 13032
2019-12-02 02:33:04,212 [salt.state       :915 ][INFO    ][13032] Loading fresh modules for state activity
2019-12-02 02:33:04,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'salt-minion --version' in directory '/root'
2019-12-02 02:33:04,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'salt-minion --version' in directory '/root'
2019-12-02 02:33:05,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'salt-minion --version' in directory '/root'
2019-12-02 02:33:06,081 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'salt-minion --version' in directory '/root'
2019-12-02 02:33:07,435 [salt.state       :1780][INFO    ][13032] Running state [salt-minion] at time 02:33:07.435436
2019-12-02 02:33:07,435 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [salt-minion]
2019-12-02 02:33:07,436 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-02 02:33:07,530 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,531 [salt.state       :1951][INFO    ][13032] Completed state [salt-minion] at time 02:33:07.531046 duration_in_ms=95.611
2019-12-02 02:33:07,531 [salt.state       :1780][INFO    ][13032] Running state [salt_minion_dependency_packages] at time 02:33:07.531409
2019-12-02 02:33:07,531 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-12-02 02:33:07,539 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,539 [salt.state       :1951][INFO    ][13032] Completed state [salt_minion_dependency_packages] at time 02:33:07.539191 duration_in_ms=7.782
2019-12-02 02:33:07,542 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/minion.d/minion.conf] at time 02:33:07.542473
2019-12-02 02:33:07,542 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-12-02 02:33:07,762 [salt.state       :300 ][INFO    ][13032] File /etc/salt/minion.d/minion.conf is in the correct state
2019-12-02 02:33:07,763 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/minion.d/minion.conf] at time 02:33:07.763213 duration_in_ms=220.74
2019-12-02 02:33:07,763 [salt.state       :1780][INFO    ][13032] Running state [python-netaddr] at time 02:33:07.763473
2019-12-02 02:33:07,763 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [python-netaddr]
2019-12-02 02:33:07,770 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,771 [salt.state       :1951][INFO    ][13032] Completed state [python-netaddr] at time 02:33:07.771011 duration_in_ms=7.538
2019-12-02 02:33:07,774 [salt.state       :1780][INFO    ][13032] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:33:07.774205
2019-12-02 02:33:07,774 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-12-02 02:33:07,784 [salt.state       :300 ][INFO    ][13032] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-12-02 02:33:07,785 [salt.state       :1951][INFO    ][13032] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:33:07.785005 duration_in_ms=10.801
2019-12-02 02:33:07,786 [salt.state       :1780][INFO    ][13032] Running state [salt-minion] at time 02:33:07.785991
2019-12-02 02:33:07,786 [salt.state       :1813][INFO    ][13032] Executing state service.running for [salt-minion]
2019-12-02 02:33:07,786 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:07,823 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-12-02 02:33:07,841 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-12-02 02:33:07,856 [salt.state       :300 ][INFO    ][13032] The service salt-minion is already running
2019-12-02 02:33:07,857 [salt.state       :1951][INFO    ][13032] Completed state [salt-minion] at time 02:33:07.857221 duration_in_ms=71.227
2019-12-02 02:33:07,859 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains.d] at time 02:33:07.859752
2019-12-02 02:33:07,860 [salt.state       :1813][INFO    ][13032] Executing state file.directory for [/etc/salt/grains.d]
2019-12-02 02:33:07,862 [salt.state       :300 ][INFO    ][13032] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-12-02 02:33:07,862 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains.d] at time 02:33:07.862350 duration_in_ms=2.597
2019-12-02 02:33:07,863 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains] at time 02:33:07.863819
2019-12-02 02:33:07,864 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/grains]
2019-12-02 02:33:07,865 [salt.state       :300 ][INFO    ][13032] File /etc/salt/grains exists with proper permissions. No changes made.
2019-12-02 02:33:07,865 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains] at time 02:33:07.865824 duration_in_ms=2.004
2019-12-02 02:33:07,866 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains.d/placeholder] at time 02:33:07.866796
2019-12-02 02:33:07,867 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-12-02 02:33:07,868 [salt.state       :300 ][INFO    ][13032] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-12-02 02:33:07,868 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains.d/placeholder] at time 02:33:07.868706 duration_in_ms=1.909
2019-12-02 02:33:07,869 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains.d/sphinx] at time 02:33:07.869632
2019-12-02 02:33:07,870 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-12-02 02:33:07,883 [salt.state       :300 ][INFO    ][13032] File /etc/salt/grains.d/sphinx is in the correct state
2019-12-02 02:33:07,883 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains.d/sphinx] at time 02:33:07.883470 duration_in_ms=13.838
2019-12-02 02:33:07,887 [salt.state       :1780][INFO    ][13032] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.887201
2019-12-02 02:33:07,887 [salt.state       :1813][INFO    ][13032] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-12-02 02:33:07,888 [salt.state       :300 ][INFO    ][13032] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-12-02 02:33:07,888 [salt.state       :1951][INFO    ][13032] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.888626 duration_in_ms=1.425
2019-12-02 02:33:07,889 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains.d/dns_records] at time 02:33:07.889417
2019-12-02 02:33:07,889 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-12-02 02:33:07,900 [salt.state       :300 ][INFO    ][13032] File /etc/salt/grains.d/dns_records is in the correct state
2019-12-02 02:33:07,901 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains.d/dns_records] at time 02:33:07.901224 duration_in_ms=11.807
2019-12-02 02:33:07,902 [salt.state       :1780][INFO    ][13032] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.902722
2019-12-02 02:33:07,903 [salt.state       :1813][INFO    ][13032] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-12-02 02:33:07,903 [salt.state       :300 ][INFO    ][13032] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-12-02 02:33:07,904 [salt.state       :1951][INFO    ][13032] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.904031 duration_in_ms=1.309
2019-12-02 02:33:07,904 [salt.state       :1780][INFO    ][13032] Running state [/etc/salt/grains.d/salt] at time 02:33:07.904782
2019-12-02 02:33:07,905 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-12-02 02:33:07,918 [salt.state       :300 ][INFO    ][13032] File /etc/salt/grains.d/salt is in the correct state
2019-12-02 02:33:07,919 [salt.state       :1951][INFO    ][13032] Completed state [/etc/salt/grains.d/salt] at time 02:33:07.919119 duration_in_ms=14.337
2019-12-02 02:33:07,920 [salt.state       :1780][INFO    ][13032] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.920426
2019-12-02 02:33:07,920 [salt.state       :1813][INFO    ][13032] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-12-02 02:33:07,921 [salt.state       :300 ][INFO    ][13032] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-12-02 02:33:07,921 [salt.state       :1951][INFO    ][13032] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:33:07.921670 duration_in_ms=1.244
2019-12-02 02:33:07,924 [salt.state       :1780][INFO    ][13032] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:33:07.924506
2019-12-02 02:33:07,924 [salt.state       :1813][INFO    ][13032] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-12-02 02:33:07,925 [salt.state       :300 ][INFO    ][13032] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-12-02 02:33:07,925 [salt.state       :1951][INFO    ][13032] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:33:07.925748 duration_in_ms=1.242
2019-12-02 02:33:07,926 [salt.state       :1780][INFO    ][13032] Running state [mine.update] at time 02:33:07.926745
2019-12-02 02:33:07,927 [salt.state       :1813][INFO    ][13032] Executing state module.wait for [mine.update]
2019-12-02 02:33:07,927 [salt.state       :300 ][INFO    ][13032] No changes made for mine.update
2019-12-02 02:33:07,927 [salt.state       :1951][INFO    ][13032] Completed state [mine.update] at time 02:33:07.927883 duration_in_ms=1.138
2019-12-02 02:33:07,928 [salt.state       :1780][INFO    ][13032] Running state [ca-certificates] at time 02:33:07.928228
2019-12-02 02:33:07,928 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [ca-certificates]
2019-12-02 02:33:07,939 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,939 [salt.state       :1951][INFO    ][13032] Completed state [ca-certificates] at time 02:33:07.939689 duration_in_ms=11.461
2019-12-02 02:33:07,940 [salt.state       :1780][INFO    ][13032] Running state [update-ca-certificates] at time 02:33:07.940673
2019-12-02 02:33:07,941 [salt.state       :1813][INFO    ][13032] Executing state cmd.wait for [update-ca-certificates]
2019-12-02 02:33:07,941 [salt.state       :300 ][INFO    ][13032] No changes made for update-ca-certificates
2019-12-02 02:33:07,941 [salt.state       :1951][INFO    ][13032] Completed state [update-ca-certificates] at time 02:33:07.941806 duration_in_ms=1.132
2019-12-02 02:33:07,942 [salt.state       :1780][INFO    ][13032] Running state [iptables] at time 02:33:07.942142
2019-12-02 02:33:07,942 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [iptables]
2019-12-02 02:33:07,952 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,952 [salt.state       :1951][INFO    ][13032] Completed state [iptables] at time 02:33:07.952311 duration_in_ms=10.169
2019-12-02 02:33:07,952 [salt.state       :1780][INFO    ][13032] Running state [iptables-persistent] at time 02:33:07.952659
2019-12-02 02:33:07,953 [salt.state       :1813][INFO    ][13032] Executing state pkg.installed for [iptables-persistent]
2019-12-02 02:33:07,962 [salt.state       :300 ][INFO    ][13032] All specified packages are already installed
2019-12-02 02:33:07,962 [salt.state       :1951][INFO    ][13032] Completed state [iptables-persistent] at time 02:33:07.962359 duration_in_ms=9.701
2019-12-02 02:33:07,963 [salt.state       :1780][INFO    ][13032] Running state [iptables_modules_v4_load] at time 02:33:07.963676
2019-12-02 02:33:07,964 [salt.state       :1813][INFO    ][13032] Executing state kmod.present for [iptables_modules_v4_load]
2019-12-02 02:33:07,964 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'lsmod' in directory '/root'
2019-12-02 02:33:07,987 [salt.state       :300 ][INFO    ][13032] Kernel modules iptable_filter, ip_tables are already present
2019-12-02 02:33:07,987 [salt.state       :1951][INFO    ][13032] Completed state [iptables_modules_v4_load] at time 02:33:07.987854 duration_in_ms=24.177
2019-12-02 02:33:07,988 [salt.state       :1780][INFO    ][13032] Running state [/etc/iptables/rules.v4] at time 02:33:07.988658
2019-12-02 02:33:07,989 [salt.state       :1813][INFO    ][13032] Executing state file.managed for [/etc/iptables/rules.v4]
2019-12-02 02:33:08,086 [salt.state       :300 ][INFO    ][13032] File /etc/iptables/rules.v4 is in the correct state
2019-12-02 02:33:08,086 [salt.state       :1951][INFO    ][13032] Completed state [/etc/iptables/rules.v4] at time 02:33:08.086818 duration_in_ms=98.16
2019-12-02 02:33:08,087 [salt.state       :1780][INFO    ][13032] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:33:08.087922
2019-12-02 02:33:08,088 [salt.state       :1813][INFO    ][13032] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-12-02 02:33:08,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-12-02 02:33:08,107 [salt.state       :300 ][INFO    ][13032] onlyif execution failed
2019-12-02 02:33:08,107 [salt.state       :1951][INFO    ][13032] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:33:08.107431 duration_in_ms=19.51
2019-12-02 02:33:08,108 [salt.state       :1780][INFO    ][13032] Running state [netfilter-persistent] at time 02:33:08.108538
2019-12-02 02:33:08,108 [salt.state       :1813][INFO    ][13032] Executing state service.running for [netfilter-persistent]
2019-12-02 02:33:08,109 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:08,126 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-12-02 02:33:08,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-12-02 02:33:08,156 [salt.state       :300 ][INFO    ][13032] The service netfilter-persistent is already running
2019-12-02 02:33:08,156 [salt.state       :1951][INFO    ][13032] Completed state [netfilter-persistent] at time 02:33:08.156617 duration_in_ms=48.079
2019-12-02 02:33:08,157 [salt.state       :1780][INFO    ][13032] Running state [iptables_extra.remove_stale_tables] at time 02:33:08.157371
2019-12-02 02:33:08,157 [salt.state       :1813][INFO    ][13032] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-12-02 02:33:08,158 [salt.state       :300 ][INFO    ][13032] No changes made for iptables_extra.remove_stale_tables
2019-12-02 02:33:08,158 [salt.state       :1951][INFO    ][13032] Completed state [iptables_extra.remove_stale_tables] at time 02:33:08.158202 duration_in_ms=0.83
2019-12-02 02:33:08,158 [salt.state       :1780][INFO    ][13032] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:33:08.158432
2019-12-02 02:33:08,158 [salt.state       :1813][INFO    ][13032] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-12-02 02:33:08,159 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13032] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-12-02 02:33:08,171 [salt.state       :300 ][INFO    ][13032] onlyif execution failed
2019-12-02 02:33:08,172 [salt.state       :1951][INFO    ][13032] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:33:08.172093 duration_in_ms=13.66
2019-12-02 02:33:08,173 [salt.state       :1780][INFO    ][13032] Running state [/etc/iptables/rules.v6] at time 02:33:08.172982
2019-12-02 02:33:08,173 [salt.state       :1813][INFO    ][13032] Executing state file.absent for [/etc/iptables/rules.v6]
2019-12-02 02:33:08,173 [salt.state       :300 ][INFO    ][13032] File /etc/iptables/rules.v6 is not present
2019-12-02 02:33:08,173 [salt.state       :1951][INFO    ][13032] Completed state [/etc/iptables/rules.v6] at time 02:33:08.173929 duration_in_ms=0.947
2019-12-02 02:33:08,174 [salt.state       :1780][INFO    ][13032] Running state [iptables_extra.flush_all] at time 02:33:08.174571
2019-12-02 02:33:08,174 [salt.state       :1813][INFO    ][13032] Executing state module.wait for [iptables_extra.flush_all]
2019-12-02 02:33:08,175 [salt.state       :300 ][INFO    ][13032] No changes made for iptables_extra.flush_all
2019-12-02 02:33:08,175 [salt.state       :1951][INFO    ][13032] Completed state [iptables_extra.flush_all] at time 02:33:08.175310 duration_in_ms=0.739
2019-12-02 02:33:08,178 [salt.minion      :1711][INFO    ][13032] Returning information for job: 20191202023300391178
2019-12-02 02:33:08,814 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202023308801170
2019-12-02 02:33:08,836 [salt.minion      :1432][INFO    ][13124] Starting a new job with PID 13124
2019-12-02 02:33:09,568 [salt.state       :915 ][INFO    ][13124] Loading fresh modules for state activity
2019-12-02 02:33:10,238 [salt.state       :1780][INFO    ][13124] Running state [maas-rack-controller] at time 02:33:10.238011
2019-12-02 02:33:10,238 [salt.state       :1813][INFO    ][13124] Executing state pkg.installed for [maas-rack-controller]
2019-12-02 02:33:10,238 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13124] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-02 02:33:10,338 [salt.state       :300 ][INFO    ][13124] All specified packages are already installed
2019-12-02 02:33:10,338 [salt.state       :1951][INFO    ][13124] Completed state [maas-rack-controller] at time 02:33:10.338583 duration_in_ms=100.571
2019-12-02 02:33:10,338 [salt.state       :1780][INFO    ][13124] Running state [ipmitool] at time 02:33:10.338948
2019-12-02 02:33:10,339 [salt.state       :1813][INFO    ][13124] Executing state pkg.installed for [ipmitool]
2019-12-02 02:33:10,346 [salt.state       :300 ][INFO    ][13124] All specified packages are already installed
2019-12-02 02:33:10,346 [salt.state       :1951][INFO    ][13124] Completed state [ipmitool] at time 02:33:10.346767 duration_in_ms=7.819
2019-12-02 02:33:10,350 [salt.state       :1780][INFO    ][13124] Running state [/etc/maas/rackd.conf] at time 02:33:10.350021
2019-12-02 02:33:10,350 [salt.state       :1813][INFO    ][13124] Executing state file.line for [/etc/maas/rackd.conf]
2019-12-02 02:33:10,351 [salt.state       :300 ][INFO    ][13124] No changes needed to be made
2019-12-02 02:33:10,351 [salt.state       :1951][INFO    ][13124] Completed state [/etc/maas/rackd.conf] at time 02:33:10.351737 duration_in_ms=1.717
2019-12-02 02:33:10,352 [salt.state       :1780][INFO    ][13124] Running state [/etc/maas/rackd.conf] at time 02:33:10.351981
2019-12-02 02:33:10,352 [salt.state       :1813][INFO    ][13124] Executing state file.managed for [/etc/maas/rackd.conf]
2019-12-02 02:33:10,352 [salt.loaded.int.states.file:2298][WARNING ][13124] 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-12-02 02:33:10,353 [salt.state       :300 ][INFO    ][13124] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-12-02 02:33:10,353 [salt.state       :1951][INFO    ][13124] Completed state [/etc/maas/rackd.conf] at time 02:33:10.353306 duration_in_ms=1.325
2019-12-02 02:33:10,354 [salt.state       :1780][INFO    ][13124] Running state [maas-rackd] at time 02:33:10.354311
2019-12-02 02:33:10,354 [salt.state       :1813][INFO    ][13124] Executing state service.running for [maas-rackd]
2019-12-02 02:33:10,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13124] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:10,389 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13124] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-12-02 02:33:10,406 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13124] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-12-02 02:33:10,423 [salt.state       :300 ][INFO    ][13124] The service maas-rackd is already running
2019-12-02 02:33:10,423 [salt.state       :1951][INFO    ][13124] Completed state [maas-rackd] at time 02:33:10.423630 duration_in_ms=69.319
2019-12-02 02:33:10,425 [salt.minion      :1711][INFO    ][13124] Returning information for job: 20191202023308801170
2019-12-02 02:33:11,047 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202023311034436
2019-12-02 02:33:11,068 [salt.minion      :1432][INFO    ][13147] Starting a new job with PID 13147
2019-12-02 02:33:11,767 [salt.state       :915 ][INFO    ][13147] Loading fresh modules for state activity
2019-12-02 02:33:12,511 [salt.state       :1780][INFO    ][13147] Running state [maas-region-controller] at time 02:33:12.511608
2019-12-02 02:33:12,511 [salt.state       :1813][INFO    ][13147] Executing state pkg.installed for [maas-region-controller]
2019-12-02 02:33:12,512 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-12-02 02:33:12,602 [salt.state       :300 ][INFO    ][13147] All specified packages are already installed
2019-12-02 02:33:12,602 [salt.state       :1951][INFO    ][13147] Completed state [maas-region-controller] at time 02:33:12.602425 duration_in_ms=90.818
2019-12-02 02:33:12,602 [salt.state       :1780][INFO    ][13147] Running state [python-oauth] at time 02:33:12.602761
2019-12-02 02:33:12,603 [salt.state       :1813][INFO    ][13147] Executing state pkg.installed for [python-oauth]
2019-12-02 02:33:12,609 [salt.state       :300 ][INFO    ][13147] All specified packages are already installed
2019-12-02 02:33:12,609 [salt.state       :1951][INFO    ][13147] Completed state [python-oauth] at time 02:33:12.609599 duration_in_ms=6.838
2019-12-02 02:33:12,612 [salt.state       :1780][INFO    ][13147] Running state [/etc/maas/regiond.conf] at time 02:33:12.612585
2019-12-02 02:33:12,612 [salt.state       :1813][INFO    ][13147] Executing state file.replace for [/etc/maas/regiond.conf]
2019-12-02 02:33:12,656 [salt.state       :300 ][INFO    ][13147] No changes needed to be made
2019-12-02 02:33:12,656 [salt.state       :1951][INFO    ][13147] Completed state [/etc/maas/regiond.conf] at time 02:33:12.656281 duration_in_ms=43.696
2019-12-02 02:33:12,656 [salt.state       :1780][INFO    ][13147] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:33:12.656792
2019-12-02 02:33:12,657 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-12-02 02:33:12,721 [salt.state       :300 ][INFO    ][13147] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-12-02 02:33:12,722 [salt.state       :1951][INFO    ][13147] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:33:12.722217 duration_in_ms=65.424
2019-12-02 02:33:12,723 [salt.state       :1780][INFO    ][13147] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:33:12.722998
2019-12-02 02:33:12,723 [salt.state       :1813][INFO    ][13147] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-02 02:33:12,735 [salt.state       :300 ][INFO    ][13147] No changes needed to be made
2019-12-02 02:33:12,736 [salt.state       :1951][INFO    ][13147] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:33:12.736030 duration_in_ms=13.032
2019-12-02 02:33:12,736 [salt.state       :1780][INFO    ][13147] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:33:12.736744
2019-12-02 02:33:12,737 [salt.state       :1813][INFO    ][13147] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-12-02 02:33:12,766 [salt.state       :300 ][INFO    ][13147] No changes needed to be made
2019-12-02 02:33:12,766 [salt.state       :1951][INFO    ][13147] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:33:12.766382 duration_in_ms=29.638
2019-12-02 02:33:12,767 [salt.state       :1780][INFO    ][13147] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:33:12.767197
2019-12-02 02:33:12,767 [salt.state       :1813][INFO    ][13147] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-12-02 02:33:12,811 [salt.state       :300 ][INFO    ][13147] No changes needed to be made
2019-12-02 02:33:12,813 [salt.state       :1951][INFO    ][13147] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:33:12.813780 duration_in_ms=46.582
2019-12-02 02:33:12,815 [salt.state       :1780][INFO    ][13147] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:33:12.815833
2019-12-02 02:33:12,816 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-12-02 02:33:12,837 [salt.state       :300 ][INFO    ][13147] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-12-02 02:33:12,837 [salt.state       :1951][INFO    ][13147] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:33:12.837291 duration_in_ms=21.457
2019-12-02 02:33:12,843 [salt.state       :1780][INFO    ][13147] Running state [a2enmod headers] at time 02:33:12.843735
2019-12-02 02:33:12,844 [salt.state       :1813][INFO    ][13147] Executing state cmd.run for [a2enmod headers]
2019-12-02 02:33:12,845 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command 'a2enmod headers' in directory '/root'
2019-12-02 02:33:12,921 [salt.state       :300 ][INFO    ][13147] {'pid': 13166, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-12-02 02:33:12,922 [salt.state       :1951][INFO    ][13147] Completed state [a2enmod headers] at time 02:33:12.922338 duration_in_ms=78.603
2019-12-02 02:33:12,923 [salt.state       :1780][INFO    ][13147] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:33:12.922955
2019-12-02 02:33:12,923 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-12-02 02:33:12,943 [salt.state       :300 ][INFO    ][13147] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-12-02 02:33:12,943 [salt.state       :1951][INFO    ][13147] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:33:12.943792 duration_in_ms=20.837
2019-12-02 02:33:12,944 [salt.state       :1780][INFO    ][13147] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:33:12.944728
2019-12-02 02:33:12,945 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-12-02 02:33:13,027 [salt.state       :300 ][INFO    ][13147] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-12-02 02:33:13,027 [salt.state       :1951][INFO    ][13147] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:33:13.027709 duration_in_ms=82.98
2019-12-02 02:33:13,028 [salt.state       :1780][INFO    ][13147] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:33:13.028334
2019-12-02 02:33:13,028 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-12-02 02:33:13,092 [salt.state       :300 ][INFO    ][13147] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-12-02 02:33:13,093 [salt.state       :1951][INFO    ][13147] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:33:13.093155 duration_in_ms=64.821
2019-12-02 02:33:13,093 [salt.state       :1780][INFO    ][13147] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:33:13.093683
2019-12-02 02:33:13,094 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-12-02 02:33:13,158 [salt.state       :300 ][INFO    ][13147] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-12-02 02:33:13,159 [salt.state       :1951][INFO    ][13147] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:33:13.159076 duration_in_ms=65.393
2019-12-02 02:33:13,159 [salt.state       :1780][INFO    ][13147] Running state [/root/.pgpass] at time 02:33:13.159386
2019-12-02 02:33:13,159 [salt.state       :1813][INFO    ][13147] Executing state file.managed for [/root/.pgpass]
2019-12-02 02:33:13,206 [salt.state       :300 ][INFO    ][13147] File /root/.pgpass is in the correct state
2019-12-02 02:33:13,207 [salt.state       :1951][INFO    ][13147] Completed state [/root/.pgpass] at time 02:33:13.207030 duration_in_ms=47.644
2019-12-02 02:33:13,212 [salt.state       :1780][INFO    ][13147] Running state [maas-region syncdb --noinput] at time 02:33:13.212831
2019-12-02 02:33:13,213 [salt.state       :1813][INFO    ][13147] Executing state cmd.run for [maas-region syncdb --noinput]
2019-12-02 02:33:13,213 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-12-02 02:33:15,230 [salt.state       :300 ][INFO    ][13147] {'pid': 13179, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, sites, metadataserver, sessions, contenttypes, auth, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-12-02 02:33:15,231 [salt.state       :1951][INFO    ][13147] Completed state [maas-region syncdb --noinput] at time 02:33:15.230886 duration_in_ms=2018.055
2019-12-02 02:33:15,231 [salt.state       :2022][WARNING ][13147] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-12-02 02:33:15,233 [salt.state       :1780][INFO    ][13147] Running state [maas-regiond] at time 02:33:15.233906
2019-12-02 02:33:15,234 [salt.state       :1813][INFO    ][13147] Executing state service.running for [maas-regiond]
2019-12-02 02:33:15,235 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:15,274 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-12-02 02:33:15,293 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-12-02 02:33:15,311 [salt.state       :300 ][INFO    ][13147] The service maas-regiond is already running
2019-12-02 02:33:15,311 [salt.state       :1951][INFO    ][13147] Completed state [maas-regiond] at time 02:33:15.311815 duration_in_ms=77.909
2019-12-02 02:33:15,314 [salt.state       :1780][INFO    ][13147] Running state [bind9] at time 02:33:15.314427
2019-12-02 02:33:15,314 [salt.state       :1813][INFO    ][13147] Executing state service.running for [bind9]
2019-12-02 02:33:15,316 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:15,335 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-12-02 02:33:15,353 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-12-02 02:33:15,370 [salt.state       :300 ][INFO    ][13147] The service bind9 is already running
2019-12-02 02:33:15,371 [salt.state       :1951][INFO    ][13147] Completed state [bind9] at time 02:33:15.371369 duration_in_ms=56.942
2019-12-02 02:33:15,374 [salt.state       :1780][INFO    ][13147] Running state [apache2] at time 02:33:15.374002
2019-12-02 02:33:15,374 [salt.state       :1813][INFO    ][13147] Executing state service.running for [apache2]
2019-12-02 02:33:15,375 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-12-02 02:33:15,394 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-12-02 02:33:15,412 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-12-02 02:33:15,436 [salt.state       :300 ][INFO    ][13147] The service apache2 is already running
2019-12-02 02:33:15,437 [salt.state       :1951][INFO    ][13147] Completed state [apache2] at time 02:33:15.437464 duration_in_ms=63.462
2019-12-02 02:33:15,440 [salt.state       :1780][INFO    ][13147] Running state [maasng.wait_for_http_code] at time 02:33:15.440209
2019-12-02 02:33:15,440 [salt.state       :1813][INFO    ][13147] Executing state module.run for [maasng.wait_for_http_code]
2019-12-02 02:33:15,441 [salt.utils.decorators:613 ][WARNING ][13147] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:33:15,571 [salt.state       :300 ][INFO    ][13147] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-12-02 02:33:15,571 [salt.state       :1951][INFO    ][13147] Completed state [maasng.wait_for_http_code] at time 02:33:15.571759 duration_in_ms=131.549
2019-12-02 02:33:15,573 [salt.state       :1780][INFO    ][13147] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:33:15.573630
2019-12-02 02:33:15,574 [salt.state       :1813][INFO    ][13147] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-12-02 02:33:15,575 [salt.state       :300 ][INFO    ][13147] /var/lib/maas/.setup_admin exists
2019-12-02 02:33:15,575 [salt.state       :1951][INFO    ][13147] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:33:15.575749 duration_in_ms=2.118
2019-12-02 02:33:15,577 [salt.state       :1780][INFO    ][13147] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:33:15.577227
2019-12-02 02:33:15,577 [salt.state       :1813][INFO    ][13147] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:33:15,579 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13147] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:33:16,971 [salt.state       :300 ][INFO    ][13147] {'pid': 13201, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:33:16,972 [salt.state       :1951][INFO    ][13147] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:33:16.972047 duration_in_ms=1394.818
2019-12-02 02:33:16,979 [salt.state       :1780][INFO    ][13147] Running state [maas_region_boot_source_resources_mirror] at time 02:33:16.979844
2019-12-02 02:33:16,980 [salt.state       :1813][INFO    ][13147] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-12-02 02:33:17,079 [salt.state       :300 ][INFO    ][13147] {'changes': {}}
2019-12-02 02:33:17,079 [salt.state       :1951][INFO    ][13147] Completed state [maas_region_boot_source_resources_mirror] at time 02:33:17.079576 duration_in_ms=99.731
2019-12-02 02:33:17,081 [salt.state       :1780][INFO    ][13147] Running state [maasng.boot_resources_import] at time 02:33:17.081017
2019-12-02 02:33:17,081 [salt.state       :1813][INFO    ][13147] Executing state module.run for [maasng.boot_resources_import]
2019-12-02 02:33:17,082 [salt.utils.decorators:613 ][WARNING ][13147] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:33:17,193 [salt.loaded.ext.module.maasng:1600][INFO    ][13147] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-12-02 02:33:22,247 [salt.loaded.ext.module.maasng:1600][INFO    ][13147] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-12-02 02:33:26,149 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023326136715
2019-12-02 02:33:26,171 [salt.minion      :1432][INFO    ][13244] Starting a new job with PID 13244
2019-12-02 02:33:26,195 [salt.minion      :1711][INFO    ][13244] Returning information for job: 20191202023326136715
2019-12-02 02:33:27,309 [salt.loaded.ext.module.maasng:1600][INFO    ][13147] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-12-02 02:33:32,423 [salt.state       :300 ][INFO    ][13147] {'ret': True}
2019-12-02 02:33:32,424 [salt.state       :1951][INFO    ][13147] Completed state [maasng.boot_resources_import] at time 02:33:32.424354 duration_in_ms=15343.336
2019-12-02 02:33:32,425 [salt.state       :1780][INFO    ][13147] Running state [maas_region_boot_sources_selection_xenial] at time 02:33:32.425571
2019-12-02 02:33:32,426 [salt.state       :1813][INFO    ][13147] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-12-02 02:33:32,632 [salt.state       :300 ][INFO    ][13147] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-12-02 02:33:32,633 [salt.state       :1951][INFO    ][13147] Completed state [maas_region_boot_sources_selection_xenial] at time 02:33:32.633171 duration_in_ms=207.601
2019-12-02 02:33:32,634 [salt.state       :1780][INFO    ][13147] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 02:33:32.634515
2019-12-02 02:33:32,635 [salt.state       :1813][INFO    ][13147] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-12-02 02:33:32,635 [salt.utils.decorators:613 ][WARNING ][13147] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:33:32,636 [salt.loaded.ext.module.maasng:1771][INFO    ][13147] boot-sources sync initiated for ALL Rack's
2019-12-02 02:33:33,728 [salt.state       :300 ][INFO    ][13147] {'ret': True}
2019-12-02 02:33:33,729 [salt.state       :1951][INFO    ][13147] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 02:33:33.729080 duration_in_ms=1094.564
2019-12-02 02:33:33,731 [salt.state       :1780][INFO    ][13147] Running state [maas.process_maas_config] at time 02:33:33.731889
2019-12-02 02:33:33,732 [salt.state       :1813][INFO    ][13147] Executing state module.run for [maas.process_maas_config]
2019-12-02 02:33:33,733 [salt.utils.decorators:613 ][WARNING ][13147] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:33:33,733 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=enable_http_proxy value=True
2019-12-02 02:33:33,802 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=upstream_dns value=8.8.8.8
2019-12-02 02:33:33,866 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=commissioning_distro_series value=xenial
2019-12-02 02:33:36,791 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=default_osystem value=ubuntu
2019-12-02 02:33:36,868 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=active_discovery_interval value=600
2019-12-02 02:33:36,932 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=dnssec_validation value=no
2019-12-02 02:33:36,999 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=maas_name value=mas01
2019-12-02 02:33:37,058 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=network_discovery value=enabled
2019-12-02 02:33:37,184 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=enable_third_party_drivers value=True
2019-12-02 02:33:37,238 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=default_storage_layout value=lvm
2019-12-02 02:33:37,283 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=ntp_external_only value=True
2019-12-02 02:33:37,353 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=disk_erase_with_secure_erase value=False
2019-12-02 02:33:37,412 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=default_distro_series value=xenial
2019-12-02 02:33:37,477 [salt.loaded.ext.module.maas:92  ][INFO    ][13147] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-12-02 02:33:37,609 [salt.state       :300 ][INFO    ][13147] {'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-12-02 02:33:37,610 [salt.state       :1951][INFO    ][13147] Completed state [maas.process_maas_config] at time 02:33:37.610030 duration_in_ms=3878.141
2019-12-02 02:33:37,610 [salt.state       :1780][INFO    ][13147] Running state [pxe_admin] at time 02:33:37.610831
2019-12-02 02:33:37,611 [salt.state       :1813][INFO    ][13147] Executing state maasng.fabric_present for [pxe_admin]
2019-12-02 02:33:37,685 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'fybmmc', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-02 02:33:37,769 [salt.loaded.ext.module.maasng:1008][WARNING ][13147] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-12-02 02:33:37,769 [salt.loaded.ext.module.maasng:1011][WARNING ][13147] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-12-02 02:33:37,840 [salt.state       :300 ][INFO    ][13147] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-12-02 02:33:37,841 [salt.state       :1951][INFO    ][13147] Completed state [pxe_admin] at time 02:33:37.841065 duration_in_ms=230.234
2019-12-02 02:33:37,841 [salt.state       :1780][INFO    ][13147] Running state [vlan 0] at time 02:33:37.841539
2019-12-02 02:33:37,842 [salt.state       :1813][INFO    ][13147] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-02 02:33:37,942 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fybmmc', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-02 02:33:38,097 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fybmmc', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-02 02:33:38,387 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-02 02:33:38,483 [salt.state       :300 ][INFO    ][13147] {'new': 'Vlan untagged was updated'}
2019-12-02 02:33:38,484 [salt.state       :1951][INFO    ][13147] Completed state [vlan 0] at time 02:33:38.484220 duration_in_ms=642.678
2019-12-02 02:33:38,485 [salt.state       :1780][INFO    ][13147] Running state [192.168.11.0/24] at time 02:33:38.485807
2019-12-02 02:33:38,486 [salt.state       :1813][INFO    ][13147] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-12-02 02:33:38,712 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fybmmc', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-02 02:33:38,713 [salt.loaded.ext.module.maasng:1235][WARNING ][13147] Ignoring parameter vlan:0
2019-12-02 02:33:38,808 [salt.state       :300 ][INFO    ][13147] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-12-02 02:33:38,808 [salt.state       :1951][INFO    ][13147] Completed state [192.168.11.0/24] at time 02:33:38.808493 duration_in_ms=322.687
2019-12-02 02:33:38,809 [salt.state       :1780][INFO    ][13147] Running state [maas_create_iprange_1] at time 02:33:38.809618
2019-12-02 02:33:38,810 [salt.state       :1813][INFO    ][13147] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-12-02 02:33:38,864 [salt.state       :300 ][INFO    ][13147] Iprange maas_create_iprange_1 already exist.
2019-12-02 02:33:38,865 [salt.state       :1951][INFO    ][13147] Completed state [maas_create_iprange_1] at time 02:33:38.865046 duration_in_ms=55.427
2019-12-02 02:33:38,865 [salt.state       :1780][INFO    ][13147] Running state [vlan 0] at time 02:33:38.865461
2019-12-02 02:33:38,865 [salt.state       :1813][INFO    ][13147] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-12-02 02:33:38,924 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'fybmmc', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-12-02 02:33:39,285 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fybmmc', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-02 02:33:39,559 [salt.loaded.ext.module.maasng:945 ][INFO    ][13147] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'fybmmc', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-12-02 02:33:39,649 [salt.state       :300 ][INFO    ][13147] {'new': 'Vlan untagged was updated'}
2019-12-02 02:33:39,650 [salt.state       :1951][INFO    ][13147] Completed state [vlan 0] at time 02:33:39.650082 duration_in_ms=784.62
2019-12-02 02:33:39,651 [salt.state       :1780][INFO    ][13147] Running state [opnfv] at time 02:33:39.650982
2019-12-02 02:33:39,651 [salt.state       :1813][INFO    ][13147] Executing state maasng.sshkey_present for [opnfv]
2019-12-02 02:33:39,705 [salt.loaded.ext.module.maasng:1903][INFO    ][13147] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-12-02 02:33:39,705 [salt.state       :300 ][INFO    ][13147] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-12-02 02:33:39,706 [salt.state       :1951][INFO    ][13147] Completed state [opnfv] at time 02:33:39.706165 duration_in_ms=55.181
2019-12-02 02:33:39,711 [salt.minion      :1711][INFO    ][13147] Returning information for job: 20191202023311034436
2019-12-02 02:33:40,281 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202023340273072
2019-12-02 02:33:40,297 [salt.minion      :1432][INFO    ][13600] Starting a new job with PID 13600
2019-12-02 02:33:44,007 [salt.state       :915 ][INFO    ][13600] Loading fresh modules for state activity
2019-12-02 02:33:44,098 [salt.state       :1780][INFO    ][13600] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:33:44.097981
2019-12-02 02:33:44,098 [salt.state       :1813][INFO    ][13600] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:33:44,100 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13600] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:33:45,497 [salt.state       :300 ][INFO    ][13600] {'pid': 13626, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:33:45,498 [salt.state       :1951][INFO    ][13600] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:33:45.498404 duration_in_ms=1400.423
2019-12-02 02:33:45,499 [salt.state       :1780][INFO    ][13600] Running state [maas.process_machines] at time 02:33:45.499705
2019-12-02 02:33:45,500 [salt.state       :1813][INFO    ][13600] Executing state module.run for [maas.process_machines]
2019-12-02 02:33:45,500 [salt.utils.decorators:613 ][WARNING ][13600] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:33:46,057 [salt.loaded.ext.module.maas:412 ][WARNING ][13600] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:33:46,058 [salt.loaded.ext.module.maas:92  ][INFO    ][13600] 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=bq8spq architecture=amd64/generic power_parameters_power_user=admin
2019-12-02 02:33:47,183 [salt.loaded.ext.module.maas:412 ][WARNING ][13600] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:33:47,184 [salt.loaded.ext.module.maas:92  ][INFO    ][13600] 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=q3dpgd architecture=amd64/generic power_parameters_power_user=admin
2019-12-02 02:33:48,399 [salt.loaded.ext.module.maas:412 ][WARNING ][13600] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:33:48,400 [salt.loaded.ext.module.maas:92  ][INFO    ][13600] 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=at386h architecture=amd64/generic power_parameters_power_user=admin
2019-12-02 02:33:49,405 [salt.loaded.ext.module.maas:412 ][WARNING ][13600] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:33:49,406 [salt.loaded.ext.module.maas:92  ][INFO    ][13600] 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=tnfy7m architecture=amd64/generic power_parameters_power_user=admin
2019-12-02 02:33:50,621 [salt.loaded.ext.module.maas:412 ][WARNING ][13600] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-12-02 02:33:50,622 [salt.loaded.ext.module.maas:92  ][INFO    ][13600] 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=7gp3bc architecture=amd64/generic power_parameters_power_user=admin
2019-12-02 02:33:51,825 [salt.state       :300 ][INFO    ][13600] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-02 02:33:51,825 [salt.state       :1951][INFO    ][13600] Completed state [maas.process_machines] at time 02:33:51.825578 duration_in_ms=6325.871
2019-12-02 02:33:51,829 [salt.minion      :1711][INFO    ][13600] Returning information for job: 20191202023340273072
2019-12-02 02:34:25,166 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202023425157280
2019-12-02 02:34:25,190 [salt.minion      :1432][INFO    ][13897] Starting a new job with PID 13897
2019-12-02 02:34:28,930 [salt.state       :915 ][INFO    ][13897] Loading fresh modules for state activity
2019-12-02 02:34:29,011 [salt.state       :1780][INFO    ][13897] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:34:29.011086
2019-12-02 02:34:29,011 [salt.state       :1813][INFO    ][13897] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:34:29,013 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13897] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:34:30,387 [salt.state       :300 ][INFO    ][13897] {'pid': 13906, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:34:30,388 [salt.state       :1951][INFO    ][13897] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:34:30.387981 duration_in_ms=1376.893
2019-12-02 02:34:30,390 [salt.state       :1780][INFO    ][13897] Running state [maas.wait_for_machine_status] at time 02:34:30.390607
2019-12-02 02:34:30,391 [salt.state       :1813][INFO    ][13897] Executing state module.run for [maas.wait_for_machine_status]
2019-12-02 02:34:30,391 [salt.utils.decorators:613 ][WARNING ][13897] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:34:33,027 [salt.loaded.ext.module.maas:993 ][INFO    ][13897] Machine tnfy7m mark broken
2019-12-02 02:34:33,693 [salt.loaded.ext.module.maas:996 ][INFO    ][13897] Machine tnfy7m mark fixed
2019-12-02 02:34:34,860 [salt.loaded.ext.module.maas:684 ][INFO    ][13897] deploymachines hwe_kernel=ga-16.04 system_id=tnfy7m distro_series=xenial
2019-12-02 02:34:38,179 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.22290397s left)
2019-12-02 02:34:40,270 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023440215869
2019-12-02 02:34:40,291 [salt.minion      :1432][INFO    ][13978] Starting a new job with PID 13978
2019-12-02 02:34:40,314 [salt.minion      :1711][INFO    ][13978] Returning information for job: 20191202023440215869
2019-12-02 02:35:10,323 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023510312095
2019-12-02 02:35:10,344 [salt.minion      :1432][INFO    ][14025] Starting a new job with PID 14025
2019-12-02 02:35:10,369 [salt.minion      :1711][INFO    ][14025] Returning information for job: 20191202023510312095
2019-12-02 02:35:11,748 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1458.65377998s left)
2019-12-02 02:35:40,422 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023540409335
2019-12-02 02:35:40,442 [salt.minion      :1432][INFO    ][14058] Starting a new job with PID 14058
2019-12-02 02:35:40,466 [salt.minion      :1711][INFO    ][14058] Returning information for job: 20191202023540409335
2019-12-02 02:35:45,210 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1425.19218898s left)
2019-12-02 02:36:10,467 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023610454032
2019-12-02 02:36:10,490 [salt.minion      :1432][INFO    ][14102] Starting a new job with PID 14102
2019-12-02 02:36:10,516 [salt.minion      :1711][INFO    ][14102] Returning information for job: 20191202023610454032
2019-12-02 02:36:17,782 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.61992097s left)
2019-12-02 02:36:40,519 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023640506885
2019-12-02 02:36:40,541 [salt.minion      :1432][INFO    ][14180] Starting a new job with PID 14180
2019-12-02 02:36:40,568 [salt.minion      :1711][INFO    ][14180] Returning information for job: 20191202023640506885
2019-12-02 02:36:51,326 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.07636905s left)
2019-12-02 02:37:10,574 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023710561239
2019-12-02 02:37:10,596 [salt.minion      :1432][INFO    ][14321] Starting a new job with PID 14321
2019-12-02 02:37:10,623 [salt.minion      :1711][INFO    ][14321] Returning information for job: 20191202023710561239
2019-12-02 02:37:24,902 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.49983501s left)
2019-12-02 02:37:40,632 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023740624913
2019-12-02 02:37:40,652 [salt.minion      :1432][INFO    ][14393] Starting a new job with PID 14393
2019-12-02 02:37:40,676 [salt.minion      :1711][INFO    ][14393] Returning information for job: 20191202023740624913
2019-12-02 02:37:58,614 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1291.78755808s left)
2019-12-02 02:38:10,691 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023810678160
2019-12-02 02:38:10,713 [salt.minion      :1432][INFO    ][14470] Starting a new job with PID 14470
2019-12-02 02:38:10,735 [salt.minion      :1711][INFO    ][14470] Returning information for job: 20191202023810678160
2019-12-02 02:38:32,325 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1258.07657695s left)
2019-12-02 02:38:40,751 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023840737828
2019-12-02 02:38:40,773 [salt.minion      :1432][INFO    ][14510] Starting a new job with PID 14510
2019-12-02 02:38:40,797 [salt.minion      :1711][INFO    ][14510] Returning information for job: 20191202023840737828
2019-12-02 02:39:06,011 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1224.39068604s left)
2019-12-02 02:39:10,822 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023910808675
2019-12-02 02:39:10,844 [salt.minion      :1432][INFO    ][14581] Starting a new job with PID 14581
2019-12-02 02:39:10,871 [salt.minion      :1711][INFO    ][14581] Returning information for job: 20191202023910808675
2019-12-02 02:39:39,599 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1190.80330515s left)
2019-12-02 02:39:40,903 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202023940889825
2019-12-02 02:39:40,925 [salt.minion      :1432][INFO    ][14637] Starting a new job with PID 14637
2019-12-02 02:39:40,950 [salt.minion      :1711][INFO    ][14637] Returning information for job: 20191202023940889825
2019-12-02 02:40:10,978 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024010965882
2019-12-02 02:40:11,000 [salt.minion      :1432][INFO    ][14723] Starting a new job with PID 14723
2019-12-02 02:40:11,027 [salt.minion      :1711][INFO    ][14723] Returning information for job: 20191202024010965882
2019-12-02 02:40:13,076 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1157.32638812s left)
2019-12-02 02:40:41,062 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024041048964
2019-12-02 02:40:41,084 [salt.minion      :1432][INFO    ][14779] Starting a new job with PID 14779
2019-12-02 02:40:41,110 [salt.minion      :1711][INFO    ][14779] Returning information for job: 20191202024041048964
2019-12-02 02:40:46,647 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1123.75445914s left)
2019-12-02 02:41:11,149 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024111136320
2019-12-02 02:41:11,172 [salt.minion      :1432][INFO    ][14893] Starting a new job with PID 14893
2019-12-02 02:41:11,199 [salt.minion      :1711][INFO    ][14893] Returning information for job: 20191202024111136320
2019-12-02 02:41:20,381 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1090.02117109s left)
2019-12-02 02:41:41,251 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024141237803
2019-12-02 02:41:41,273 [salt.minion      :1432][INFO    ][14929] Starting a new job with PID 14929
2019-12-02 02:41:41,299 [salt.minion      :1711][INFO    ][14929] Returning information for job: 20191202024141237803
2019-12-02 02:41:53,494 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1056.9074471s left)
2019-12-02 02:42:11,351 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024211338543
2019-12-02 02:42:11,373 [salt.minion      :1432][INFO    ][14984] Starting a new job with PID 14984
2019-12-02 02:42:11,398 [salt.minion      :1711][INFO    ][14984] Returning information for job: 20191202024211338543
2019-12-02 02:42:26,780 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1023.6223371s left)
2019-12-02 02:42:41,458 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024241443728
2019-12-02 02:42:41,481 [salt.minion      :1432][INFO    ][15018] Starting a new job with PID 15018
2019-12-02 02:42:41,507 [salt.minion      :1711][INFO    ][15018] Returning information for job: 20191202024241443728
2019-12-02 02:43:00,403 [salt.loaded.ext.module.maas:1023][INFO    ][13897] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (989.998708963s left)
2019-12-02 02:43:11,567 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command saltutil.find_job with jid 20191202024311554370
2019-12-02 02:43:11,589 [salt.minion      :1432][INFO    ][15098] Starting a new job with PID 15098
2019-12-02 02:43:11,615 [salt.minion      :1711][INFO    ][15098] Returning information for job: 20191202024311554370
2019-12-02 02:43:33,869 [salt.state       :300 ][INFO    ][13897] {'ret': True}
2019-12-02 02:43:33,870 [salt.state       :1951][INFO    ][13897] Completed state [maas.wait_for_machine_status] at time 02:43:33.869984 duration_in_ms=543479.377
2019-12-02 02:43:33,872 [salt.minion      :1711][INFO    ][13897] Returning information for job: 20191202023425157280
2019-12-02 02:43:34,554 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202024334544935
2019-12-02 02:43:34,576 [salt.minion      :1432][INFO    ][15152] Starting a new job with PID 15152
2019-12-02 02:43:38,204 [salt.state       :915 ][INFO    ][15152] Loading fresh modules for state activity
2019-12-02 02:43:38,342 [salt.state       :1780][INFO    ][15152] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:38.342391
2019-12-02 02:43:38,342 [salt.state       :1813][INFO    ][15152] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:43:38,344 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15152] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:43:39,800 [salt.state       :300 ][INFO    ][15152] {'pid': 15160, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:43:39,801 [salt.state       :1951][INFO    ][15152] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:39.801060 duration_in_ms=1458.67
2019-12-02 02:43:39,802 [salt.state       :1780][INFO    ][15152] Running state [maas_machines_storage_cmp002_lvm] at time 02:43:39.802487
2019-12-02 02:43:39,802 [salt.state       :1813][INFO    ][15152] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-12-02 02:43:40,556 [salt.state       :300 ][INFO    ][15152] Machine cmp002 is not in Ready state.
2019-12-02 02:43:40,557 [salt.state       :1951][INFO    ][15152] Completed state [maas_machines_storage_cmp002_lvm] at time 02:43:40.557179 duration_in_ms=754.697
2019-12-02 02:43:40,557 [salt.state       :1780][INFO    ][15152] Running state [maas_machines_storage_cmp001_lvm] at time 02:43:40.557755
2019-12-02 02:43:40,558 [salt.state       :1813][INFO    ][15152] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-12-02 02:43:41,271 [salt.state       :300 ][INFO    ][15152] Machine cmp001 is not in Ready state.
2019-12-02 02:43:41,271 [salt.state       :1951][INFO    ][15152] Completed state [maas_machines_storage_cmp001_lvm] at time 02:43:41.271587 duration_in_ms=713.832
2019-12-02 02:43:41,274 [salt.minion      :1711][INFO    ][15152] Returning information for job: 20191202024334544935
2019-12-02 02:43:41,912 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202024341899726
2019-12-02 02:43:41,934 [salt.minion      :1432][INFO    ][15171] Starting a new job with PID 15171
2019-12-02 02:43:42,724 [salt.state       :915 ][INFO    ][15171] Loading fresh modules for state activity
2019-12-02 02:43:42,811 [salt.state       :1780][INFO    ][15171] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:42.811842
2019-12-02 02:43:42,812 [salt.state       :1813][INFO    ][15171] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:43:42,814 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15171] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:43:44,154 [salt.state       :300 ][INFO    ][15171] {'pid': 15178, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:43:44,155 [salt.state       :1951][INFO    ][15171] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:44.155379 duration_in_ms=1343.537
2019-12-02 02:43:44,157 [salt.state       :1780][INFO    ][15171] Running state [maas.deploy_machines] at time 02:43:44.157800
2019-12-02 02:43:44,158 [salt.state       :1813][INFO    ][15171] Executing state module.run for [maas.deploy_machines]
2019-12-02 02:43:44,159 [salt.utils.decorators:613 ][WARNING ][15171] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:43:44,663 [salt.state       :300 ][INFO    ][15171] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-12-02 02:43:44,663 [salt.state       :1951][INFO    ][15171] Completed state [maas.deploy_machines] at time 02:43:44.663634 duration_in_ms=505.832
2019-12-02 02:43:44,667 [salt.minion      :1711][INFO    ][15171] Returning information for job: 20191202024341899726
2019-12-02 02:43:45,308 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command state.apply with jid 20191202024345295898
2019-12-02 02:43:45,331 [salt.minion      :1432][INFO    ][15187] Starting a new job with PID 15187
2019-12-02 02:43:46,076 [salt.state       :915 ][INFO    ][15187] Loading fresh modules for state activity
2019-12-02 02:43:46,164 [salt.state       :1780][INFO    ][15187] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:46.164457
2019-12-02 02:43:46,164 [salt.state       :1813][INFO    ][15187] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-12-02 02:43:46,166 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15187] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-12-02 02:43:47,772 [salt.state       :300 ][INFO    ][15187] {'pid': 15194, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-12-02 02:43:47,773 [salt.state       :1951][INFO    ][15187] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:43:47.773482 duration_in_ms=1609.024
2019-12-02 02:43:47,777 [salt.state       :1780][INFO    ][15187] Running state [maas.wait_for_machine_status] at time 02:43:47.776933
2019-12-02 02:43:47,777 [salt.state       :1813][INFO    ][15187] Executing state module.run for [maas.wait_for_machine_status]
2019-12-02 02:43:47,778 [salt.utils.decorators:613 ][WARNING ][15187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-12-02 02:43:51,410 [salt.state       :300 ][INFO    ][15187] {'ret': True}
2019-12-02 02:43:51,411 [salt.state       :1951][INFO    ][15187] Completed state [maas.wait_for_machine_status] at time 02:43:51.410928 duration_in_ms=3633.993
2019-12-02 02:43:51,414 [salt.minion      :1711][INFO    ][15187] Returning information for job: 20191202024345295898
2019-12-02 03:11:30,218 [salt.utils.schedule:1377][INFO    ][6669] Running scheduled job: __mine_interval
2019-12-02 04:11:30,219 [salt.utils.schedule:1377][INFO    ][6669] Running scheduled job: __mine_interval
2019-12-02 04:13:30,062 [salt.minion      :1308][INFO    ][6669] User sudo_ubuntu Executing command cp.push_dir with jid 20191202041330050547
2019-12-02 04:13:30,078 [salt.minion      :1432][INFO    ][21628] Starting a new job with PID 21628
