2019-06-12 02:13:05,413 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-12 02:13:55,448 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-12 02:14:45,488 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-12 02:15:35,531 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-12 02:16:25,578 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-12 02:18:33,465 [salt.utils.decorators:613 ][WARNING ][2716] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:18:34,039 [salt.utils.decorators:613 ][WARNING ][2716] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:18:36,309 [salt.loaded.int.states.file:2298][WARNING ][2871] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-12 02:18:41,934 [salt.state       :2022][WARNING ][2966] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-12 02:18:44,460 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:18:58,424 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:19:34,290 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:19:35,249 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:19:39,028 [salt.loaded.ext.module.maasng:1008][WARNING ][2966] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-12 02:19:39,029 [salt.loaded.ext.module.maasng:1011][WARNING ][2966] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-12 02:19:39,599 [salt.loaded.ext.module.maasng:1235][WARNING ][2966] Ignoring parameter vlan:0
2019-06-12 02:19:46,590 [salt.utils.decorators:613 ][WARNING ][5931] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:19:46,665 [salt.loaded.ext.module.maas:412 ][WARNING ][5931] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:19:48,170 [salt.loaded.ext.module.maas:412 ][WARNING ][5931] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:19:49,384 [salt.loaded.ext.module.maas:412 ][WARNING ][5931] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:19:50,630 [salt.loaded.ext.module.maas:412 ][WARNING ][5931] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:19:51,961 [salt.loaded.ext.module.maas:412 ][WARNING ][5931] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:19:56,676 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6584] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-12 02:19:56,706 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6584] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-12 02:19:56,729 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-06-12 02:19:57,799 [salt.cli.daemons :293 ][INFO    ][6634] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-06-12 02:19:57,892 [salt.cli.daemons :82  ][INFO    ][6634] Starting up the Salt Minion
2019-06-12 02:19:57,893 [salt.utils.event :1017][INFO    ][6634] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-06-12 02:19:58,697 [salt.minion      :976 ][INFO    ][6634] Creating minion process manager
2019-06-12 02:20:00,075 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6634] Executing command ['date', '+%z'] in directory '/root'
2019-06-12 02:20:00,094 [salt.utils.schedule:568 ][INFO    ][6634] Updating job settings for scheduled job: __mine_interval
2019-06-12 02:20:00,095 [salt.minion      :1108][INFO    ][6634] Added mine.update to scheduler
2019-06-12 02:20:00,099 [salt.minion      :1975][INFO    ][6634] Minion is starting as user 'root'
2019-06-12 02:20:00,112 [salt.minion      :2336][INFO    ][6634] Minion is ready to receive requests!
2019-06-12 02:20:24,333 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612022024317589
2019-06-12 02:20:24,355 [salt.minion      :1432][INFO    ][6725] Starting a new job with PID 6725
2019-06-12 02:20:28,087 [salt.state       :915 ][INFO    ][6725] Loading fresh modules for state activity
2019-06-12 02:20:28,139 [salt.fileclient  :1219][INFO    ][6725] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-12 02:20:28,180 [salt.state       :1780][INFO    ][6725] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:20:28.180101
2019-06-12 02:20:28,180 [salt.state       :1813][INFO    ][6725] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:20:28,182 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6725] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:20:29,625 [salt.state       :300 ][INFO    ][6725] {'pid': 6732, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:20:29,625 [salt.state       :1951][INFO    ][6725] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:20:29.625425 duration_in_ms=1445.324
2019-06-12 02:20:29,626 [salt.state       :1780][INFO    ][6725] Running state [maas.wait_for_machine_status] at time 02:20:29.626510
2019-06-12 02:20:29,626 [salt.state       :1813][INFO    ][6725] Executing state module.run for [maas.wait_for_machine_status]
2019-06-12 02:20:29,627 [salt.utils.decorators:613 ][WARNING ][6725] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:20:30,552 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.079072s left)
2019-06-12 02:20:39,369 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022039355318
2019-06-12 02:20:39,392 [salt.minion      :1432][INFO    ][6759] Starting a new job with PID 6759
2019-06-12 02:20:39,416 [salt.minion      :1711][INFO    ][6759] Returning information for job: 20190612022039355318
2019-06-12 02:21:01,561 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.06976199s left)
2019-06-12 02:21:09,415 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022109401851
2019-06-12 02:21:09,438 [salt.minion      :1432][INFO    ][6804] Starting a new job with PID 6804
2019-06-12 02:21:09,461 [salt.minion      :1711][INFO    ][6804] Returning information for job: 20190612022109401851
2019-06-12 02:21:32,850 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.78068995s left)
2019-06-12 02:21:39,520 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022139507246
2019-06-12 02:21:39,541 [salt.minion      :1432][INFO    ][6952] Starting a new job with PID 6952
2019-06-12 02:21:39,562 [salt.minion      :1711][INFO    ][6952] Returning information for job: 20190612022139507246
2019-06-12 02:22:04,249 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.38222289s left)
2019-06-12 02:22:09,571 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022209555340
2019-06-12 02:22:09,594 [salt.minion      :1432][INFO    ][7144] Starting a new job with PID 7144
2019-06-12 02:22:09,617 [salt.minion      :1711][INFO    ][7144] Returning information for job: 20190612022209555340
2019-06-12 02:22:35,753 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.87765789s left)
2019-06-12 02:22:39,628 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022239615518
2019-06-12 02:22:39,651 [salt.minion      :1432][INFO    ][7287] Starting a new job with PID 7287
2019-06-12 02:22:39,673 [salt.minion      :1711][INFO    ][7287] Returning information for job: 20190612022239615518
2019-06-12 02:23:07,587 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.04382896s left)
2019-06-12 02:23:09,686 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022309670643
2019-06-12 02:23:09,708 [salt.minion      :1432][INFO    ][7872] Starting a new job with PID 7872
2019-06-12 02:23:09,731 [salt.minion      :1711][INFO    ][7872] Returning information for job: 20190612022309670643
2019-06-12 02:23:39,749 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022339733480
2019-06-12 02:23:39,772 [salt.minion      :1432][INFO    ][7982] Starting a new job with PID 7982
2019-06-12 02:23:39,796 [salt.minion      :1711][INFO    ][7982] Returning information for job: 20190612022339733480
2019-06-12 02:23:40,318 [salt.loaded.ext.module.maas:1023][INFO    ][6725] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1309.31294394s left)
2019-06-12 02:24:09,818 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022409800957
2019-06-12 02:24:09,839 [salt.minion      :1432][INFO    ][8192] Starting a new job with PID 8192
2019-06-12 02:24:09,862 [salt.minion      :1711][INFO    ][8192] Returning information for job: 20190612022409800957
2019-06-12 02:24:13,665 [salt.state       :300 ][INFO    ][6725] {'ret': True}
2019-06-12 02:24:13,666 [salt.state       :1951][INFO    ][6725] Completed state [maas.wait_for_machine_status] at time 02:24:13.666163 duration_in_ms=224039.651
2019-06-12 02:24:13,670 [salt.minion      :1711][INFO    ][6725] Returning information for job: 20190612022024317589
2019-06-12 02:24:14,310 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612022414298640
2019-06-12 02:24:14,331 [salt.minion      :1432][INFO    ][8205] Starting a new job with PID 8205
2019-06-12 02:24:17,996 [salt.state       :915 ][INFO    ][8205] Loading fresh modules for state activity
2019-06-12 02:24:18,040 [salt.fileclient  :1219][INFO    ][8205] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-12 02:24:18,127 [salt.state       :1780][INFO    ][8205] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:18.127091
2019-06-12 02:24:18,127 [salt.state       :1813][INFO    ][8205] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:24:18,129 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8205] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:24:19,588 [salt.state       :300 ][INFO    ][8205] {'pid': 8212, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:24:19,589 [salt.state       :1951][INFO    ][8205] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:19.589318 duration_in_ms=1462.226
2019-06-12 02:24:19,590 [salt.state       :1780][INFO    ][8205] Running state [maas_machines_storage_cmp002_lvm] at time 02:24:19.590885
2019-06-12 02:24:19,591 [salt.state       :1813][INFO    ][8205] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-12 02:24:20,891 [salt.loaded.ext.module.maasng:610 ][INFO    ][8205] 647nsp
2019-06-12 02:24:20,892 [salt.loaded.ext.module.maasng:626 ][INFO    ][8205] sda
2019-06-12 02:24:21,607 [salt.loaded.ext.module.maasng:361 ][INFO    ][8205] 647nsp
2019-06-12 02:24:21,732 [salt.loaded.ext.module.maasng:367 ][INFO    ][8205] [{u'partition_table_type': u'GPT', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'4b2b42c2-8d55-4233-8bfd-48a60d9f0f96', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/partition/4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'647nsp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'321a2120-6a74-4736-8183-85c5cd90a340', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 4, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/', 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'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'partition_table_type': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'e07aa9d7-2b56-4914-b202-4ceed9e1db31', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/9/', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'fe1106bc-4d04-48f5-8bbd-4905ad554bc6', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 9, u'serial': None, u'size': 2397988454400}]
2019-06-12 02:24:21,733 [salt.loaded.ext.module.maasng:632 ][INFO    ][8205] vgroot
2019-06-12 02:24:21,733 [salt.loaded.ext.module.maasng:635 ][INFO    ][8205] lvroot
2019-06-12 02:24:21,733 [salt.loaded.ext.module.maasng:639 ][INFO    ][8205] 107374182400
2019-06-12 02:24:22,490 [salt.loaded.ext.module.maasng:645 ][INFO    ][8205] {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'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'partition_table_type': u'GPT', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'de10208d-9754-4e67-b778-3017d348ce32', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'647nsp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'adcf0188-0106-4eaa-a137-c09feabe30b6', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/', 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'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'partition_table_type': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'babf05c1-4725-4cf4-8498-4a3df0f7ea97', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/12/', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'54baaa84-6edb-47da-9c1b-a5d05b789b2c', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'size': 107374182400}], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'resource_uri': u'/MAAS/api/2.0/machines/647nsp/', u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'647nsp', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'partition_table_type': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'uuid': u'babf05c1-4725-4cf4-8498-4a3df0f7ea97', u'id': 12, u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/12/', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'54baaa84-6edb-47da-9c1b-a5d05b789b2c', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'647nsp', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 25, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'647nsp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'id': 27, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 13, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'647nsp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/interfaces/13/'}, {u'name': u'enp9s0', u'links': [{u'id': 30, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 16, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'647nsp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/interfaces/16/'}, {u'name': u'enp8s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 20, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'647nsp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'partition_table_type': u'GPT', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'uuid': u'de10208d-9754-4e67-b778-3017d348ce32', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'647nsp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'adcf0188-0106-4eaa-a137-c09feabe30b6', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'id': 2, u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 25, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'647nsp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/interfaces/4/'}, u'ip_addresses': [u'192.168.11.42'], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'partition_table_type': u'GPT', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'uuid': u'de10208d-9754-4e67-b778-3017d348ce32', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'647nsp', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'adcf0188-0106-4eaa-a137-c09feabe30b6', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'id': 2, u'system_id': u'647nsp', u'resource_uri': u'/MAAS/api/2.0/nodes/647nsp/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'size': 2397998940160}}
2019-06-12 02:24:22,492 [salt.state       :300 ][INFO    ][8205] {'new': {'storage_layout': 'lvm'}}
2019-06-12 02:24:22,492 [salt.state       :1951][INFO    ][8205] Completed state [maas_machines_storage_cmp002_lvm] at time 02:24:22.492828 duration_in_ms=2901.941
2019-06-12 02:24:22,493 [salt.state       :1780][INFO    ][8205] Running state [maas_machines_storage_cmp001_lvm] at time 02:24:22.493406
2019-06-12 02:24:22,493 [salt.state       :1813][INFO    ][8205] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-12 02:24:24,061 [salt.loaded.ext.module.maasng:610 ][INFO    ][8205] rcfn6h
2019-06-12 02:24:24,061 [salt.loaded.ext.module.maasng:626 ][INFO    ][8205] sda
2019-06-12 02:24:24,671 [salt.loaded.ext.module.maasng:361 ][INFO    ][8205] rcfn6h
2019-06-12 02:24:24,780 [salt.loaded.ext.module.maasng:367 ][INFO    ][8205] [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/', u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'tags': [u'rotary'], u'id': 4, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'rcfn6h', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'd209c649-d6df-46be-a2d9-1ad029cb80c1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rcfn6h', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'cd2643f3-3d3c-40a0-b00b-e646e6f19473', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/partition/2'}], u'type': u'physical', u'model': u'UCSB-MRAID12G', u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'8299b763-5875-43b9-bea6-d752ef3f3ee3', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/8/', u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'tags': [], u'id': 8, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'rcfn6h', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'09175853-f450-4f1d-ab23-957958349f4c', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'model': None, u'size': 2397988454400}]
2019-06-12 02:24:24,780 [salt.loaded.ext.module.maasng:632 ][INFO    ][8205] vgroot
2019-06-12 02:24:24,780 [salt.loaded.ext.module.maasng:635 ][INFO    ][8205] lvroot
2019-06-12 02:24:24,781 [salt.loaded.ext.module.maasng:639 ][INFO    ][8205] 107374182400
2019-06-12 02:24:25,434 [salt.loaded.ext.module.maasng:645 ][INFO    ][8205] {u'hwe_kernel': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', 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'status_action': u'', u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/rcfn6h/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'rcfn6h', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', 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': 22}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'rcfn6h', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/interfaces/5/'}, u'blockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/', u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'tags': [u'rotary'], u'id': 4, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'rcfn6h', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'6ecad33a-bfdc-4c87-a839-33a4cd0ff93c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rcfn6h', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'78dd66f8-b8d1-4e5f-b7c8-83c76fc4d4e9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/partition/7'}], u'type': u'physical', u'model': u'UCSB-MRAID12G', u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'ce3cc423-3b0b-4c85-9812-3208fec5624b', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/13/', u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'tags': [], u'id': 13, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'rcfn6h', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'c283895d-a827-4ee0-be89-7c175fbf200a', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'model': None, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'rcfn6h', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'id': 4, u'system_id': u'rcfn6h', 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'partitions': [{u'size': 2397992648704, u'uuid': u'6ecad33a-bfdc-4c87-a839-33a4cd0ff93c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rcfn6h', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'78dd66f8-b8d1-4e5f-b7c8-83c76fc4d4e9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/partition/7'}], u'type': u'physical', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/', u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'id': 4, u'system_id': u'rcfn6h', 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'partitions': [{u'size': 2397992648704, u'uuid': u'6ecad33a-bfdc-4c87-a839-33a4cd0ff93c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rcfn6h', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'78dd66f8-b8d1-4e5f-b7c8-83c76fc4d4e9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/partition/7'}], u'type': u'physical', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/4/', u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'uuid': u'ce3cc423-3b0b-4c85-9812-3208fec5624b', u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'c283895d-a827-4ee0-be89-7c175fbf200a', u'fstype': u'ext4', u'label': u'root'}, u'id': 13, u'system_id': u'rcfn6h', 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'partitions': [], u'type': u'virtual', u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/blockdevices/13/', u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', 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': 22}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'rcfn6h', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 23}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'id': 14, u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'rcfn6h', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/interfaces/14/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 24}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'id': 17, u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'rcfn6h', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/interfaces/17/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 28}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'id': 18, u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'rcfn6h', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rcfn6h/interfaces/18/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-06-12 02:24:25,436 [salt.state       :300 ][INFO    ][8205] {'new': {'storage_layout': 'lvm'}}
2019-06-12 02:24:25,436 [salt.state       :1951][INFO    ][8205] Completed state [maas_machines_storage_cmp001_lvm] at time 02:24:25.436529 duration_in_ms=2943.123
2019-06-12 02:24:25,439 [salt.minion      :1711][INFO    ][8205] Returning information for job: 20190612022414298640
2019-06-12 02:24:25,911 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612022425898448
2019-06-12 02:24:25,925 [salt.minion      :1432][INFO    ][8231] Starting a new job with PID 8231
2019-06-12 02:24:26,661 [salt.state       :915 ][INFO    ][8231] Loading fresh modules for state activity
2019-06-12 02:24:26,711 [salt.fileclient  :1219][INFO    ][8231] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-12 02:24:26,755 [salt.state       :1780][INFO    ][8231] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:26.755450
2019-06-12 02:24:26,755 [salt.state       :1813][INFO    ][8231] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:24:26,758 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8231] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:24:28,136 [salt.state       :300 ][INFO    ][8231] {'pid': 8238, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:24:28,137 [salt.state       :1951][INFO    ][8231] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:28.137183 duration_in_ms=1381.733
2019-06-12 02:24:28,139 [salt.state       :1780][INFO    ][8231] Running state [maas.deploy_machines] at time 02:24:28.139782
2019-06-12 02:24:28,140 [salt.state       :1813][INFO    ][8231] Executing state module.run for [maas.deploy_machines]
2019-06-12 02:24:28,141 [salt.utils.decorators:613 ][WARNING ][8231] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:24:28,793 [salt.loaded.ext.module.maas:684 ][INFO    ][8231] deploymachines hwe_kernel=ga-16.04 system_id=647nsp distro_series=xenial
2019-06-12 02:24:31,444 [salt.loaded.ext.module.maas:684 ][INFO    ][8231] deploymachines hwe_kernel=ga-16.04 system_id=rcfn6h distro_series=xenial
2019-06-12 02:24:34,115 [salt.loaded.ext.module.maas:684 ][INFO    ][8231] deploymachines hwe_kernel=ga-16.04 system_id=83fmkt distro_series=xenial
2019-06-12 02:24:36,407 [salt.loaded.ext.module.maas:684 ][INFO    ][8231] deploymachines hwe_kernel=ga-16.04 system_id=kt7pge distro_series=xenial
2019-06-12 02:24:38,924 [salt.loaded.ext.module.maas:684 ][INFO    ][8231] deploymachines hwe_kernel=ga-16.04 system_id=744pr7 distro_series=xenial
2019-06-12 02:24:40,933 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022440920273
2019-06-12 02:24:40,955 [salt.minion      :1432][INFO    ][8517] Starting a new job with PID 8517
2019-06-12 02:24:40,977 [salt.minion      :1711][INFO    ][8517] Returning information for job: 20190612022440920273
2019-06-12 02:24:41,320 [salt.state       :300 ][INFO    ][8231] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-12 02:24:41,321 [salt.state       :1951][INFO    ][8231] Completed state [maas.deploy_machines] at time 02:24:41.321075 duration_in_ms=13181.292
2019-06-12 02:24:41,325 [salt.minion      :1711][INFO    ][8231] Returning information for job: 20190612022425898448
2019-06-12 02:24:41,968 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612022441954551
2019-06-12 02:24:41,990 [salt.minion      :1432][INFO    ][8531] Starting a new job with PID 8531
2019-06-12 02:24:45,713 [salt.state       :915 ][INFO    ][8531] Loading fresh modules for state activity
2019-06-12 02:24:45,756 [salt.fileclient  :1219][INFO    ][8531] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-12 02:24:45,791 [salt.state       :1780][INFO    ][8531] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:45.791594
2019-06-12 02:24:45,791 [salt.state       :1813][INFO    ][8531] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:24:45,793 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8531] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:24:47,252 [salt.state       :300 ][INFO    ][8531] {'pid': 8576, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:24:47,253 [salt.state       :1951][INFO    ][8531] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:24:47.253370 duration_in_ms=1461.776
2019-06-12 02:24:47,256 [salt.state       :1780][INFO    ][8531] Running state [maas.wait_for_machine_status] at time 02:24:47.256496
2019-06-12 02:24:47,257 [salt.state       :1813][INFO    ][8531] Executing state module.run for [maas.wait_for_machine_status]
2019-06-12 02:24:47,257 [salt.utils.decorators:613 ][WARNING ][8531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:24:50,684 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.58347797s left)
2019-06-12 02:24:56,995 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022456983835
2019-06-12 02:24:57,019 [salt.minion      :1432][INFO    ][8589] Starting a new job with PID 8589
2019-06-12 02:24:57,043 [salt.minion      :1711][INFO    ][8589] Returning information for job: 20190612022456983835
2019-06-12 02:25:24,205 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.06253195s left)
2019-06-12 02:25:27,049 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022527037167
2019-06-12 02:25:27,072 [salt.minion      :1432][INFO    ][8609] Starting a new job with PID 8609
2019-06-12 02:25:27,095 [salt.minion      :1711][INFO    ][8609] Returning information for job: 20190612022527037167
2019-06-12 02:25:57,148 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022557136345
2019-06-12 02:25:57,170 [salt.minion      :1432][INFO    ][8666] Starting a new job with PID 8666
2019-06-12 02:25:57,194 [salt.minion      :1711][INFO    ][8666] Returning information for job: 20190612022557136345
2019-06-12 02:25:57,853 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.41467094s left)
2019-06-12 02:26:27,189 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022627182578
2019-06-12 02:26:27,207 [salt.minion      :1432][INFO    ][8779] Starting a new job with PID 8779
2019-06-12 02:26:27,222 [salt.minion      :1711][INFO    ][8779] Returning information for job: 20190612022627182578
2019-06-12 02:26:30,631 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.63695693s left)
2019-06-12 02:26:57,231 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022657219694
2019-06-12 02:26:57,254 [salt.minion      :1432][INFO    ][9300] Starting a new job with PID 9300
2019-06-12 02:26:57,276 [salt.minion      :1711][INFO    ][9300] Returning information for job: 20190612022657219694
2019-06-12 02:27:04,189 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.07899213s left)
2019-06-12 02:27:27,286 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022727271694
2019-06-12 02:27:27,309 [salt.minion      :1432][INFO    ][9351] Starting a new job with PID 9351
2019-06-12 02:27:27,334 [salt.minion      :1711][INFO    ][9351] Returning information for job: 20190612022727271694
2019-06-12 02:27:37,705 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.56270409s left)
2019-06-12 02:27:57,345 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022757330423
2019-06-12 02:27:57,367 [salt.minion      :1432][INFO    ][9873] Starting a new job with PID 9873
2019-06-12 02:27:57,391 [salt.minion      :1711][INFO    ][9873] Returning information for job: 20190612022757330423
2019-06-12 02:28:11,242 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.02537203s left)
2019-06-12 02:28:27,405 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022827392404
2019-06-12 02:28:27,428 [salt.minion      :1432][INFO    ][9893] Starting a new job with PID 9893
2019-06-12 02:28:27,450 [salt.minion      :1711][INFO    ][9893] Returning information for job: 20190612022827392404
2019-06-12 02:28:44,393 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.87513614s left)
2019-06-12 02:28:57,474 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022857457825
2019-06-12 02:28:57,496 [salt.minion      :1432][INFO    ][9992] Starting a new job with PID 9992
2019-06-12 02:28:57,521 [salt.minion      :1711][INFO    ][9992] Returning information for job: 20190612022857457825
2019-06-12 02:29:17,587 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.68068004s left)
2019-06-12 02:29:27,542 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022927529773
2019-06-12 02:29:27,565 [salt.minion      :1432][INFO    ][10029] Starting a new job with PID 10029
2019-06-12 02:29:27,587 [salt.minion      :1711][INFO    ][10029] Returning information for job: 20190612022927529773
2019-06-12 02:29:50,557 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.71031594s left)
2019-06-12 02:29:57,610 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612022957597333
2019-06-12 02:29:57,632 [salt.minion      :1432][INFO    ][10320] Starting a new job with PID 10320
2019-06-12 02:29:57,656 [salt.minion      :1711][INFO    ][10320] Returning information for job: 20190612022957597333
2019-06-12 02:30:23,995 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.27289295s left)
2019-06-12 02:30:27,689 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023027677035
2019-06-12 02:30:27,712 [salt.minion      :1432][INFO    ][10340] Starting a new job with PID 10340
2019-06-12 02:30:27,736 [salt.minion      :1711][INFO    ][10340] Returning information for job: 20190612023027677035
2019-06-12 02:30:57,673 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.59447813s left)
2019-06-12 02:30:57,772 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023057759114
2019-06-12 02:30:57,794 [salt.minion      :1432][INFO    ][10651] Starting a new job with PID 10651
2019-06-12 02:30:57,819 [salt.minion      :1711][INFO    ][10651] Returning information for job: 20190612023057759114
2019-06-12 02:31:27,858 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023127845052
2019-06-12 02:31:27,879 [salt.minion      :1432][INFO    ][10668] Starting a new job with PID 10668
2019-06-12 02:31:27,903 [salt.minion      :1711][INFO    ][10668] Returning information for job: 20190612023127845052
2019-06-12 02:31:31,050 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.21736002s left)
2019-06-12 02:31:57,952 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023157939444
2019-06-12 02:31:57,974 [salt.minion      :1432][INFO    ][11109] Starting a new job with PID 11109
2019-06-12 02:31:57,997 [salt.minion      :1711][INFO    ][11109] Returning information for job: 20190612023157939444
2019-06-12 02:32:04,720 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.54816008s left)
2019-06-12 02:32:28,053 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023228040874
2019-06-12 02:32:28,076 [salt.minion      :1432][INFO    ][11128] Starting a new job with PID 11128
2019-06-12 02:32:28,100 [salt.minion      :1711][INFO    ][11128] Returning information for job: 20190612023228040874
2019-06-12 02:32:38,244 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1779.02416301s left)
2019-06-12 02:32:58,157 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023258144744
2019-06-12 02:32:58,177 [salt.minion      :1432][INFO    ][11262] Starting a new job with PID 11262
2019-06-12 02:32:58,200 [salt.minion      :1711][INFO    ][11262] Returning information for job: 20190612023258144744
2019-06-12 02:33:11,777 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1745.49032211s left)
2019-06-12 02:33:28,269 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023328256725
2019-06-12 02:33:28,293 [salt.minion      :1432][INFO    ][11327] Starting a new job with PID 11327
2019-06-12 02:33:28,317 [salt.minion      :1711][INFO    ][11327] Returning information for job: 20190612023328256725
2019-06-12 02:33:44,831 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1712.43670511s left)
2019-06-12 02:33:58,339 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023358323767
2019-06-12 02:33:58,362 [salt.minion      :1432][INFO    ][11597] Starting a new job with PID 11597
2019-06-12 02:33:58,386 [salt.minion      :1711][INFO    ][11597] Returning information for job: 20190612023358323767
2019-06-12 02:34:18,412 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1678.85550499s left)
2019-06-12 02:34:28,445 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023428433333
2019-06-12 02:34:28,466 [salt.minion      :1432][INFO    ][11675] Starting a new job with PID 11675
2019-06-12 02:34:28,488 [salt.minion      :1711][INFO    ][11675] Returning information for job: 20190612023428433333
2019-06-12 02:34:51,570 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1645.69802713s left)
2019-06-12 02:34:58,583 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023458570280
2019-06-12 02:34:58,606 [salt.minion      :1432][INFO    ][12062] Starting a new job with PID 12062
2019-06-12 02:34:58,630 [salt.minion      :1711][INFO    ][12062] Returning information for job: 20190612023458570280
2019-06-12 02:35:25,013 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1612.25438809s left)
2019-06-12 02:35:28,725 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023528712157
2019-06-12 02:35:28,750 [salt.minion      :1432][INFO    ][12080] Starting a new job with PID 12080
2019-06-12 02:35:28,775 [salt.minion      :1711][INFO    ][12080] Returning information for job: 20190612023528712157
2019-06-12 02:35:58,578 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.68960309s left)
2019-06-12 02:35:58,888 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023558875700
2019-06-12 02:35:58,912 [salt.minion      :1432][INFO    ][12134] Starting a new job with PID 12134
2019-06-12 02:35:58,934 [salt.minion      :1711][INFO    ][12134] Returning information for job: 20190612023558875700
2019-06-12 02:36:29,050 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023629036471
2019-06-12 02:36:29,068 [salt.minion      :1432][INFO    ][12151] Starting a new job with PID 12151
2019-06-12 02:36:29,092 [salt.minion      :1711][INFO    ][12151] Returning information for job: 20190612023629036471
2019-06-12 02:36:31,986 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1545.28288794s left)
2019-06-12 02:36:59,216 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023659203321
2019-06-12 02:36:59,238 [salt.minion      :1432][INFO    ][12209] Starting a new job with PID 12209
2019-06-12 02:36:59,262 [salt.minion      :1711][INFO    ][12209] Returning information for job: 20190612023659203321
2019-06-12 02:37:05,452 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1511.81581306s left)
2019-06-12 02:37:29,395 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023729381107
2019-06-12 02:37:29,417 [salt.minion      :1432][INFO    ][12230] Starting a new job with PID 12230
2019-06-12 02:37:29,441 [salt.minion      :1711][INFO    ][12230] Returning information for job: 20190612023729381107
2019-06-12 02:37:38,811 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1478.45673609s left)
2019-06-12 02:37:59,588 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023759575694
2019-06-12 02:37:59,610 [salt.minion      :1432][INFO    ][12287] Starting a new job with PID 12287
2019-06-12 02:37:59,633 [salt.minion      :1711][INFO    ][12287] Returning information for job: 20190612023759575694
2019-06-12 02:38:12,069 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1445.19905591s left)
2019-06-12 02:38:29,787 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023829774806
2019-06-12 02:38:29,810 [salt.minion      :1432][INFO    ][12314] Starting a new job with PID 12314
2019-06-12 02:38:29,834 [salt.minion      :1711][INFO    ][12314] Returning information for job: 20190612023829774806
2019-06-12 02:38:45,353 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1411.91474295s left)
2019-06-12 02:39:00,012 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023859998869
2019-06-12 02:39:00,034 [salt.minion      :1432][INFO    ][12522] Starting a new job with PID 12522
2019-06-12 02:39:00,057 [salt.minion      :1711][INFO    ][12522] Returning information for job: 20190612023859998869
2019-06-12 02:39:18,876 [salt.loaded.ext.module.maas:1023][INFO    ][8531] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1378.39205194s left)
2019-06-12 02:39:30,232 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612023930219807
2019-06-12 02:39:30,254 [salt.minion      :1432][INFO    ][12550] Starting a new job with PID 12550
2019-06-12 02:39:30,278 [salt.minion      :1711][INFO    ][12550] Returning information for job: 20190612023930219807
2019-06-12 02:39:51,747 [salt.loaded.ext.module.maas:993 ][INFO    ][8531] Machine kt7pge mark broken
2019-06-12 02:39:52,602 [salt.loaded.ext.module.maas:996 ][INFO    ][8531] Machine kt7pge mark fixed
2019-06-12 02:39:53,810 [salt.loaded.ext.module.maas:684 ][INFO    ][8531] deploymachines hwe_kernel=ga-16.04 system_id=kt7pge distro_series=xenial
2019-06-12 02:39:56,425 [salt.loaded.ext.module.maas:160 ][ERROR   ][8531] 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-06-12 02:39:56,427 [salt.state       :302 ][ERROR   ][8531] 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-06-12 02:39:56,428 [salt.state       :1951][INFO    ][8531] Completed state [maas.wait_for_machine_status] at time 02:39:56.427998 duration_in_ms=909171.516
2019-06-12 02:39:56,438 [salt.minion      :1711][INFO    ][8531] Returning information for job: 20190612022441954551
2019-06-12 02:40:07,244 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command pillar.get with jid 20190612024007231414
2019-06-12 02:40:07,267 [salt.minion      :1432][INFO    ][12676] Starting a new job with PID 12676
2019-06-12 02:40:07,275 [salt.minion      :1711][INFO    ][12676] Returning information for job: 20190612024007231414
2019-06-12 02:40:07,874 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command service.status with jid 20190612024007861653
2019-06-12 02:40:07,896 [salt.minion      :1432][INFO    ][12687] Starting a new job with PID 12687
2019-06-12 02:40:08,286 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12687] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:08,319 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12687] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-12 02:40:08,335 [salt.minion      :1711][INFO    ][12687] Returning information for job: 20190612024007861653
2019-06-12 02:40:08,834 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612024008827057
2019-06-12 02:40:08,853 [salt.minion      :1432][INFO    ][12699] Starting a new job with PID 12699
2019-06-12 02:40:12,570 [salt.state       :915 ][INFO    ][12699] Loading fresh modules for state activity
2019-06-12 02:40:13,004 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'salt-minion --version' in directory '/root'
2019-06-12 02:40:13,321 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'salt-minion --version' in directory '/root'
2019-06-12 02:40:14,157 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'salt-minion --version' in directory '/root'
2019-06-12 02:40:14,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'salt-minion --version' in directory '/root'
2019-06-12 02:40:15,822 [salt.state       :1780][INFO    ][12699] Running state [salt-minion] at time 02:40:15.822408
2019-06-12 02:40:15,822 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [salt-minion]
2019-06-12 02:40:15,823 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-12 02:40:15,914 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:15,915 [salt.state       :1951][INFO    ][12699] Completed state [salt-minion] at time 02:40:15.915174 duration_in_ms=92.766
2019-06-12 02:40:15,915 [salt.state       :1780][INFO    ][12699] Running state [salt_minion_dependency_packages] at time 02:40:15.915568
2019-06-12 02:40:15,915 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-12 02:40:15,923 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:15,923 [salt.state       :1951][INFO    ][12699] Completed state [salt_minion_dependency_packages] at time 02:40:15.923254 duration_in_ms=7.686
2019-06-12 02:40:15,926 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/minion.d/minion.conf] at time 02:40:15.926618
2019-06-12 02:40:15,926 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-12 02:40:16,123 [salt.state       :300 ][INFO    ][12699] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-12 02:40:16,123 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/minion.d/minion.conf] at time 02:40:16.123473 duration_in_ms=196.855
2019-06-12 02:40:16,123 [salt.state       :1780][INFO    ][12699] Running state [python-netaddr] at time 02:40:16.123700
2019-06-12 02:40:16,123 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [python-netaddr]
2019-06-12 02:40:16,130 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:16,130 [salt.state       :1951][INFO    ][12699] Completed state [python-netaddr] at time 02:40:16.130639 duration_in_ms=6.937
2019-06-12 02:40:16,133 [salt.state       :1780][INFO    ][12699] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:40:16.133520
2019-06-12 02:40:16,133 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-12 02:40:16,142 [salt.state       :300 ][INFO    ][12699] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-12 02:40:16,143 [salt.state       :1951][INFO    ][12699] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 02:40:16.143172 duration_in_ms=9.651
2019-06-12 02:40:16,143 [salt.state       :1780][INFO    ][12699] Running state [salt-minion] at time 02:40:16.143950
2019-06-12 02:40:16,144 [salt.state       :1813][INFO    ][12699] Executing state service.running for [salt-minion]
2019-06-12 02:40:16,144 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:16,179 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-12 02:40:16,195 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-12 02:40:16,211 [salt.state       :300 ][INFO    ][12699] The service salt-minion is already running
2019-06-12 02:40:16,211 [salt.state       :1951][INFO    ][12699] Completed state [salt-minion] at time 02:40:16.211605 duration_in_ms=67.654
2019-06-12 02:40:16,212 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains.d] at time 02:40:16.212854
2019-06-12 02:40:16,213 [salt.state       :1813][INFO    ][12699] Executing state file.directory for [/etc/salt/grains.d]
2019-06-12 02:40:16,214 [salt.state       :300 ][INFO    ][12699] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-12 02:40:16,214 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains.d] at time 02:40:16.214181 duration_in_ms=1.327
2019-06-12 02:40:16,214 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains] at time 02:40:16.214808
2019-06-12 02:40:16,215 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/grains]
2019-06-12 02:40:16,215 [salt.state       :300 ][INFO    ][12699] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-12 02:40:16,215 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains] at time 02:40:16.215791 duration_in_ms=0.983
2019-06-12 02:40:16,216 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains.d/placeholder] at time 02:40:16.216190
2019-06-12 02:40:16,216 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-12 02:40:16,216 [salt.state       :300 ][INFO    ][12699] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-12 02:40:16,217 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains.d/placeholder] at time 02:40:16.217129 duration_in_ms=0.939
2019-06-12 02:40:16,217 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains.d/sphinx] at time 02:40:16.217545
2019-06-12 02:40:16,217 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-12 02:40:16,231 [salt.state       :300 ][INFO    ][12699] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-12 02:40:16,231 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains.d/sphinx] at time 02:40:16.231218 duration_in_ms=13.672
2019-06-12 02:40:16,232 [salt.state       :1780][INFO    ][12699] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.232931
2019-06-12 02:40:16,233 [salt.state       :1813][INFO    ][12699] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-12 02:40:16,233 [salt.state       :300 ][INFO    ][12699] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-12 02:40:16,233 [salt.state       :1951][INFO    ][12699] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.233644 duration_in_ms=0.714
2019-06-12 02:40:16,234 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains.d/dns_records] at time 02:40:16.234023
2019-06-12 02:40:16,234 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-12 02:40:16,248 [salt.state       :300 ][INFO    ][12699] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-12 02:40:16,249 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains.d/dns_records] at time 02:40:16.249056 duration_in_ms=15.032
2019-06-12 02:40:16,249 [salt.state       :1780][INFO    ][12699] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.249787
2019-06-12 02:40:16,250 [salt.state       :1813][INFO    ][12699] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-12 02:40:16,250 [salt.state       :300 ][INFO    ][12699] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-12 02:40:16,250 [salt.state       :1951][INFO    ][12699] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.250524 duration_in_ms=0.737
2019-06-12 02:40:16,250 [salt.state       :1780][INFO    ][12699] Running state [/etc/salt/grains.d/salt] at time 02:40:16.250911
2019-06-12 02:40:16,251 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-12 02:40:16,266 [salt.state       :300 ][INFO    ][12699] File /etc/salt/grains.d/salt is in the correct state
2019-06-12 02:40:16,267 [salt.state       :1951][INFO    ][12699] Completed state [/etc/salt/grains.d/salt] at time 02:40:16.267074 duration_in_ms=16.163
2019-06-12 02:40:16,267 [salt.state       :1780][INFO    ][12699] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.267776
2019-06-12 02:40:16,268 [salt.state       :1813][INFO    ][12699] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-12 02:40:16,268 [salt.state       :300 ][INFO    ][12699] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-12 02:40:16,268 [salt.state       :1951][INFO    ][12699] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 02:40:16.268516 duration_in_ms=0.74
2019-06-12 02:40:16,269 [salt.state       :1780][INFO    ][12699] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:40:16.269854
2019-06-12 02:40:16,270 [salt.state       :1813][INFO    ][12699] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-12 02:40:16,270 [salt.state       :300 ][INFO    ][12699] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-12 02:40:16,270 [salt.state       :1951][INFO    ][12699] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 02:40:16.270612 duration_in_ms=0.758
2019-06-12 02:40:16,271 [salt.state       :1780][INFO    ][12699] Running state [mine.update] at time 02:40:16.271128
2019-06-12 02:40:16,271 [salt.state       :1813][INFO    ][12699] Executing state module.wait for [mine.update]
2019-06-12 02:40:16,271 [salt.state       :300 ][INFO    ][12699] No changes made for mine.update
2019-06-12 02:40:16,271 [salt.state       :1951][INFO    ][12699] Completed state [mine.update] at time 02:40:16.271839 duration_in_ms=0.712
2019-06-12 02:40:16,272 [salt.state       :1780][INFO    ][12699] Running state [ca-certificates] at time 02:40:16.272055
2019-06-12 02:40:16,272 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [ca-certificates]
2019-06-12 02:40:16,277 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:16,277 [salt.state       :1951][INFO    ][12699] Completed state [ca-certificates] at time 02:40:16.277733 duration_in_ms=5.677
2019-06-12 02:40:16,278 [salt.state       :1780][INFO    ][12699] Running state [update-ca-certificates] at time 02:40:16.278275
2019-06-12 02:40:16,278 [salt.state       :1813][INFO    ][12699] Executing state cmd.wait for [update-ca-certificates]
2019-06-12 02:40:16,278 [salt.state       :300 ][INFO    ][12699] No changes made for update-ca-certificates
2019-06-12 02:40:16,279 [salt.state       :1951][INFO    ][12699] Completed state [update-ca-certificates] at time 02:40:16.278990 duration_in_ms=0.716
2019-06-12 02:40:16,279 [salt.state       :1780][INFO    ][12699] Running state [iptables] at time 02:40:16.279204
2019-06-12 02:40:16,279 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [iptables]
2019-06-12 02:40:16,284 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:16,284 [salt.state       :1951][INFO    ][12699] Completed state [iptables] at time 02:40:16.284339 duration_in_ms=5.135
2019-06-12 02:40:16,284 [salt.state       :1780][INFO    ][12699] Running state [iptables-persistent] at time 02:40:16.284565
2019-06-12 02:40:16,284 [salt.state       :1813][INFO    ][12699] Executing state pkg.installed for [iptables-persistent]
2019-06-12 02:40:16,289 [salt.state       :300 ][INFO    ][12699] All specified packages are already installed
2019-06-12 02:40:16,289 [salt.state       :1951][INFO    ][12699] Completed state [iptables-persistent] at time 02:40:16.289703 duration_in_ms=5.138
2019-06-12 02:40:16,290 [salt.state       :1780][INFO    ][12699] Running state [iptables_modules_v4_load] at time 02:40:16.290504
2019-06-12 02:40:16,290 [salt.state       :1813][INFO    ][12699] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-12 02:40:16,291 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'lsmod' in directory '/root'
2019-06-12 02:40:16,311 [salt.state       :300 ][INFO    ][12699] Kernel modules iptable_filter, ip_tables are already present
2019-06-12 02:40:16,311 [salt.state       :1951][INFO    ][12699] Completed state [iptables_modules_v4_load] at time 02:40:16.311842 duration_in_ms=21.338
2019-06-12 02:40:16,312 [salt.state       :1780][INFO    ][12699] Running state [/etc/iptables/rules.v4] at time 02:40:16.312328
2019-06-12 02:40:16,312 [salt.state       :1813][INFO    ][12699] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-12 02:40:16,386 [salt.state       :300 ][INFO    ][12699] File /etc/iptables/rules.v4 is in the correct state
2019-06-12 02:40:16,387 [salt.state       :1951][INFO    ][12699] Completed state [/etc/iptables/rules.v4] at time 02:40:16.387151 duration_in_ms=74.822
2019-06-12 02:40:16,387 [salt.state       :1780][INFO    ][12699] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:40:16.387947
2019-06-12 02:40:16,388 [salt.state       :1813][INFO    ][12699] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-12 02:40:16,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-12 02:40:16,407 [salt.state       :300 ][INFO    ][12699] onlyif execution failed
2019-06-12 02:40:16,407 [salt.state       :1951][INFO    ][12699] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 02:40:16.407821 duration_in_ms=19.874
2019-06-12 02:40:16,408 [salt.state       :1780][INFO    ][12699] Running state [netfilter-persistent] at time 02:40:16.408538
2019-06-12 02:40:16,408 [salt.state       :1813][INFO    ][12699] Executing state service.running for [netfilter-persistent]
2019-06-12 02:40:16,409 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:16,427 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-12 02:40:16,444 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-12 02:40:16,460 [salt.state       :300 ][INFO    ][12699] The service netfilter-persistent is already running
2019-06-12 02:40:16,460 [salt.state       :1951][INFO    ][12699] Completed state [netfilter-persistent] at time 02:40:16.460415 duration_in_ms=51.877
2019-06-12 02:40:16,461 [salt.state       :1780][INFO    ][12699] Running state [iptables_extra.remove_stale_tables] at time 02:40:16.461141
2019-06-12 02:40:16,461 [salt.state       :1813][INFO    ][12699] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-12 02:40:16,461 [salt.state       :300 ][INFO    ][12699] No changes made for iptables_extra.remove_stale_tables
2019-06-12 02:40:16,462 [salt.state       :1951][INFO    ][12699] Completed state [iptables_extra.remove_stale_tables] at time 02:40:16.462013 duration_in_ms=0.872
2019-06-12 02:40:16,462 [salt.state       :1780][INFO    ][12699] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:40:16.462258
2019-06-12 02:40:16,462 [salt.state       :1813][INFO    ][12699] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-12 02:40:16,463 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-12 02:40:16,476 [salt.state       :300 ][INFO    ][12699] onlyif execution failed
2019-06-12 02:40:16,476 [salt.state       :1951][INFO    ][12699] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 02:40:16.476798 duration_in_ms=14.54
2019-06-12 02:40:16,477 [salt.state       :1780][INFO    ][12699] Running state [/etc/iptables/rules.v6] at time 02:40:16.477548
2019-06-12 02:40:16,477 [salt.state       :1813][INFO    ][12699] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-12 02:40:16,478 [salt.state       :300 ][INFO    ][12699] File /etc/iptables/rules.v6 is not present
2019-06-12 02:40:16,478 [salt.state       :1951][INFO    ][12699] Completed state [/etc/iptables/rules.v6] at time 02:40:16.478427 duration_in_ms=0.879
2019-06-12 02:40:16,479 [salt.state       :1780][INFO    ][12699] Running state [iptables_extra.flush_all] at time 02:40:16.478977
2019-06-12 02:40:16,479 [salt.state       :1813][INFO    ][12699] Executing state module.wait for [iptables_extra.flush_all]
2019-06-12 02:40:16,479 [salt.state       :300 ][INFO    ][12699] No changes made for iptables_extra.flush_all
2019-06-12 02:40:16,479 [salt.state       :1951][INFO    ][12699] Completed state [iptables_extra.flush_all] at time 02:40:16.479679 duration_in_ms=0.702
2019-06-12 02:40:16,482 [salt.minion      :1711][INFO    ][12699] Returning information for job: 20190612024008827057
2019-06-12 02:40:17,084 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612024017072032
2019-06-12 02:40:17,105 [salt.minion      :1432][INFO    ][12774] Starting a new job with PID 12774
2019-06-12 02:40:17,906 [salt.state       :915 ][INFO    ][12774] Loading fresh modules for state activity
2019-06-12 02:40:18,583 [salt.state       :1780][INFO    ][12774] Running state [maas-rack-controller] at time 02:40:18.583267
2019-06-12 02:40:18,583 [salt.state       :1813][INFO    ][12774] Executing state pkg.installed for [maas-rack-controller]
2019-06-12 02:40:18,584 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12774] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-12 02:40:18,663 [salt.state       :300 ][INFO    ][12774] All specified packages are already installed
2019-06-12 02:40:18,664 [salt.state       :1951][INFO    ][12774] Completed state [maas-rack-controller] at time 02:40:18.663939 duration_in_ms=80.672
2019-06-12 02:40:18,664 [salt.state       :1780][INFO    ][12774] Running state [ipmitool] at time 02:40:18.664203
2019-06-12 02:40:18,664 [salt.state       :1813][INFO    ][12774] Executing state pkg.installed for [ipmitool]
2019-06-12 02:40:18,669 [salt.state       :300 ][INFO    ][12774] All specified packages are already installed
2019-06-12 02:40:18,669 [salt.state       :1951][INFO    ][12774] Completed state [ipmitool] at time 02:40:18.669360 duration_in_ms=5.158
2019-06-12 02:40:18,671 [salt.state       :1780][INFO    ][12774] Running state [/etc/maas/rackd.conf] at time 02:40:18.671866
2019-06-12 02:40:18,672 [salt.state       :1813][INFO    ][12774] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-12 02:40:18,672 [salt.state       :300 ][INFO    ][12774] No changes needed to be made
2019-06-12 02:40:18,673 [salt.state       :1951][INFO    ][12774] Completed state [/etc/maas/rackd.conf] at time 02:40:18.673053 duration_in_ms=1.188
2019-06-12 02:40:18,673 [salt.state       :1780][INFO    ][12774] Running state [/etc/maas/rackd.conf] at time 02:40:18.673227
2019-06-12 02:40:18,673 [salt.state       :1813][INFO    ][12774] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-12 02:40:18,673 [salt.loaded.int.states.file:2298][WARNING ][12774] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-06-12 02:40:18,674 [salt.state       :300 ][INFO    ][12774] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-12 02:40:18,674 [salt.state       :1951][INFO    ][12774] Completed state [/etc/maas/rackd.conf] at time 02:40:18.674175 duration_in_ms=0.948
2019-06-12 02:40:18,674 [salt.state       :1780][INFO    ][12774] Running state [maas-rackd] at time 02:40:18.674885
2019-06-12 02:40:18,675 [salt.state       :1813][INFO    ][12774] Executing state service.running for [maas-rackd]
2019-06-12 02:40:18,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12774] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:18,707 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12774] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-12 02:40:18,723 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12774] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-12 02:40:18,737 [salt.state       :300 ][INFO    ][12774] The service maas-rackd is already running
2019-06-12 02:40:18,738 [salt.state       :1951][INFO    ][12774] Completed state [maas-rackd] at time 02:40:18.738009 duration_in_ms=63.124
2019-06-12 02:40:18,739 [salt.minion      :1711][INFO    ][12774] Returning information for job: 20190612024017072032
2019-06-12 02:40:19,227 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612024019215133
2019-06-12 02:40:19,249 [salt.minion      :1432][INFO    ][12797] Starting a new job with PID 12797
2019-06-12 02:40:20,040 [salt.state       :915 ][INFO    ][12797] Loading fresh modules for state activity
2019-06-12 02:40:20,779 [salt.state       :1780][INFO    ][12797] Running state [maas-region-controller] at time 02:40:20.779211
2019-06-12 02:40:20,779 [salt.state       :1813][INFO    ][12797] Executing state pkg.installed for [maas-region-controller]
2019-06-12 02:40:20,780 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-12 02:40:20,855 [salt.state       :300 ][INFO    ][12797] All specified packages are already installed
2019-06-12 02:40:20,855 [salt.state       :1951][INFO    ][12797] Completed state [maas-region-controller] at time 02:40:20.855261 duration_in_ms=76.049
2019-06-12 02:40:20,855 [salt.state       :1780][INFO    ][12797] Running state [python-oauth] at time 02:40:20.855511
2019-06-12 02:40:20,855 [salt.state       :1813][INFO    ][12797] Executing state pkg.installed for [python-oauth]
2019-06-12 02:40:20,860 [salt.state       :300 ][INFO    ][12797] All specified packages are already installed
2019-06-12 02:40:20,860 [salt.state       :1951][INFO    ][12797] Completed state [python-oauth] at time 02:40:20.860370 duration_in_ms=4.859
2019-06-12 02:40:20,862 [salt.state       :1780][INFO    ][12797] Running state [/etc/maas/regiond.conf] at time 02:40:20.862781
2019-06-12 02:40:20,862 [salt.state       :1813][INFO    ][12797] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-12 02:40:20,938 [salt.state       :300 ][INFO    ][12797] No changes needed to be made
2019-06-12 02:40:20,938 [salt.state       :1951][INFO    ][12797] Completed state [/etc/maas/regiond.conf] at time 02:40:20.938254 duration_in_ms=75.473
2019-06-12 02:40:20,938 [salt.state       :1780][INFO    ][12797] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:40:20.938711
2019-06-12 02:40:20,939 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-12 02:40:21,003 [salt.state       :300 ][INFO    ][12797] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-12 02:40:21,003 [salt.state       :1951][INFO    ][12797] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 02:40:21.003517 duration_in_ms=64.806
2019-06-12 02:40:21,003 [salt.state       :1780][INFO    ][12797] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:40:21.003955
2019-06-12 02:40:21,004 [salt.state       :1813][INFO    ][12797] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-12 02:40:21,016 [salt.state       :300 ][INFO    ][12797] No changes needed to be made
2019-06-12 02:40:21,016 [salt.state       :1951][INFO    ][12797] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:40:21.016671 duration_in_ms=12.716
2019-06-12 02:40:21,017 [salt.state       :1780][INFO    ][12797] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:40:21.017095
2019-06-12 02:40:21,017 [salt.state       :1813][INFO    ][12797] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-12 02:40:21,040 [salt.state       :300 ][INFO    ][12797] No changes needed to be made
2019-06-12 02:40:21,040 [salt.state       :1951][INFO    ][12797] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 02:40:21.040852 duration_in_ms=23.757
2019-06-12 02:40:21,041 [salt.state       :1780][INFO    ][12797] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:40:21.041338
2019-06-12 02:40:21,041 [salt.state       :1813][INFO    ][12797] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-12 02:40:21,065 [salt.state       :300 ][INFO    ][12797] No changes needed to be made
2019-06-12 02:40:21,065 [salt.state       :1951][INFO    ][12797] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 02:40:21.065306 duration_in_ms=23.968
2019-06-12 02:40:21,065 [salt.state       :1780][INFO    ][12797] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:40:21.065761
2019-06-12 02:40:21,066 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-12 02:40:21,084 [salt.state       :300 ][INFO    ][12797] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-12 02:40:21,085 [salt.state       :1951][INFO    ][12797] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 02:40:21.085210 duration_in_ms=19.448
2019-06-12 02:40:21,089 [salt.state       :1780][INFO    ][12797] Running state [a2enmod headers] at time 02:40:21.089518
2019-06-12 02:40:21,089 [salt.state       :1813][INFO    ][12797] Executing state cmd.run for [a2enmod headers]
2019-06-12 02:40:21,090 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command 'a2enmod headers' in directory '/root'
2019-06-12 02:40:21,165 [salt.state       :300 ][INFO    ][12797] {'pid': 12816, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-12 02:40:21,166 [salt.state       :1951][INFO    ][12797] Completed state [a2enmod headers] at time 02:40:21.166028 duration_in_ms=76.51
2019-06-12 02:40:21,166 [salt.state       :1780][INFO    ][12797] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:40:21.166332
2019-06-12 02:40:21,166 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-12 02:40:21,179 [salt.state       :300 ][INFO    ][12797] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-12 02:40:21,180 [salt.state       :1951][INFO    ][12797] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 02:40:21.179974 duration_in_ms=13.642
2019-06-12 02:40:21,180 [salt.state       :1780][INFO    ][12797] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:40:21.180427
2019-06-12 02:40:21,180 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-12 02:40:21,243 [salt.state       :300 ][INFO    ][12797] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-12 02:40:21,244 [salt.state       :1951][INFO    ][12797] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 02:40:21.244120 duration_in_ms=63.691
2019-06-12 02:40:21,245 [salt.state       :1780][INFO    ][12797] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:40:21.244937
2019-06-12 02:40:21,245 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-12 02:40:21,326 [salt.state       :300 ][INFO    ][12797] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-12 02:40:21,327 [salt.state       :1951][INFO    ][12797] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 02:40:21.327213 duration_in_ms=82.277
2019-06-12 02:40:21,327 [salt.state       :1780][INFO    ][12797] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:40:21.327775
2019-06-12 02:40:21,328 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-12 02:40:21,386 [salt.state       :300 ][INFO    ][12797] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-12 02:40:21,387 [salt.state       :1951][INFO    ][12797] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 02:40:21.387058 duration_in_ms=59.283
2019-06-12 02:40:21,387 [salt.state       :1780][INFO    ][12797] Running state [/root/.pgpass] at time 02:40:21.387350
2019-06-12 02:40:21,387 [salt.state       :1813][INFO    ][12797] Executing state file.managed for [/root/.pgpass]
2019-06-12 02:40:21,434 [salt.state       :300 ][INFO    ][12797] File /root/.pgpass is in the correct state
2019-06-12 02:40:21,435 [salt.state       :1951][INFO    ][12797] Completed state [/root/.pgpass] at time 02:40:21.435075 duration_in_ms=47.724
2019-06-12 02:40:21,441 [salt.state       :1780][INFO    ][12797] Running state [maas-region syncdb --noinput] at time 02:40:21.440949
2019-06-12 02:40:21,441 [salt.state       :1813][INFO    ][12797] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-12 02:40:21,442 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-12 02:40:23,402 [salt.state       :300 ][INFO    ][12797] {'pid': 12829, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sites, contenttypes, metadataserver, auth, piston3, sessions, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-12 02:40:23,403 [salt.state       :1951][INFO    ][12797] Completed state [maas-region syncdb --noinput] at time 02:40:23.403456 duration_in_ms=1962.506
2019-06-12 02:40:23,404 [salt.state       :2022][WARNING ][12797] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-12 02:40:23,406 [salt.state       :1780][INFO    ][12797] Running state [maas-regiond] at time 02:40:23.406882
2019-06-12 02:40:23,407 [salt.state       :1813][INFO    ][12797] Executing state service.running for [maas-regiond]
2019-06-12 02:40:23,409 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:23,447 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-12 02:40:23,465 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-12 02:40:23,482 [salt.state       :300 ][INFO    ][12797] The service maas-regiond is already running
2019-06-12 02:40:23,482 [salt.state       :1951][INFO    ][12797] Completed state [maas-regiond] at time 02:40:23.482461 duration_in_ms=75.579
2019-06-12 02:40:23,484 [salt.state       :1780][INFO    ][12797] Running state [bind9] at time 02:40:23.484694
2019-06-12 02:40:23,485 [salt.state       :1813][INFO    ][12797] Executing state service.running for [bind9]
2019-06-12 02:40:23,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:23,504 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-12 02:40:23,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-12 02:40:23,536 [salt.state       :300 ][INFO    ][12797] The service bind9 is already running
2019-06-12 02:40:23,537 [salt.state       :1951][INFO    ][12797] Completed state [bind9] at time 02:40:23.537332 duration_in_ms=52.638
2019-06-12 02:40:23,539 [salt.state       :1780][INFO    ][12797] Running state [apache2] at time 02:40:23.539385
2019-06-12 02:40:23,539 [salt.state       :1813][INFO    ][12797] Executing state service.running for [apache2]
2019-06-12 02:40:23,540 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-12 02:40:23,558 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-12 02:40:23,574 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-12 02:40:23,595 [salt.state       :300 ][INFO    ][12797] The service apache2 is already running
2019-06-12 02:40:23,595 [salt.state       :1951][INFO    ][12797] Completed state [apache2] at time 02:40:23.595425 duration_in_ms=56.04
2019-06-12 02:40:23,597 [salt.state       :1780][INFO    ][12797] Running state [maasng.wait_for_http_code] at time 02:40:23.597246
2019-06-12 02:40:23,597 [salt.state       :1813][INFO    ][12797] Executing state module.run for [maasng.wait_for_http_code]
2019-06-12 02:40:23,598 [salt.utils.decorators:613 ][WARNING ][12797] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:40:23,701 [salt.state       :300 ][INFO    ][12797] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-12 02:40:23,701 [salt.state       :1951][INFO    ][12797] Completed state [maasng.wait_for_http_code] at time 02:40:23.701735 duration_in_ms=104.486
2019-06-12 02:40:23,703 [salt.state       :1780][INFO    ][12797] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:40:23.703850
2019-06-12 02:40:23,704 [salt.state       :1813][INFO    ][12797] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-12 02:40:23,705 [salt.state       :300 ][INFO    ][12797] /var/lib/maas/.setup_admin exists
2019-06-12 02:40:23,705 [salt.state       :1951][INFO    ][12797] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 02:40:23.705590 duration_in_ms=1.741
2019-06-12 02:40:23,706 [salt.state       :1780][INFO    ][12797] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:40:23.706753
2019-06-12 02:40:23,707 [salt.state       :1813][INFO    ][12797] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:40:23,708 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12797] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:40:25,256 [salt.state       :300 ][INFO    ][12797] {'pid': 12851, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:40:25,257 [salt.state       :1951][INFO    ][12797] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:40:25.256992 duration_in_ms=1550.239
2019-06-12 02:40:25,265 [salt.state       :1780][INFO    ][12797] Running state [maas_region_boot_source_resources_mirror] at time 02:40:25.265278
2019-06-12 02:40:25,265 [salt.state       :1813][INFO    ][12797] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-12 02:40:25,358 [salt.state       :300 ][INFO    ][12797] {'changes': {}}
2019-06-12 02:40:25,358 [salt.state       :1951][INFO    ][12797] Completed state [maas_region_boot_source_resources_mirror] at time 02:40:25.358542 duration_in_ms=93.264
2019-06-12 02:40:25,359 [salt.state       :1780][INFO    ][12797] Running state [maasng.boot_resources_import] at time 02:40:25.359255
2019-06-12 02:40:25,359 [salt.state       :1813][INFO    ][12797] Executing state module.run for [maasng.boot_resources_import]
2019-06-12 02:40:25,360 [salt.utils.decorators:613 ][WARNING ][12797] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:40:25,460 [salt.loaded.ext.module.maasng:1600][INFO    ][12797] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-12 02:40:30,532 [salt.loaded.ext.module.maasng:1600][INFO    ][12797] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-12 02:40:34,310 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024034298288
2019-06-12 02:40:34,333 [salt.minion      :1432][INFO    ][12878] Starting a new job with PID 12878
2019-06-12 02:40:34,356 [salt.minion      :1711][INFO    ][12878] Returning information for job: 20190612024034298288
2019-06-12 02:40:35,593 [salt.loaded.ext.module.maasng:1600][INFO    ][12797] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-12 02:40:40,706 [salt.state       :300 ][INFO    ][12797] {'ret': True}
2019-06-12 02:40:40,707 [salt.state       :1951][INFO    ][12797] Completed state [maasng.boot_resources_import] at time 02:40:40.707049 duration_in_ms=15347.791
2019-06-12 02:40:40,708 [salt.state       :1780][INFO    ][12797] Running state [maas_region_boot_sources_selection_xenial] at time 02:40:40.708237
2019-06-12 02:40:40,708 [salt.state       :1813][INFO    ][12797] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-12 02:40:40,909 [salt.state       :300 ][INFO    ][12797] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-12 02:40:40,909 [salt.state       :1951][INFO    ][12797] Completed state [maas_region_boot_sources_selection_xenial] at time 02:40:40.909892 duration_in_ms=201.655
2019-06-12 02:40:40,911 [salt.state       :1780][INFO    ][12797] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 02:40:40.911171
2019-06-12 02:40:40,911 [salt.state       :1813][INFO    ][12797] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-12 02:40:40,912 [salt.utils.decorators:613 ][WARNING ][12797] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:40:40,912 [salt.loaded.ext.module.maasng:1771][INFO    ][12797] boot-sources sync initiated for ALL Rack's
2019-06-12 02:40:41,969 [salt.state       :300 ][INFO    ][12797] {'ret': True}
2019-06-12 02:40:41,969 [salt.state       :1951][INFO    ][12797] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 02:40:41.969821 duration_in_ms=1058.649
2019-06-12 02:40:41,972 [salt.state       :1780][INFO    ][12797] Running state [maas.process_maas_config] at time 02:40:41.971952
2019-06-12 02:40:41,972 [salt.state       :1813][INFO    ][12797] Executing state module.run for [maas.process_maas_config]
2019-06-12 02:40:41,973 [salt.utils.decorators:613 ][WARNING ][12797] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:40:41,974 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=enable_http_proxy value=True
2019-06-12 02:40:42,038 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=upstream_dns value=8.8.8.8
2019-06-12 02:40:42,101 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=commissioning_distro_series value=xenial
2019-06-12 02:40:42,167 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=default_osystem value=ubuntu
2019-06-12 02:40:42,239 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=active_discovery_interval value=600
2019-06-12 02:40:42,292 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=dnssec_validation value=no
2019-06-12 02:40:42,353 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=maas_name value=mas01
2019-06-12 02:40:42,406 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=network_discovery value=enabled
2019-06-12 02:40:42,526 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=enable_third_party_drivers value=True
2019-06-12 02:40:45,174 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=default_storage_layout value=lvm
2019-06-12 02:40:45,236 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=ntp_external_only value=True
2019-06-12 02:40:45,296 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-12 02:40:45,340 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=default_distro_series value=xenial
2019-06-12 02:40:45,416 [salt.loaded.ext.module.maas:92  ][INFO    ][12797] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-06-12 02:40:45,544 [salt.state       :300 ][INFO    ][12797] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-06-12 02:40:45,545 [salt.state       :1951][INFO    ][12797] Completed state [maas.process_maas_config] at time 02:40:45.544993 duration_in_ms=3573.04
2019-06-12 02:40:45,545 [salt.state       :1780][INFO    ][12797] Running state [pxe_admin] at time 02:40:45.545883
2019-06-12 02:40:45,546 [salt.state       :1813][INFO    ][12797] Executing state maasng.fabric_present for [pxe_admin]
2019-06-12 02:40:45,610 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-12 02:40:45,694 [salt.loaded.ext.module.maasng:1008][WARNING ][12797] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-12 02:40:45,695 [salt.loaded.ext.module.maasng:1011][WARNING ][12797] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-12 02:40:45,768 [salt.state       :300 ][INFO    ][12797] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-12 02:40:45,769 [salt.state       :1951][INFO    ][12797] Completed state [pxe_admin] at time 02:40:45.768961 duration_in_ms=223.077
2019-06-12 02:40:45,769 [salt.state       :1780][INFO    ][12797] Running state [vlan 0] at time 02:40:45.769403
2019-06-12 02:40:45,769 [salt.state       :1813][INFO    ][12797] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-12 02:40:45,827 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'id': 0, 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'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'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'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'freft3', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-12 02:40:45,924 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'id': 0, 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'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'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'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'freft3', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-12 02:40:46,190 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-12 02:40:46,284 [salt.state       :300 ][INFO    ][12797] {'new': 'Vlan untagged was updated'}
2019-06-12 02:40:46,284 [salt.state       :1951][INFO    ][12797] Completed state [vlan 0] at time 02:40:46.284597 duration_in_ms=515.192
2019-06-12 02:40:46,286 [salt.state       :1780][INFO    ][12797] Running state [192.168.11.0/24] at time 02:40:46.286185
2019-06-12 02:40:46,286 [salt.state       :1813][INFO    ][12797] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-12 02:40:46,478 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-06-12 02:40:46,479 [salt.loaded.ext.module.maasng:1235][WARNING ][12797] Ignoring parameter vlan:0
2019-06-12 02:40:46,551 [salt.state       :300 ][INFO    ][12797] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-12 02:40:46,551 [salt.state       :1951][INFO    ][12797] Completed state [192.168.11.0/24] at time 02:40:46.551624 duration_in_ms=265.439
2019-06-12 02:40:46,553 [salt.state       :1780][INFO    ][12797] Running state [maas_create_iprange_1] at time 02:40:46.552970
2019-06-12 02:40:46,553 [salt.state       :1813][INFO    ][12797] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-12 02:40:46,628 [salt.state       :300 ][INFO    ][12797] Iprange maas_create_iprange_1 already exist.
2019-06-12 02:40:46,629 [salt.state       :1951][INFO    ][12797] Completed state [maas_create_iprange_1] at time 02:40:46.629239 duration_in_ms=76.268
2019-06-12 02:40:46,629 [salt.state       :1780][INFO    ][12797] Running state [vlan 0] at time 02:40:46.629716
2019-06-12 02:40:46,630 [salt.state       :1813][INFO    ][12797] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-12 02:40:46,690 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'freft3', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-12 02:40:46,786 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'id': 0, 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'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'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'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'freft3', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-12 02:40:47,024 [salt.loaded.ext.module.maasng:945 ][INFO    ][12797] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'freft3', 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-06-12 02:40:47,107 [salt.state       :300 ][INFO    ][12797] {'new': 'Vlan untagged was updated'}
2019-06-12 02:40:47,108 [salt.state       :1951][INFO    ][12797] Completed state [vlan 0] at time 02:40:47.108165 duration_in_ms=478.449
2019-06-12 02:40:47,108 [salt.state       :1780][INFO    ][12797] Running state [opnfv] at time 02:40:47.108807
2019-06-12 02:40:47,109 [salt.state       :1813][INFO    ][12797] Executing state maasng.sshkey_present for [opnfv]
2019-06-12 02:40:47,149 [salt.loaded.ext.module.maasng:1903][INFO    ][12797] [{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-06-12 02:40:47,150 [salt.state       :300 ][INFO    ][12797] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-12 02:40:47,150 [salt.state       :1951][INFO    ][12797] Completed state [opnfv] at time 02:40:47.150321 duration_in_ms=41.513
2019-06-12 02:40:47,155 [salt.minion      :1711][INFO    ][12797] Returning information for job: 20190612024019215133
2019-06-12 02:40:47,753 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612024047741862
2019-06-12 02:40:47,774 [salt.minion      :1432][INFO    ][13274] Starting a new job with PID 13274
2019-06-12 02:40:51,498 [salt.state       :915 ][INFO    ][13274] Loading fresh modules for state activity
2019-06-12 02:40:51,593 [salt.state       :1780][INFO    ][13274] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:40:51.593766
2019-06-12 02:40:51,594 [salt.state       :1813][INFO    ][13274] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:40:51,596 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13274] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:40:53,000 [salt.state       :300 ][INFO    ][13274] {'pid': 13298, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:40:53,001 [salt.state       :1951][INFO    ][13274] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:40:53.001362 duration_in_ms=1407.596
2019-06-12 02:40:53,002 [salt.state       :1780][INFO    ][13274] Running state [maas.process_machines] at time 02:40:53.002557
2019-06-12 02:40:53,002 [salt.state       :1813][INFO    ][13274] Executing state module.run for [maas.process_machines]
2019-06-12 02:40:53,003 [salt.utils.decorators:613 ][WARNING ][13274] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:40:53,709 [salt.loaded.ext.module.maas:412 ][WARNING ][13274] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:40:53,710 [salt.loaded.ext.module.maas:92  ][INFO    ][13274] 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=647nsp architecture=amd64/generic power_parameters_power_user=admin
2019-06-12 02:40:54,847 [salt.loaded.ext.module.maas:412 ][WARNING ][13274] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:40:54,848 [salt.loaded.ext.module.maas:92  ][INFO    ][13274] 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=rcfn6h architecture=amd64/generic power_parameters_power_user=admin
2019-06-12 02:40:56,129 [salt.loaded.ext.module.maas:412 ][WARNING ][13274] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:40:56,130 [salt.loaded.ext.module.maas:92  ][INFO    ][13274] 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=83fmkt architecture=amd64/generic power_parameters_power_user=admin
2019-06-12 02:40:57,416 [salt.loaded.ext.module.maas:412 ][WARNING ][13274] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:40:57,418 [salt.loaded.ext.module.maas:92  ][INFO    ][13274] 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=kt7pge architecture=amd64/generic power_parameters_power_user=admin
2019-06-12 02:40:58,650 [salt.loaded.ext.module.maas:412 ][WARNING ][13274] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-12 02:40:58,651 [salt.loaded.ext.module.maas:92  ][INFO    ][13274] 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=744pr7 architecture=amd64/generic power_parameters_power_user=admin
2019-06-12 02:40:59,914 [salt.state       :300 ][INFO    ][13274] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-12 02:40:59,915 [salt.state       :1951][INFO    ][13274] Completed state [maas.process_machines] at time 02:40:59.915338 duration_in_ms=6912.777
2019-06-12 02:40:59,919 [salt.minion      :1711][INFO    ][13274] Returning information for job: 20190612024047741862
2019-06-12 02:41:32,053 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612024132041997
2019-06-12 02:41:32,070 [salt.minion      :1432][INFO    ][13524] Starting a new job with PID 13524
2019-06-12 02:41:35,770 [salt.state       :915 ][INFO    ][13524] Loading fresh modules for state activity
2019-06-12 02:41:35,859 [salt.state       :1780][INFO    ][13524] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:41:35.859736
2019-06-12 02:41:35,860 [salt.state       :1813][INFO    ][13524] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:41:35,862 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13524] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:41:37,330 [salt.state       :300 ][INFO    ][13524] {'pid': 13534, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:41:37,331 [salt.state       :1951][INFO    ][13524] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:41:37.331259 duration_in_ms=1471.525
2019-06-12 02:41:37,332 [salt.state       :1780][INFO    ][13524] Running state [maas.wait_for_machine_status] at time 02:41:37.332867
2019-06-12 02:41:37,333 [salt.state       :1813][INFO    ][13524] Executing state module.run for [maas.wait_for_machine_status]
2019-06-12 02:41:37,333 [salt.utils.decorators:613 ][WARNING ][13524] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:41:39,744 [salt.loaded.ext.module.maas:993 ][INFO    ][13524] Machine kt7pge mark broken
2019-06-12 02:41:40,339 [salt.loaded.ext.module.maas:996 ][INFO    ][13524] Machine kt7pge mark fixed
2019-06-12 02:41:41,577 [salt.loaded.ext.module.maas:684 ][INFO    ][13524] deploymachines hwe_kernel=ga-16.04 system_id=kt7pge distro_series=xenial
2019-06-12 02:41:44,750 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.58740401s left)
2019-06-12 02:41:47,197 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024147154530
2019-06-12 02:41:47,217 [salt.minion      :1432][INFO    ][13642] Starting a new job with PID 13642
2019-06-12 02:41:47,240 [salt.minion      :1711][INFO    ][13642] Returning information for job: 20190612024147154530
2019-06-12 02:42:17,238 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024217225823
2019-06-12 02:42:17,259 [salt.minion      :1432][INFO    ][13666] Starting a new job with PID 13666
2019-06-12 02:42:17,285 [salt.minion      :1711][INFO    ][13666] Returning information for job: 20190612024217225823
2019-06-12 02:42:18,211 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.12653708s left)
2019-06-12 02:42:47,288 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024247275376
2019-06-12 02:42:47,311 [salt.minion      :1432][INFO    ][13726] Starting a new job with PID 13726
2019-06-12 02:42:47,337 [salt.minion      :1711][INFO    ][13726] Returning information for job: 20190612024247275376
2019-06-12 02:42:51,460 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1425.87740612s left)
2019-06-12 02:43:17,342 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024317327955
2019-06-12 02:43:17,365 [salt.minion      :1432][INFO    ][13748] Starting a new job with PID 13748
2019-06-12 02:43:17,392 [salt.minion      :1711][INFO    ][13748] Returning information for job: 20190612024317327955
2019-06-12 02:43:24,352 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.98603415s left)
2019-06-12 02:43:47,404 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024347388927
2019-06-12 02:43:47,427 [salt.minion      :1432][INFO    ][13910] Starting a new job with PID 13910
2019-06-12 02:43:47,453 [salt.minion      :1711][INFO    ][13910] Returning information for job: 20190612024347388927
2019-06-12 02:43:57,794 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.54363894s left)
2019-06-12 02:44:17,462 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024417449531
2019-06-12 02:44:17,485 [salt.minion      :1432][INFO    ][13941] Starting a new job with PID 13941
2019-06-12 02:44:17,511 [salt.minion      :1711][INFO    ][13941] Returning information for job: 20190612024417449531
2019-06-12 02:44:30,866 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1326.47207904s left)
2019-06-12 02:44:47,525 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024447511839
2019-06-12 02:44:47,547 [salt.minion      :1432][INFO    ][14111] Starting a new job with PID 14111
2019-06-12 02:44:47,573 [salt.minion      :1711][INFO    ][14111] Returning information for job: 20190612024447511839
2019-06-12 02:45:04,645 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1292.69229913s left)
2019-06-12 02:45:17,587 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024517574021
2019-06-12 02:45:17,610 [salt.minion      :1432][INFO    ][14130] Starting a new job with PID 14130
2019-06-12 02:45:17,636 [salt.minion      :1711][INFO    ][14130] Returning information for job: 20190612024517574021
2019-06-12 02:45:38,064 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1259.27382612s left)
2019-06-12 02:45:47,655 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024547640868
2019-06-12 02:45:47,675 [salt.minion      :1432][INFO    ][14208] Starting a new job with PID 14208
2019-06-12 02:45:47,701 [salt.minion      :1711][INFO    ][14208] Returning information for job: 20190612024547640868
2019-06-12 02:46:11,248 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1226.08944893s left)
2019-06-12 02:46:17,728 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024617715142
2019-06-12 02:46:17,750 [salt.minion      :1432][INFO    ][14229] Starting a new job with PID 14229
2019-06-12 02:46:17,777 [salt.minion      :1711][INFO    ][14229] Returning information for job: 20190612024617715142
2019-06-12 02:46:44,628 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1192.71017504s left)
2019-06-12 02:46:47,807 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024647795385
2019-06-12 02:46:47,830 [salt.minion      :1432][INFO    ][14354] Starting a new job with PID 14354
2019-06-12 02:46:47,855 [salt.minion      :1711][INFO    ][14354] Returning information for job: 20190612024647795385
2019-06-12 02:47:17,884 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024717872040
2019-06-12 02:47:17,909 [salt.minion      :1432][INFO    ][14380] Starting a new job with PID 14380
2019-06-12 02:47:17,934 [salt.minion      :1711][INFO    ][14380] Returning information for job: 20190612024717872040
2019-06-12 02:47:18,173 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1159.16445613s left)
2019-06-12 02:47:47,969 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024747957250
2019-06-12 02:47:47,992 [salt.minion      :1432][INFO    ][14477] Starting a new job with PID 14477
2019-06-12 02:47:48,020 [salt.minion      :1711][INFO    ][14477] Returning information for job: 20190612024747957250
2019-06-12 02:47:51,931 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1125.40634513s left)
2019-06-12 02:48:18,064 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024818051335
2019-06-12 02:48:18,087 [salt.minion      :1432][INFO    ][14504] Starting a new job with PID 14504
2019-06-12 02:48:18,112 [salt.minion      :1711][INFO    ][14504] Returning information for job: 20190612024818051335
2019-06-12 02:48:25,455 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1091.88270903s left)
2019-06-12 02:48:48,158 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024848146928
2019-06-12 02:48:48,182 [salt.minion      :1432][INFO    ][14641] Starting a new job with PID 14641
2019-06-12 02:48:48,208 [salt.minion      :1711][INFO    ][14641] Returning information for job: 20190612024848146928
2019-06-12 02:48:58,925 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1058.41314316s left)
2019-06-12 02:49:18,259 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024918247341
2019-06-12 02:49:18,282 [salt.minion      :1432][INFO    ][14676] Starting a new job with PID 14676
2019-06-12 02:49:18,309 [salt.minion      :1711][INFO    ][14676] Returning information for job: 20190612024918247341
2019-06-12 02:49:32,427 [salt.loaded.ext.module.maas:1023][INFO    ][13524] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1024.91029s left)
2019-06-12 02:49:48,370 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command saltutil.find_job with jid 20190612024948357708
2019-06-12 02:49:48,393 [salt.minion      :1432][INFO    ][14753] Starting a new job with PID 14753
2019-06-12 02:49:48,421 [salt.minion      :1711][INFO    ][14753] Returning information for job: 20190612024948357708
2019-06-12 02:50:05,784 [salt.state       :300 ][INFO    ][13524] {'ret': True}
2019-06-12 02:50:05,785 [salt.state       :1951][INFO    ][13524] Completed state [maas.wait_for_machine_status] at time 02:50:05.784965 duration_in_ms=508452.097
2019-06-12 02:50:05,787 [salt.minion      :1711][INFO    ][13524] Returning information for job: 20190612024132041997
2019-06-12 02:50:06,368 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612025006356469
2019-06-12 02:50:06,383 [salt.minion      :1432][INFO    ][14784] Starting a new job with PID 14784
2019-06-12 02:50:10,077 [salt.state       :915 ][INFO    ][14784] Loading fresh modules for state activity
2019-06-12 02:50:10,216 [salt.state       :1780][INFO    ][14784] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:10.215984
2019-06-12 02:50:10,216 [salt.state       :1813][INFO    ][14784] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:50:10,217 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14784] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:50:11,762 [salt.state       :300 ][INFO    ][14784] {'pid': 14800, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:50:11,763 [salt.state       :1951][INFO    ][14784] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:11.763175 duration_in_ms=1547.192
2019-06-12 02:50:11,764 [salt.state       :1780][INFO    ][14784] Running state [maas_machines_storage_cmp002_lvm] at time 02:50:11.764677
2019-06-12 02:50:11,764 [salt.state       :1813][INFO    ][14784] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-12 02:50:12,506 [salt.state       :300 ][INFO    ][14784] Machine cmp002 is not in Ready state.
2019-06-12 02:50:12,506 [salt.state       :1951][INFO    ][14784] Completed state [maas_machines_storage_cmp002_lvm] at time 02:50:12.506839 duration_in_ms=742.161
2019-06-12 02:50:12,507 [salt.state       :1780][INFO    ][14784] Running state [maas_machines_storage_cmp001_lvm] at time 02:50:12.507397
2019-06-12 02:50:12,507 [salt.state       :1813][INFO    ][14784] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-12 02:50:13,224 [salt.state       :300 ][INFO    ][14784] Machine cmp001 is not in Ready state.
2019-06-12 02:50:13,225 [salt.state       :1951][INFO    ][14784] Completed state [maas_machines_storage_cmp001_lvm] at time 02:50:13.225086 duration_in_ms=717.688
2019-06-12 02:50:13,229 [salt.minion      :1711][INFO    ][14784] Returning information for job: 20190612025006356469
2019-06-12 02:50:13,713 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612025013700431
2019-06-12 02:50:13,735 [salt.minion      :1432][INFO    ][14810] Starting a new job with PID 14810
2019-06-12 02:50:14,474 [salt.state       :915 ][INFO    ][14810] Loading fresh modules for state activity
2019-06-12 02:50:14,522 [salt.state       :1780][INFO    ][14810] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:14.521978
2019-06-12 02:50:14,522 [salt.state       :1813][INFO    ][14810] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:50:14,523 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14810] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:50:15,969 [salt.state       :300 ][INFO    ][14810] {'pid': 14818, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:50:15,970 [salt.state       :1951][INFO    ][14810] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:15.970401 duration_in_ms=1448.423
2019-06-12 02:50:15,971 [salt.state       :1780][INFO    ][14810] Running state [maas.deploy_machines] at time 02:50:15.971628
2019-06-12 02:50:15,971 [salt.state       :1813][INFO    ][14810] Executing state module.run for [maas.deploy_machines]
2019-06-12 02:50:15,972 [salt.utils.decorators:613 ][WARNING ][14810] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:50:16,716 [salt.state       :300 ][INFO    ][14810] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-12 02:50:16,717 [salt.state       :1951][INFO    ][14810] Completed state [maas.deploy_machines] at time 02:50:16.717013 duration_in_ms=745.383
2019-06-12 02:50:16,720 [salt.minion      :1711][INFO    ][14810] Returning information for job: 20190612025013700431
2019-06-12 02:50:17,284 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command state.apply with jid 20190612025017270762
2019-06-12 02:50:17,306 [salt.minion      :1432][INFO    ][14827] Starting a new job with PID 14827
2019-06-12 02:50:18,122 [salt.state       :915 ][INFO    ][14827] Loading fresh modules for state activity
2019-06-12 02:50:18,217 [salt.state       :1780][INFO    ][14827] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:18.217222
2019-06-12 02:50:18,217 [salt.state       :1813][INFO    ][14827] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-12 02:50:18,219 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14827] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-12 02:50:19,666 [salt.state       :300 ][INFO    ][14827] {'pid': 14834, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-12 02:50:19,667 [salt.state       :1951][INFO    ][14827] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:50:19.667142 duration_in_ms=1449.921
2019-06-12 02:50:19,668 [salt.state       :1780][INFO    ][14827] Running state [maas.wait_for_machine_status] at time 02:50:19.668648
2019-06-12 02:50:19,668 [salt.state       :1813][INFO    ][14827] Executing state module.run for [maas.wait_for_machine_status]
2019-06-12 02:50:19,669 [salt.utils.decorators:613 ][WARNING ][14827] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-12 02:50:23,021 [salt.state       :300 ][INFO    ][14827] {'ret': True}
2019-06-12 02:50:23,021 [salt.state       :1951][INFO    ][14827] Completed state [maas.wait_for_machine_status] at time 02:50:23.021568 duration_in_ms=3352.917
2019-06-12 02:50:23,025 [salt.minion      :1711][INFO    ][14827] Returning information for job: 20190612025017270762
2019-06-12 03:20:01,114 [salt.utils.schedule:1377][INFO    ][6634] Running scheduled job: __mine_interval
2019-06-12 04:20:01,114 [salt.utils.schedule:1377][INFO    ][6634] Running scheduled job: __mine_interval
2019-06-12 04:28:33,970 [salt.minion      :1308][INFO    ][6634] User sudo_ubuntu Executing command cp.push_dir with jid 20190612042833956477
2019-06-12 04:28:33,991 [salt.minion      :1432][INFO    ][21846] Starting a new job with PID 21846
