2019-03-18 05:07:56,444 [salt.utils.decorators:613 ][WARNING ][2266] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:07:56,926 [salt.utils.decorators:613 ][WARNING ][2266] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:07:58,780 [salt.loaded.int.states.file:2298][WARNING ][2522] 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-03-18 05:08:24,565 [salt.state       :2022][WARNING ][3142] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-18 05:08:27,020 [salt.utils.decorators:613 ][WARNING ][3142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:09:22,482 [salt.utils.decorators:613 ][WARNING ][3142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:00,431 [salt.utils.decorators:613 ][WARNING ][3142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:01,448 [salt.utils.decorators:613 ][WARNING ][3142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:05,443 [salt.loaded.ext.module.maasng:1008][WARNING ][3142] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-03-18 05:10:05,444 [salt.loaded.ext.module.maasng:1011][WARNING ][3142] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-03-18 05:10:06,151 [salt.loaded.ext.module.maasng:1235][WARNING ][3142] Ignoring parameter vlan:0
2019-03-18 05:10:07,153 [salt.utils.decorators:613 ][WARNING ][3142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:09,308 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7520] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-03-18 05:10:09,336 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7520] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-03-18 05:10:09,357 [salt.utils.parsers:1051][WARNING ][360] Minion received a SIGTERM. Exiting.
2019-03-18 05:10:10,253 [salt.cli.daemons :293 ][INFO    ][7597] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-03-18 05:10:10,372 [salt.cli.daemons :82  ][INFO    ][7597] Starting up the Salt Minion
2019-03-18 05:10:10,372 [salt.utils.event :1017][INFO    ][7597] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-03-18 05:10:11,261 [salt.minion      :976 ][INFO    ][7597] Creating minion process manager
2019-03-18 05:10:12,571 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][7597] Executing command ['date', '+%z'] in directory '/root'
2019-03-18 05:10:12,590 [salt.utils.schedule:568 ][INFO    ][7597] Updating job settings for scheduled job: __mine_interval
2019-03-18 05:10:12,591 [salt.minion      :1108][INFO    ][7597] Added mine.update to scheduler
2019-03-18 05:10:12,595 [salt.minion      :1975][INFO    ][7597] Minion is starting as user 'root'
2019-03-18 05:10:12,608 [salt.minion      :2336][INFO    ][7597] Minion is ready to receive requests!
2019-03-18 05:10:12,967 [salt.utils.decorators:613 ][WARNING ][7528] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:13,045 [salt.loaded.ext.module.maas:412 ][WARNING ][7528] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:10:14,537 [salt.loaded.ext.module.maas:412 ][WARNING ][7528] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:10:15,991 [salt.loaded.ext.module.maas:412 ][WARNING ][7528] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:10:17,302 [salt.loaded.ext.module.maas:412 ][WARNING ][7528] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:10:18,619 [salt.loaded.ext.module.maas:412 ][WARNING ][7528] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:10:53,423 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318051053410420
2019-03-18 05:10:53,447 [salt.minion      :1432][INFO    ][8078] Starting a new job with PID 8078
2019-03-18 05:10:57,070 [salt.state       :915 ][INFO    ][8078] Loading fresh modules for state activity
2019-03-18 05:10:57,125 [salt.fileclient  :1219][INFO    ][8078] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-03-18 05:10:57,169 [salt.state       :1780][INFO    ][8078] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:10:57.169414
2019-03-18 05:10:57,169 [salt.state       :1813][INFO    ][8078] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:10:57,171 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8078] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:10:58,639 [salt.state       :300 ][INFO    ][8078] {'pid': 8102, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:10:58,639 [salt.state       :1951][INFO    ][8078] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:10:58.639734 duration_in_ms=1470.32
2019-03-18 05:10:58,640 [salt.state       :1780][INFO    ][8078] Running state [maas.wait_for_machine_status] at time 05:10:58.640918
2019-03-18 05:10:58,641 [salt.state       :1813][INFO    ][8078] Executing state module.run for [maas.wait_for_machine_status]
2019-03-18 05:10:58,641 [salt.utils.decorators:613 ][WARNING ][8078] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:10:59,695 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.95052981s left)
2019-03-18 05:11:08,465 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051108453201
2019-03-18 05:11:08,491 [salt.minion      :1432][INFO    ][8114] Starting a new job with PID 8114
2019-03-18 05:11:08,513 [salt.minion      :1711][INFO    ][8114] Returning information for job: 20190318051108453201
2019-03-18 05:11:30,588 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.05741692s left)
2019-03-18 05:11:38,520 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051138505051
2019-03-18 05:11:38,542 [salt.minion      :1432][INFO    ][8154] Starting a new job with PID 8154
2019-03-18 05:11:38,561 [salt.minion      :1711][INFO    ][8154] Returning information for job: 20190318051138505051
2019-03-18 05:12:01,836 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.80970883s left)
2019-03-18 05:12:08,641 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051208588454
2019-03-18 05:12:08,662 [salt.minion      :1432][INFO    ][8262] Starting a new job with PID 8262
2019-03-18 05:12:08,682 [salt.minion      :1711][INFO    ][8262] Returning information for job: 20190318051208588454
2019-03-18 05:12:33,173 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.47278094s left)
2019-03-18 05:12:38,690 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051238675635
2019-03-18 05:12:38,715 [salt.minion      :1432][INFO    ][8495] Starting a new job with PID 8495
2019-03-18 05:12:38,736 [salt.minion      :1711][INFO    ][8495] Returning information for job: 20190318051238675635
2019-03-18 05:13:04,726 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.91994095s left)
2019-03-18 05:13:08,753 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051308738522
2019-03-18 05:13:08,777 [salt.minion      :1432][INFO    ][8775] Starting a new job with PID 8775
2019-03-18 05:13:08,798 [salt.minion      :1711][INFO    ][8775] Returning information for job: 20190318051308738522
2019-03-18 05:13:36,631 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.01453185s left)
2019-03-18 05:13:38,811 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051338796984
2019-03-18 05:13:38,836 [salt.minion      :1432][INFO    ][9207] Starting a new job with PID 9207
2019-03-18 05:13:38,858 [salt.minion      :1711][INFO    ][9207] Returning information for job: 20190318051338796984
2019-03-18 05:14:08,880 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051408863470
2019-03-18 05:14:08,905 [salt.minion      :1432][INFO    ][9396] Starting a new job with PID 9396
2019-03-18 05:14:08,927 [salt.minion      :1711][INFO    ][9396] Returning information for job: 20190318051408863470
2019-03-18 05:14:09,733 [salt.loaded.ext.module.maas:1023][INFO    ][8078] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1308.91279984s left)
2019-03-18 05:14:38,949 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051438932897
2019-03-18 05:14:38,974 [salt.minion      :1432][INFO    ][9566] Starting a new job with PID 9566
2019-03-18 05:14:38,994 [salt.minion      :1711][INFO    ][9566] Returning information for job: 20190318051438932897
2019-03-18 05:14:43,568 [salt.state       :300 ][INFO    ][8078] {'ret': True}
2019-03-18 05:14:43,568 [salt.state       :1951][INFO    ][8078] Completed state [maas.wait_for_machine_status] at time 05:14:43.568631 duration_in_ms=224927.711
2019-03-18 05:14:43,572 [salt.minion      :1711][INFO    ][8078] Returning information for job: 20190318051053410420
2019-03-18 05:14:44,187 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318051444171110
2019-03-18 05:14:44,211 [salt.minion      :1432][INFO    ][9578] Starting a new job with PID 9578
2019-03-18 05:14:47,828 [salt.state       :915 ][INFO    ][9578] Loading fresh modules for state activity
2019-03-18 05:14:47,885 [salt.fileclient  :1219][INFO    ][9578] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-03-18 05:14:47,979 [salt.state       :1780][INFO    ][9578] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:47.979754
2019-03-18 05:14:47,980 [salt.state       :1813][INFO    ][9578] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:14:47,981 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9578] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:14:49,355 [salt.state       :300 ][INFO    ][9578] {'pid': 9585, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:14:49,355 [salt.state       :1951][INFO    ][9578] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:49.355738 duration_in_ms=1375.982
2019-03-18 05:14:49,358 [salt.state       :1780][INFO    ][9578] Running state [maas_machines_storage_cmp002_lvm] at time 05:14:49.358504
2019-03-18 05:14:49,359 [salt.state       :1813][INFO    ][9578] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-03-18 05:14:50,583 [salt.loaded.ext.module.maasng:610 ][INFO    ][9578] dhmbhe
2019-03-18 05:14:50,583 [salt.loaded.ext.module.maasng:626 ][INFO    ][9578] sda
2019-03-18 05:14:51,117 [salt.loaded.ext.module.maasng:361 ][INFO    ][9578] dhmbhe
2019-03-18 05:14:51,210 [salt.loaded.ext.module.maasng:367 ][INFO    ][9578] [{u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'uuid': u'750dae12-1c13-40f0-a5af-0812881ef038', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dhmbhe', u'device_id': 5, u'filesystem': {u'uuid': u'41f413a5-1ed3-4316-b4bc-928b32e3bec0', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/partition/5'}], u'filesystem': None, u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'system_id': u'dhmbhe', u'partition_table_type': u'GPT', u'available_size': 0, u'id': 5, u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/'}, {u'block_size': 4096, u'uuid': u'9c456e22-68a6-43b1-ac8b-d520a028929f', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'filesystem': {u'uuid': u'614a1852-9562-406e-9d07-bf626f9e98d0', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'dhmbhe', u'partition_table_type': None, u'available_size': 0, u'id': 10, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 2397988454400, u'used_size': 2397988454400, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/10/'}]
2019-03-18 05:14:51,210 [salt.loaded.ext.module.maasng:632 ][INFO    ][9578] vgroot
2019-03-18 05:14:51,211 [salt.loaded.ext.module.maasng:635 ][INFO    ][9578] lvroot
2019-03-18 05:14:51,211 [salt.loaded.ext.module.maasng:639 ][INFO    ][9578] 107374182400
2019-03-18 05:14:51,846 [salt.loaded.ext.module.maasng:645 ][INFO    ][9578] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.43'], 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'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'dhmbhe', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'33efbb1a-fbb2-4f16-9095-76357f842162', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dhmbhe', u'filesystem': {u'uuid': u'8fda0a10-daed-4a86-9f27-849cf54a3731', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/'}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'uuid': u'7784d859-027c-42fd-b189-ee8b3ef85a78', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'dhmbhe', u'partition_table_type': None, u'filesystem': {u'uuid': u'6370c232-1cb5-4ee1-855f-90ce6692e45e', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'id': 11, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/11/'}], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'dhmbhe', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'uuid': u'7784d859-027c-42fd-b189-ee8b3ef85a78', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'dhmbhe', u'partition_table_type': None, u'filesystem': {u'uuid': u'6370c232-1cb5-4ee1-855f-90ce6692e45e', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'id': 11, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/11/'}], u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'dhmbhe', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'33efbb1a-fbb2-4f16-9095-76357f842162', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dhmbhe', u'filesystem': {u'uuid': u'8fda0a10-daed-4a86-9f27-849cf54a3731', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'dhmbhe', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', 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.43', u'id': 40, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', 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.43'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'id': 6, u'system_id': u'dhmbhe', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/interfaces/6/'}, {u'name': u'enp9s0', u'links': [{u'id': 41, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'effective_mtu': 1500, u'id': 23, u'system_id': u'dhmbhe', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/interfaces/23/'}, {u'name': u'enp7s0', u'links': [{u'id': 42, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'effective_mtu': 1500, u'id': 24, u'system_id': u'dhmbhe', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/interfaces/24/'}, {u'name': u'enp8s0', u'links': [{u'id': 43, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'effective_mtu': 1500, u'id': 25, u'system_id': u'dhmbhe', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/interfaces/25/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'architecture': u'amd64/generic', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', 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.43', u'id': 40, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', 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.43'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'id': 6, u'system_id': u'dhmbhe', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/interfaces/6/'}, u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'dhmbhe', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'33efbb1a-fbb2-4f16-9095-76357f842162', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dhmbhe', u'filesystem': {u'uuid': u'8fda0a10-daed-4a86-9f27-849cf54a3731', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/dhmbhe/blockdevices/5/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/dhmbhe/'}
2019-03-18 05:14:51,848 [salt.state       :300 ][INFO    ][9578] {'new': {'storage_layout': 'lvm'}}
2019-03-18 05:14:51,849 [salt.state       :1951][INFO    ][9578] Completed state [maas_machines_storage_cmp002_lvm] at time 05:14:51.849283 duration_in_ms=2490.779
2019-03-18 05:14:51,849 [salt.state       :1780][INFO    ][9578] Running state [maas_machines_storage_cmp001_lvm] at time 05:14:51.849846
2019-03-18 05:14:51,850 [salt.state       :1813][INFO    ][9578] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-03-18 05:14:53,028 [salt.loaded.ext.module.maasng:610 ][INFO    ][9578] wwhmpp
2019-03-18 05:14:53,029 [salt.loaded.ext.module.maasng:626 ][INFO    ][9578] sda
2019-03-18 05:14:53,744 [salt.loaded.ext.module.maasng:361 ][INFO    ][9578] wwhmpp
2019-03-18 05:14:53,857 [salt.loaded.ext.module.maasng:367 ][INFO    ][9578] [{u'partition_table_type': u'GPT', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'50c17e73-bbd5-4fda-a676-be192f76e3db', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/partition/2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wwhmpp', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'0594021a-5c85-447e-a65a-eec730c9e62a', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 2, u'device_id': 2}], u'filesystem': None, u'name': u'sda', u'system_id': u'wwhmpp', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'partition_table_type': None, u'uuid': u'356d63f7-f3ad-4846-9ce5-9af12a148031', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'2a9c8f37-5e27-4d00-bce2-b1632337cbde', u'fstype': u'ext4', u'label': u'root'}, u'name': u'vgroot-lvroot', u'system_id': u'wwhmpp', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/7/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 7, u'serial': None, u'size': 2397988454400}]
2019-03-18 05:14:53,858 [salt.loaded.ext.module.maasng:632 ][INFO    ][9578] vgroot
2019-03-18 05:14:53,858 [salt.loaded.ext.module.maasng:635 ][INFO    ][9578] lvroot
2019-03-18 05:14:53,859 [salt.loaded.ext.module.maasng:639 ][INFO    ][9578] 107374182400
2019-03-18 05:14:54,591 [salt.loaded.ext.module.maasng:645 ][INFO    ][9578] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'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'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'wwhmpp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'e1ec6063-69c6-4412-9259-b2de6e8f800b', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wwhmpp', u'filesystem': {u'uuid': u'edf3dc05-ae89-4e26-a3e6-4e25494cab43', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/'}, {u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'uuid': u'd3d58ef4-f28c-4461-b448-dc69523cdc30', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'wwhmpp', u'partition_table_type': None, u'filesystem': {u'uuid': u'11fafb51-20d1-4b12-b35b-818316ed616f', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/12/'}], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'wwhmpp', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'uuid': u'd3d58ef4-f28c-4461-b448-dc69523cdc30', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'wwhmpp', u'partition_table_type': None, u'filesystem': {u'uuid': u'11fafb51-20d1-4b12-b35b-818316ed616f', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/12/'}], u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'wwhmpp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'e1ec6063-69c6-4412-9259-b2de6e8f800b', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wwhmpp', u'filesystem': {u'uuid': u'edf3dc05-ae89-4e26-a3e6-4e25494cab43', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'wwhmpp', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 25, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'id': 7, u'system_id': u'wwhmpp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/interfaces/7/'}, {u'name': u'enp9s0', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'effective_mtu': 1500, u'id': 14, u'system_id': u'wwhmpp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/interfaces/14/'}, {u'name': u'enp8s0', u'links': [{u'id': 27, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'effective_mtu': 1500, u'id': 15, u'system_id': u'wwhmpp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/interfaces/15/'}, {u'name': u'enp7s0', u'links': [{u'id': 29, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'effective_mtu': 1500, u'id': 16, u'system_id': u'wwhmpp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/interfaces/16/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'architecture': u'amd64/generic', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 25, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'effective_mtu': 1500, u'id': 7, u'system_id': u'wwhmpp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/interfaces/7/'}, u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'wwhmpp', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'e1ec6063-69c6-4412-9259-b2de6e8f800b', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'wwhmpp', u'filesystem': {u'uuid': u'edf3dc05-ae89-4e26-a3e6-4e25494cab43', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/wwhmpp/blockdevices/2/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/wwhmpp/'}
2019-03-18 05:14:54,593 [salt.state       :300 ][INFO    ][9578] {'new': {'storage_layout': 'lvm'}}
2019-03-18 05:14:54,594 [salt.state       :1951][INFO    ][9578] Completed state [maas_machines_storage_cmp001_lvm] at time 05:14:54.594198 duration_in_ms=2744.351
2019-03-18 05:14:54,598 [salt.minion      :1711][INFO    ][9578] Returning information for job: 20190318051444171110
2019-03-18 05:14:55,218 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318051455207924
2019-03-18 05:14:55,238 [salt.minion      :1432][INFO    ][9634] Starting a new job with PID 9634
2019-03-18 05:14:55,840 [salt.state       :915 ][INFO    ][9634] Loading fresh modules for state activity
2019-03-18 05:14:55,898 [salt.fileclient  :1219][INFO    ][9634] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-03-18 05:14:55,943 [salt.state       :1780][INFO    ][9634] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:55.943335
2019-03-18 05:14:55,943 [salt.state       :1813][INFO    ][9634] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:14:55,945 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9634] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:14:57,515 [salt.state       :300 ][INFO    ][9634] {'pid': 9649, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:14:57,515 [salt.state       :1951][INFO    ][9634] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:57.515856 duration_in_ms=1572.52
2019-03-18 05:14:57,518 [salt.state       :1780][INFO    ][9634] Running state [maas.deploy_machines] at time 05:14:57.518471
2019-03-18 05:14:57,519 [salt.state       :1813][INFO    ][9634] Executing state module.run for [maas.deploy_machines]
2019-03-18 05:14:57,519 [salt.utils.decorators:613 ][WARNING ][9634] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:14:58,218 [salt.loaded.ext.module.maas:684 ][INFO    ][9634] deploymachines hwe_kernel=hwe-16.04 system_id=dhmbhe distro_series=xenial
2019-03-18 05:15:00,801 [salt.loaded.ext.module.maas:684 ][INFO    ][9634] deploymachines hwe_kernel=hwe-16.04 system_id=wwhmpp distro_series=xenial
2019-03-18 05:15:03,654 [salt.loaded.ext.module.maas:684 ][INFO    ][9634] deploymachines hwe_kernel=hwe-16.04 system_id=pbx3hc distro_series=xenial
2019-03-18 05:15:06,081 [salt.loaded.ext.module.maas:684 ][INFO    ][9634] deploymachines hwe_kernel=hwe-16.04 system_id=syqpep distro_series=xenial
2019-03-18 05:15:08,443 [salt.loaded.ext.module.maas:684 ][INFO    ][9634] deploymachines hwe_kernel=hwe-16.04 system_id=fhf8cb distro_series=xenial
2019-03-18 05:15:10,337 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051510323679
2019-03-18 05:15:10,360 [salt.minion      :1432][INFO    ][9908] Starting a new job with PID 9908
2019-03-18 05:15:10,381 [salt.minion      :1711][INFO    ][9908] Returning information for job: 20190318051510323679
2019-03-18 05:15:11,210 [salt.state       :300 ][INFO    ][9634] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-03-18 05:15:11,211 [salt.state       :1951][INFO    ][9634] Completed state [maas.deploy_machines] at time 05:15:11.211447 duration_in_ms=13692.975
2019-03-18 05:15:11,215 [salt.minion      :1711][INFO    ][9634] Returning information for job: 20190318051455207924
2019-03-18 05:15:11,847 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318051511830814
2019-03-18 05:15:11,870 [salt.minion      :1432][INFO    ][9923] Starting a new job with PID 9923
2019-03-18 05:15:15,504 [salt.state       :915 ][INFO    ][9923] Loading fresh modules for state activity
2019-03-18 05:15:15,554 [salt.fileclient  :1219][INFO    ][9923] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-03-18 05:15:15,597 [salt.state       :1780][INFO    ][9923] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:15.597547
2019-03-18 05:15:15,597 [salt.state       :1813][INFO    ][9923] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:15:15,599 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9923] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:15:16,915 [salt.state       :300 ][INFO    ][9923] {'pid': 9937, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:15:16,916 [salt.state       :1951][INFO    ][9923] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:16.915986 duration_in_ms=1318.44
2019-03-18 05:15:16,918 [salt.state       :1780][INFO    ][9923] Running state [maas.wait_for_machine_status] at time 05:15:16.918381
2019-03-18 05:15:16,918 [salt.state       :1813][INFO    ][9923] Executing state module.run for [maas.wait_for_machine_status]
2019-03-18 05:15:16,919 [salt.utils.decorators:613 ][WARNING ][9923] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:15:20,427 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.50170183s left)
2019-03-18 05:15:26,898 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051526884709
2019-03-18 05:15:26,921 [salt.minion      :1432][INFO    ][9972] Starting a new job with PID 9972
2019-03-18 05:15:26,938 [salt.minion      :1711][INFO    ][9972] Returning information for job: 20190318051526884709
2019-03-18 05:15:54,017 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.91162586s left)
2019-03-18 05:15:56,937 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051556926593
2019-03-18 05:15:56,959 [salt.minion      :1432][INFO    ][10011] Starting a new job with PID 10011
2019-03-18 05:15:56,979 [salt.minion      :1711][INFO    ][10011] Returning information for job: 20190318051556926593
2019-03-18 05:16:27,019 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051627006682
2019-03-18 05:16:27,042 [salt.minion      :1432][INFO    ][10047] Starting a new job with PID 10047
2019-03-18 05:16:27,063 [salt.minion      :1711][INFO    ][10047] Returning information for job: 20190318051627006682
2019-03-18 05:16:27,449 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.48036504s left)
2019-03-18 05:16:57,064 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051657052565
2019-03-18 05:16:57,086 [salt.minion      :1432][INFO    ][10179] Starting a new job with PID 10179
2019-03-18 05:16:57,107 [salt.minion      :1711][INFO    ][10179] Returning information for job: 20190318051657052565
2019-03-18 05:17:00,192 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.73682785s left)
2019-03-18 05:17:27,113 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051727104925
2019-03-18 05:17:27,133 [salt.minion      :1432][INFO    ][10400] Starting a new job with PID 10400
2019-03-18 05:17:27,149 [salt.minion      :1711][INFO    ][10400] Returning information for job: 20190318051727104925
2019-03-18 05:17:33,234 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.69442296s left)
2019-03-18 05:17:57,161 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051757149564
2019-03-18 05:17:57,185 [salt.minion      :1432][INFO    ][10760] Starting a new job with PID 10760
2019-03-18 05:17:57,205 [salt.minion      :1711][INFO    ][10760] Returning information for job: 20190318051757149564
2019-03-18 05:18:05,833 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.09601593s left)
2019-03-18 05:18:27,215 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051827206680
2019-03-18 05:18:27,232 [salt.minion      :1432][INFO    ][10988] Starting a new job with PID 10988
2019-03-18 05:18:27,246 [salt.minion      :1711][INFO    ][10988] Returning information for job: 20190318051827206680
2019-03-18 05:18:39,204 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.72514987s left)
2019-03-18 05:18:57,256 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051857242729
2019-03-18 05:18:57,280 [salt.minion      :1432][INFO    ][11316] Starting a new job with PID 11316
2019-03-18 05:18:57,300 [salt.minion      :1711][INFO    ][11316] Returning information for job: 20190318051857242729
2019-03-18 05:19:12,212 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.71663499s left)
2019-03-18 05:19:27,310 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051927302759
2019-03-18 05:19:27,327 [salt.minion      :1432][INFO    ][11436] Starting a new job with PID 11436
2019-03-18 05:19:27,338 [salt.minion      :1711][INFO    ][11436] Returning information for job: 20190318051927302759
2019-03-18 05:19:45,887 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.0422399s left)
2019-03-18 05:19:57,357 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318051957344745
2019-03-18 05:19:57,382 [salt.minion      :1432][INFO    ][11611] Starting a new job with PID 11611
2019-03-18 05:19:57,404 [salt.minion      :1711][INFO    ][11611] Returning information for job: 20190318051957344745
2019-03-18 05:20:19,411 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.51794791s left)
2019-03-18 05:20:27,428 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052027418434
2019-03-18 05:20:27,448 [salt.minion      :1432][INFO    ][11752] Starting a new job with PID 11752
2019-03-18 05:20:27,463 [salt.minion      :1711][INFO    ][11752] Returning information for job: 20190318052027418434
2019-03-18 05:20:53,062 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.86733294s left)
2019-03-18 05:20:57,494 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052057481011
2019-03-18 05:20:57,519 [salt.minion      :1432][INFO    ][12019] Starting a new job with PID 12019
2019-03-18 05:20:57,542 [salt.minion      :1711][INFO    ][12019] Returning information for job: 20190318052057481011
2019-03-18 05:21:26,726 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.20239401s left)
2019-03-18 05:21:27,579 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052127567264
2019-03-18 05:21:27,602 [salt.minion      :1432][INFO    ][12061] Starting a new job with PID 12061
2019-03-18 05:21:27,622 [salt.minion      :1711][INFO    ][12061] Returning information for job: 20190318052127567264
2019-03-18 05:21:57,661 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052157649254
2019-03-18 05:21:57,686 [salt.minion      :1432][INFO    ][12131] Starting a new job with PID 12131
2019-03-18 05:21:57,707 [salt.minion      :1711][INFO    ][12131] Returning information for job: 20190318052157649254
2019-03-18 05:22:00,400 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.52893686s left)
2019-03-18 05:22:27,735 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052227725867
2019-03-18 05:22:27,750 [salt.minion      :1432][INFO    ][12407] Starting a new job with PID 12407
2019-03-18 05:22:27,761 [salt.minion      :1711][INFO    ][12407] Returning information for job: 20190318052227725867
2019-03-18 05:22:34,194 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1812.73518705s left)
2019-03-18 05:22:57,815 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052257801916
2019-03-18 05:22:57,839 [salt.minion      :1432][INFO    ][12617] Starting a new job with PID 12617
2019-03-18 05:22:57,861 [salt.minion      :1711][INFO    ][12617] Returning information for job: 20190318052257801916
2019-03-18 05:23:07,450 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1779.47870588s left)
2019-03-18 05:23:27,916 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052327906154
2019-03-18 05:23:27,939 [salt.minion      :1432][INFO    ][12740] Starting a new job with PID 12740
2019-03-18 05:23:27,956 [salt.minion      :1711][INFO    ][12740] Returning information for job: 20190318052327906154
2019-03-18 05:23:40,840 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1746.08887291s left)
2019-03-18 05:23:58,022 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052358009012
2019-03-18 05:23:58,048 [salt.minion      :1432][INFO    ][12821] Starting a new job with PID 12821
2019-03-18 05:23:58,067 [salt.minion      :1711][INFO    ][12821] Returning information for job: 20190318052358009012
2019-03-18 05:24:14,367 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1712.56173801s left)
2019-03-18 05:24:28,134 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052428121773
2019-03-18 05:24:28,154 [salt.minion      :1432][INFO    ][12861] Starting a new job with PID 12861
2019-03-18 05:24:28,165 [salt.minion      :1711][INFO    ][12861] Returning information for job: 20190318052428121773
2019-03-18 05:24:47,334 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1679.59461284s left)
2019-03-18 05:24:58,241 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052458228111
2019-03-18 05:24:58,266 [salt.minion      :1432][INFO    ][12895] Starting a new job with PID 12895
2019-03-18 05:24:58,286 [salt.minion      :1711][INFO    ][12895] Returning information for job: 20190318052458228111
2019-03-18 05:25:20,760 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1646.16890287s left)
2019-03-18 05:25:28,372 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052528359885
2019-03-18 05:25:28,398 [salt.minion      :1432][INFO    ][12934] Starting a new job with PID 12934
2019-03-18 05:25:28,420 [salt.minion      :1711][INFO    ][12934] Returning information for job: 20190318052528359885
2019-03-18 05:25:54,389 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1612.53963399s left)
2019-03-18 05:25:58,510 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052558496799
2019-03-18 05:25:58,534 [salt.minion      :1432][INFO    ][12970] Starting a new job with PID 12970
2019-03-18 05:25:58,556 [salt.minion      :1711][INFO    ][12970] Returning information for job: 20190318052558496799
2019-03-18 05:26:28,197 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1578.73211884s left)
2019-03-18 05:26:28,663 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052628649764
2019-03-18 05:26:28,687 [salt.minion      :1432][INFO    ][13015] Starting a new job with PID 13015
2019-03-18 05:26:28,709 [salt.minion      :1711][INFO    ][13015] Returning information for job: 20190318052628649764
2019-03-18 05:26:58,825 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052658812959
2019-03-18 05:26:58,850 [salt.minion      :1432][INFO    ][13054] Starting a new job with PID 13054
2019-03-18 05:26:58,871 [salt.minion      :1711][INFO    ][13054] Returning information for job: 20190318052658812959
2019-03-18 05:27:01,575 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1545.35407686s left)
2019-03-18 05:27:28,997 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052728984287
2019-03-18 05:27:29,022 [salt.minion      :1432][INFO    ][13092] Starting a new job with PID 13092
2019-03-18 05:27:29,045 [salt.minion      :1711][INFO    ][13092] Returning information for job: 20190318052728984287
2019-03-18 05:27:34,969 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1511.959692s left)
2019-03-18 05:27:59,174 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052759161925
2019-03-18 05:27:59,199 [salt.minion      :1432][INFO    ][13127] Starting a new job with PID 13127
2019-03-18 05:27:59,219 [salt.minion      :1711][INFO    ][13127] Returning information for job: 20190318052759161925
2019-03-18 05:28:08,533 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1478.39553595s left)
2019-03-18 05:28:29,361 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052829348111
2019-03-18 05:28:29,387 [salt.minion      :1432][INFO    ][13305] Starting a new job with PID 13305
2019-03-18 05:28:29,410 [salt.minion      :1711][INFO    ][13305] Returning information for job: 20190318052829348111
2019-03-18 05:28:42,056 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1444.87288594s left)
2019-03-18 05:28:59,563 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052859550714
2019-03-18 05:28:59,587 [salt.minion      :1432][INFO    ][13357] Starting a new job with PID 13357
2019-03-18 05:28:59,606 [salt.minion      :1711][INFO    ][13357] Returning information for job: 20190318052859550714
2019-03-18 05:29:15,690 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1411.23901701s left)
2019-03-18 05:29:29,769 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052929756369
2019-03-18 05:29:29,794 [salt.minion      :1432][INFO    ][13399] Starting a new job with PID 13399
2019-03-18 05:29:29,816 [salt.minion      :1711][INFO    ][13399] Returning information for job: 20190318052929756369
2019-03-18 05:29:48,856 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1378.07272196s left)
2019-03-18 05:29:59,989 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318052959976788
2019-03-18 05:30:00,013 [salt.minion      :1432][INFO    ][13435] Starting a new job with PID 13435
2019-03-18 05:30:00,033 [salt.minion      :1711][INFO    ][13435] Returning information for job: 20190318052959976788
2019-03-18 05:30:22,198 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1344.73041987s left)
2019-03-18 05:30:30,010 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053029997375
2019-03-18 05:30:30,035 [salt.minion      :1432][INFO    ][13477] Starting a new job with PID 13477
2019-03-18 05:30:30,058 [salt.minion      :1711][INFO    ][13477] Returning information for job: 20190318053029997375
2019-03-18 05:30:55,245 [salt.loaded.ext.module.maas:1023][INFO    ][9923] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1311.68417287s left)
2019-03-18 05:31:00,037 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053100024379
2019-03-18 05:31:00,061 [salt.minion      :1432][INFO    ][13511] Starting a new job with PID 13511
2019-03-18 05:31:00,082 [salt.minion      :1711][INFO    ][13511] Returning information for job: 20190318053100024379
2019-03-18 05:31:27,469 [salt.loaded.ext.module.maas:993 ][INFO    ][9923] Machine pbx3hc mark broken
2019-03-18 05:31:28,229 [salt.loaded.ext.module.maas:996 ][INFO    ][9923] Machine pbx3hc mark fixed
2019-03-18 05:31:29,450 [salt.loaded.ext.module.maas:684 ][INFO    ][9923] deploymachines hwe_kernel=hwe-16.04 system_id=pbx3hc distro_series=xenial
2019-03-18 05:31:30,083 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053130070058
2019-03-18 05:31:30,107 [salt.minion      :1432][INFO    ][13574] Starting a new job with PID 13574
2019-03-18 05:31:30,130 [salt.minion      :1711][INFO    ][13574] Returning information for job: 20190318053130070058
2019-03-18 05:31:32,122 [salt.loaded.ext.module.maas:160 ][ERROR   ][9923] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-03-18 05:31:32,123 [salt.state       :302 ][ERROR   ][9923] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-03-18 05:31:32,124 [salt.state       :1951][INFO    ][9923] Completed state [maas.wait_for_machine_status] at time 05:31:32.124124 duration_in_ms=975205.739
2019-03-18 05:31:32,130 [salt.minion      :1711][INFO    ][9923] Returning information for job: 20190318051511830814
2019-03-18 05:31:42,887 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command pillar.get with jid 20190318053142874809
2019-03-18 05:31:42,908 [salt.minion      :1432][INFO    ][13635] Starting a new job with PID 13635
2019-03-18 05:31:42,914 [salt.minion      :1711][INFO    ][13635] Returning information for job: 20190318053142874809
2019-03-18 05:31:43,411 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command service.status with jid 20190318053143398312
2019-03-18 05:31:43,434 [salt.minion      :1432][INFO    ][13640] Starting a new job with PID 13640
2019-03-18 05:31:43,814 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13640] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:43,846 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13640] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-03-18 05:31:43,861 [salt.minion      :1711][INFO    ][13640] Returning information for job: 20190318053143398312
2019-03-18 05:31:44,354 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318053144342130
2019-03-18 05:31:44,377 [salt.minion      :1432][INFO    ][13651] Starting a new job with PID 13651
2019-03-18 05:31:47,832 [salt.state       :915 ][INFO    ][13651] Loading fresh modules for state activity
2019-03-18 05:31:48,275 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'salt-minion --version' in directory '/root'
2019-03-18 05:31:48,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'salt-minion --version' in directory '/root'
2019-03-18 05:31:49,527 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'salt-minion --version' in directory '/root'
2019-03-18 05:31:49,902 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'salt-minion --version' in directory '/root'
2019-03-18 05:31:51,342 [salt.state       :1780][INFO    ][13651] Running state [salt-minion] at time 05:31:51.342850
2019-03-18 05:31:51,343 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [salt-minion]
2019-03-18 05:31:51,343 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-18 05:31:51,415 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,416 [salt.state       :1951][INFO    ][13651] Completed state [salt-minion] at time 05:31:51.416185 duration_in_ms=73.336
2019-03-18 05:31:51,416 [salt.state       :1780][INFO    ][13651] Running state [salt_minion_dependency_packages] at time 05:31:51.416428
2019-03-18 05:31:51,416 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-03-18 05:31:51,421 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,421 [salt.state       :1951][INFO    ][13651] Completed state [salt_minion_dependency_packages] at time 05:31:51.421314 duration_in_ms=4.885
2019-03-18 05:31:51,423 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/minion.d/minion.conf] at time 05:31:51.423584
2019-03-18 05:31:51,423 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-03-18 05:31:51,593 [salt.state       :300 ][INFO    ][13651] File /etc/salt/minion.d/minion.conf is in the correct state
2019-03-18 05:31:51,594 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/minion.d/minion.conf] at time 05:31:51.594069 duration_in_ms=170.485
2019-03-18 05:31:51,594 [salt.state       :1780][INFO    ][13651] Running state [python-netaddr] at time 05:31:51.594247
2019-03-18 05:31:51,594 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [python-netaddr]
2019-03-18 05:31:51,598 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,598 [salt.state       :1951][INFO    ][13651] Completed state [python-netaddr] at time 05:31:51.598904 duration_in_ms=4.656
2019-03-18 05:31:51,600 [salt.state       :1780][INFO    ][13651] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:31:51.600934
2019-03-18 05:31:51,601 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-03-18 05:31:51,610 [salt.state       :300 ][INFO    ][13651] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-03-18 05:31:51,610 [salt.state       :1951][INFO    ][13651] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:31:51.610455 duration_in_ms=9.52
2019-03-18 05:31:51,611 [salt.state       :1780][INFO    ][13651] Running state [salt-minion] at time 05:31:51.611104
2019-03-18 05:31:51,611 [salt.state       :1813][INFO    ][13651] Executing state service.running for [salt-minion]
2019-03-18 05:31:51,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:51,646 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-03-18 05:31:51,662 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-03-18 05:31:51,678 [salt.state       :300 ][INFO    ][13651] The service salt-minion is already running
2019-03-18 05:31:51,678 [salt.state       :1951][INFO    ][13651] Completed state [salt-minion] at time 05:31:51.678855 duration_in_ms=67.751
2019-03-18 05:31:51,680 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains.d] at time 05:31:51.679975
2019-03-18 05:31:51,680 [salt.state       :1813][INFO    ][13651] Executing state file.directory for [/etc/salt/grains.d]
2019-03-18 05:31:51,680 [salt.state       :300 ][INFO    ][13651] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-03-18 05:31:51,681 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains.d] at time 05:31:51.681101 duration_in_ms=1.126
2019-03-18 05:31:51,681 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains] at time 05:31:51.681597
2019-03-18 05:31:51,681 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/grains]
2019-03-18 05:31:51,682 [salt.state       :300 ][INFO    ][13651] File /etc/salt/grains exists with proper permissions. No changes made.
2019-03-18 05:31:51,682 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains] at time 05:31:51.682383 duration_in_ms=0.785
2019-03-18 05:31:51,682 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains.d/placeholder] at time 05:31:51.682739
2019-03-18 05:31:51,682 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-03-18 05:31:51,683 [salt.state       :300 ][INFO    ][13651] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-03-18 05:31:51,683 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains.d/placeholder] at time 05:31:51.683506 duration_in_ms=0.768
2019-03-18 05:31:51,683 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains.d/sphinx] at time 05:31:51.683852
2019-03-18 05:31:51,684 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-03-18 05:31:51,695 [salt.state       :300 ][INFO    ][13651] File /etc/salt/grains.d/sphinx is in the correct state
2019-03-18 05:31:51,695 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains.d/sphinx] at time 05:31:51.695689 duration_in_ms=11.836
2019-03-18 05:31:51,697 [salt.state       :1780][INFO    ][13651] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.697413
2019-03-18 05:31:51,697 [salt.state       :1813][INFO    ][13651] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-03-18 05:31:51,697 [salt.state       :300 ][INFO    ][13651] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-03-18 05:31:51,698 [salt.state       :1951][INFO    ][13651] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.698087 duration_in_ms=0.674
2019-03-18 05:31:51,698 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains.d/dns_records] at time 05:31:51.698451
2019-03-18 05:31:51,698 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-03-18 05:31:51,713 [salt.state       :300 ][INFO    ][13651] File /etc/salt/grains.d/dns_records is in the correct state
2019-03-18 05:31:51,713 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains.d/dns_records] at time 05:31:51.713699 duration_in_ms=15.248
2019-03-18 05:31:51,714 [salt.state       :1780][INFO    ][13651] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.714396
2019-03-18 05:31:51,714 [salt.state       :1813][INFO    ][13651] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-03-18 05:31:51,714 [salt.state       :300 ][INFO    ][13651] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-03-18 05:31:51,715 [salt.state       :1951][INFO    ][13651] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.715072 duration_in_ms=0.676
2019-03-18 05:31:51,715 [salt.state       :1780][INFO    ][13651] Running state [/etc/salt/grains.d/salt] at time 05:31:51.715438
2019-03-18 05:31:51,715 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-03-18 05:31:51,725 [salt.state       :300 ][INFO    ][13651] File /etc/salt/grains.d/salt is in the correct state
2019-03-18 05:31:51,725 [salt.state       :1951][INFO    ][13651] Completed state [/etc/salt/grains.d/salt] at time 05:31:51.725683 duration_in_ms=10.245
2019-03-18 05:31:51,726 [salt.state       :1780][INFO    ][13651] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.726349
2019-03-18 05:31:51,726 [salt.state       :1813][INFO    ][13651] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-03-18 05:31:51,726 [salt.state       :300 ][INFO    ][13651] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-03-18 05:31:51,727 [salt.state       :1951][INFO    ][13651] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:31:51.727031 duration_in_ms=0.682
2019-03-18 05:31:51,728 [salt.state       :1780][INFO    ][13651] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:31:51.728469
2019-03-18 05:31:51,728 [salt.state       :1813][INFO    ][13651] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-03-18 05:31:51,729 [salt.state       :300 ][INFO    ][13651] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-03-18 05:31:51,729 [salt.state       :1951][INFO    ][13651] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:31:51.729155 duration_in_ms=0.686
2019-03-18 05:31:51,729 [salt.state       :1780][INFO    ][13651] Running state [mine.update] at time 05:31:51.729675
2019-03-18 05:31:51,729 [salt.state       :1813][INFO    ][13651] Executing state module.wait for [mine.update]
2019-03-18 05:31:51,730 [salt.state       :300 ][INFO    ][13651] No changes made for mine.update
2019-03-18 05:31:51,730 [salt.state       :1951][INFO    ][13651] Completed state [mine.update] at time 05:31:51.730296 duration_in_ms=0.621
2019-03-18 05:31:51,730 [salt.state       :1780][INFO    ][13651] Running state [ca-certificates] at time 05:31:51.730501
2019-03-18 05:31:51,730 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [ca-certificates]
2019-03-18 05:31:51,736 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,736 [salt.state       :1951][INFO    ][13651] Completed state [ca-certificates] at time 05:31:51.736496 duration_in_ms=5.995
2019-03-18 05:31:51,737 [salt.state       :1780][INFO    ][13651] Running state [update-ca-certificates] at time 05:31:51.737053
2019-03-18 05:31:51,737 [salt.state       :1813][INFO    ][13651] Executing state cmd.wait for [update-ca-certificates]
2019-03-18 05:31:51,737 [salt.state       :300 ][INFO    ][13651] No changes made for update-ca-certificates
2019-03-18 05:31:51,737 [salt.state       :1951][INFO    ][13651] Completed state [update-ca-certificates] at time 05:31:51.737698 duration_in_ms=0.644
2019-03-18 05:31:51,737 [salt.state       :1780][INFO    ][13651] Running state [iptables] at time 05:31:51.737887
2019-03-18 05:31:51,738 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [iptables]
2019-03-18 05:31:51,743 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,743 [salt.state       :1951][INFO    ][13651] Completed state [iptables] at time 05:31:51.743410 duration_in_ms=5.523
2019-03-18 05:31:51,743 [salt.state       :1780][INFO    ][13651] Running state [iptables-persistent] at time 05:31:51.743615
2019-03-18 05:31:51,743 [salt.state       :1813][INFO    ][13651] Executing state pkg.installed for [iptables-persistent]
2019-03-18 05:31:51,748 [salt.state       :300 ][INFO    ][13651] All specified packages are already installed
2019-03-18 05:31:51,749 [salt.state       :1951][INFO    ][13651] Completed state [iptables-persistent] at time 05:31:51.749071 duration_in_ms=5.456
2019-03-18 05:31:51,749 [salt.state       :1780][INFO    ][13651] Running state [iptables_modules_v4_load] at time 05:31:51.749824
2019-03-18 05:31:51,750 [salt.state       :1813][INFO    ][13651] Executing state kmod.present for [iptables_modules_v4_load]
2019-03-18 05:31:51,750 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'lsmod' in directory '/root'
2019-03-18 05:31:51,772 [salt.state       :300 ][INFO    ][13651] Kernel modules iptable_filter, ip_tables are already present
2019-03-18 05:31:51,772 [salt.state       :1951][INFO    ][13651] Completed state [iptables_modules_v4_load] at time 05:31:51.772753 duration_in_ms=22.929
2019-03-18 05:31:51,773 [salt.state       :1780][INFO    ][13651] Running state [/etc/iptables/rules.v4] at time 05:31:51.773305
2019-03-18 05:31:51,773 [salt.state       :1813][INFO    ][13651] Executing state file.managed for [/etc/iptables/rules.v4]
2019-03-18 05:31:51,857 [salt.state       :300 ][INFO    ][13651] File /etc/iptables/rules.v4 is in the correct state
2019-03-18 05:31:51,857 [salt.state       :1951][INFO    ][13651] Completed state [/etc/iptables/rules.v4] at time 05:31:51.857693 duration_in_ms=84.388
2019-03-18 05:31:51,858 [salt.state       :1780][INFO    ][13651] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:31:51.858541
2019-03-18 05:31:51,858 [salt.state       :1813][INFO    ][13651] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-03-18 05:31:51,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-03-18 05:31:51,877 [salt.state       :300 ][INFO    ][13651] onlyif execution failed
2019-03-18 05:31:51,878 [salt.state       :1951][INFO    ][13651] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:31:51.878332 duration_in_ms=19.79
2019-03-18 05:31:51,880 [salt.state       :1780][INFO    ][13651] Running state [netfilter-persistent] at time 05:31:51.880002
2019-03-18 05:31:51,880 [salt.state       :1813][INFO    ][13651] Executing state service.running for [netfilter-persistent]
2019-03-18 05:31:51,881 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:51,902 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-03-18 05:31:51,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-03-18 05:31:51,938 [salt.state       :300 ][INFO    ][13651] The service netfilter-persistent is already running
2019-03-18 05:31:51,938 [salt.state       :1951][INFO    ][13651] Completed state [netfilter-persistent] at time 05:31:51.938688 duration_in_ms=58.686
2019-03-18 05:31:51,940 [salt.state       :1780][INFO    ][13651] Running state [iptables_extra.remove_stale_tables] at time 05:31:51.940007
2019-03-18 05:31:51,940 [salt.state       :1813][INFO    ][13651] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-03-18 05:31:51,941 [salt.state       :300 ][INFO    ][13651] No changes made for iptables_extra.remove_stale_tables
2019-03-18 05:31:51,941 [salt.state       :1951][INFO    ][13651] Completed state [iptables_extra.remove_stale_tables] at time 05:31:51.941349 duration_in_ms=1.342
2019-03-18 05:31:51,941 [salt.state       :1780][INFO    ][13651] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:31:51.941746
2019-03-18 05:31:51,942 [salt.state       :1813][INFO    ][13651] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-03-18 05:31:51,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13651] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-03-18 05:31:51,958 [salt.state       :300 ][INFO    ][13651] onlyif execution failed
2019-03-18 05:31:51,958 [salt.state       :1951][INFO    ][13651] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:31:51.958666 duration_in_ms=16.92
2019-03-18 05:31:51,960 [salt.state       :1780][INFO    ][13651] Running state [/etc/iptables/rules.v6] at time 05:31:51.960080
2019-03-18 05:31:51,960 [salt.state       :1813][INFO    ][13651] Executing state file.absent for [/etc/iptables/rules.v6]
2019-03-18 05:31:51,961 [salt.state       :300 ][INFO    ][13651] File /etc/iptables/rules.v6 is not present
2019-03-18 05:31:51,961 [salt.state       :1951][INFO    ][13651] Completed state [/etc/iptables/rules.v6] at time 05:31:51.961566 duration_in_ms=1.486
2019-03-18 05:31:51,962 [salt.state       :1780][INFO    ][13651] Running state [iptables_extra.flush_all] at time 05:31:51.962568
2019-03-18 05:31:51,963 [salt.state       :1813][INFO    ][13651] Executing state module.wait for [iptables_extra.flush_all]
2019-03-18 05:31:51,963 [salt.state       :300 ][INFO    ][13651] No changes made for iptables_extra.flush_all
2019-03-18 05:31:51,963 [salt.state       :1951][INFO    ][13651] Completed state [iptables_extra.flush_all] at time 05:31:51.963695 duration_in_ms=1.127
2019-03-18 05:31:51,968 [salt.minion      :1711][INFO    ][13651] Returning information for job: 20190318053144342130
2019-03-18 05:31:52,611 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318053152598905
2019-03-18 05:31:52,635 [salt.minion      :1432][INFO    ][13730] Starting a new job with PID 13730
2019-03-18 05:31:53,243 [salt.state       :915 ][INFO    ][13730] Loading fresh modules for state activity
2019-03-18 05:31:53,830 [salt.state       :1780][INFO    ][13730] Running state [maas-rack-controller] at time 05:31:53.830813
2019-03-18 05:31:53,831 [salt.state       :1813][INFO    ][13730] Executing state pkg.installed for [maas-rack-controller]
2019-03-18 05:31:53,831 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13730] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-18 05:31:53,973 [salt.state       :300 ][INFO    ][13730] All specified packages are already installed
2019-03-18 05:31:53,973 [salt.state       :1951][INFO    ][13730] Completed state [maas-rack-controller] at time 05:31:53.973904 duration_in_ms=143.091
2019-03-18 05:31:53,974 [salt.state       :1780][INFO    ][13730] Running state [ipmitool] at time 05:31:53.974186
2019-03-18 05:31:53,974 [salt.state       :1813][INFO    ][13730] Executing state pkg.installed for [ipmitool]
2019-03-18 05:31:53,980 [salt.state       :300 ][INFO    ][13730] All specified packages are already installed
2019-03-18 05:31:53,980 [salt.state       :1951][INFO    ][13730] Completed state [ipmitool] at time 05:31:53.980290 duration_in_ms=6.104
2019-03-18 05:31:53,982 [salt.state       :1780][INFO    ][13730] Running state [/etc/maas/rackd.conf] at time 05:31:53.982633
2019-03-18 05:31:53,982 [salt.state       :1813][INFO    ][13730] Executing state file.line for [/etc/maas/rackd.conf]
2019-03-18 05:31:53,983 [salt.state       :300 ][INFO    ][13730] No changes needed to be made
2019-03-18 05:31:53,983 [salt.state       :1951][INFO    ][13730] Completed state [/etc/maas/rackd.conf] at time 05:31:53.983955 duration_in_ms=1.322
2019-03-18 05:31:53,984 [salt.state       :1780][INFO    ][13730] Running state [/etc/maas/rackd.conf] at time 05:31:53.984157
2019-03-18 05:31:53,984 [salt.state       :1813][INFO    ][13730] Executing state file.managed for [/etc/maas/rackd.conf]
2019-03-18 05:31:53,984 [salt.loaded.int.states.file:2298][WARNING ][13730] 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-03-18 05:31:53,985 [salt.state       :300 ][INFO    ][13730] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-03-18 05:31:53,985 [salt.state       :1951][INFO    ][13730] Completed state [/etc/maas/rackd.conf] at time 05:31:53.985232 duration_in_ms=1.075
2019-03-18 05:31:53,986 [salt.state       :1780][INFO    ][13730] Running state [maas-rackd] at time 05:31:53.986064
2019-03-18 05:31:53,986 [salt.state       :1813][INFO    ][13730] Executing state service.running for [maas-rackd]
2019-03-18 05:31:53,986 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13730] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:54,022 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13730] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-03-18 05:31:54,040 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13730] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-03-18 05:31:54,056 [salt.state       :300 ][INFO    ][13730] The service maas-rackd is already running
2019-03-18 05:31:54,057 [salt.state       :1951][INFO    ][13730] Completed state [maas-rackd] at time 05:31:54.057216 duration_in_ms=71.151
2019-03-18 05:31:54,059 [salt.minion      :1711][INFO    ][13730] Returning information for job: 20190318053152598905
2019-03-18 05:31:54,643 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318053154629583
2019-03-18 05:31:54,668 [salt.minion      :1432][INFO    ][13754] Starting a new job with PID 13754
2019-03-18 05:31:55,272 [salt.state       :915 ][INFO    ][13754] Loading fresh modules for state activity
2019-03-18 05:31:55,833 [salt.state       :1780][INFO    ][13754] Running state [maas-region-controller] at time 05:31:55.833132
2019-03-18 05:31:55,833 [salt.state       :1813][INFO    ][13754] Executing state pkg.installed for [maas-region-controller]
2019-03-18 05:31:55,833 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-18 05:31:55,935 [salt.state       :300 ][INFO    ][13754] All specified packages are already installed
2019-03-18 05:31:55,936 [salt.state       :1951][INFO    ][13754] Completed state [maas-region-controller] at time 05:31:55.936023 duration_in_ms=102.891
2019-03-18 05:31:55,936 [salt.state       :1780][INFO    ][13754] Running state [python-oauth] at time 05:31:55.936409
2019-03-18 05:31:55,936 [salt.state       :1813][INFO    ][13754] Executing state pkg.installed for [python-oauth]
2019-03-18 05:31:55,946 [salt.state       :300 ][INFO    ][13754] All specified packages are already installed
2019-03-18 05:31:55,947 [salt.state       :1951][INFO    ][13754] Completed state [python-oauth] at time 05:31:55.946981 duration_in_ms=10.572
2019-03-18 05:31:55,950 [salt.state       :1780][INFO    ][13754] Running state [/etc/maas/regiond.conf] at time 05:31:55.950336
2019-03-18 05:31:55,950 [salt.state       :1813][INFO    ][13754] Executing state file.replace for [/etc/maas/regiond.conf]
2019-03-18 05:31:56,002 [salt.state       :300 ][INFO    ][13754] No changes needed to be made
2019-03-18 05:31:56,002 [salt.state       :1951][INFO    ][13754] Completed state [/etc/maas/regiond.conf] at time 05:31:56.002723 duration_in_ms=52.387
2019-03-18 05:31:56,003 [salt.state       :1780][INFO    ][13754] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:31:56.003384
2019-03-18 05:31:56,003 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-03-18 05:31:56,079 [salt.state       :300 ][INFO    ][13754] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-03-18 05:31:56,079 [salt.state       :1951][INFO    ][13754] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:31:56.079679 duration_in_ms=76.296
2019-03-18 05:31:56,080 [salt.state       :1780][INFO    ][13754] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:56.080266
2019-03-18 05:31:56,080 [salt.state       :1813][INFO    ][13754] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-18 05:31:56,092 [salt.state       :300 ][INFO    ][13754] No changes needed to be made
2019-03-18 05:31:56,093 [salt.state       :1951][INFO    ][13754] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:56.093185 duration_in_ms=12.919
2019-03-18 05:31:56,093 [salt.state       :1780][INFO    ][13754] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:56.093777
2019-03-18 05:31:56,094 [salt.state       :1813][INFO    ][13754] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-18 05:31:56,122 [salt.state       :300 ][INFO    ][13754] No changes needed to be made
2019-03-18 05:31:56,123 [salt.state       :1951][INFO    ][13754] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:31:56.123103 duration_in_ms=29.325
2019-03-18 05:31:56,123 [salt.state       :1780][INFO    ][13754] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:31:56.123684
2019-03-18 05:31:56,124 [salt.state       :1813][INFO    ][13754] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-03-18 05:31:56,151 [salt.state       :300 ][INFO    ][13754] No changes needed to be made
2019-03-18 05:31:56,151 [salt.state       :1951][INFO    ][13754] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:31:56.151377 duration_in_ms=27.693
2019-03-18 05:31:56,151 [salt.state       :1780][INFO    ][13754] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:31:56.151919
2019-03-18 05:31:56,152 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-03-18 05:31:56,163 [salt.state       :300 ][INFO    ][13754] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-03-18 05:31:56,164 [salt.state       :1951][INFO    ][13754] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:31:56.164213 duration_in_ms=12.293
2019-03-18 05:31:56,165 [salt.state       :1780][INFO    ][13754] Running state [a2enmod headers] at time 05:31:56.165549
2019-03-18 05:31:56,165 [salt.state       :1813][INFO    ][13754] Executing state cmd.run for [a2enmod headers]
2019-03-18 05:31:56,166 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command 'a2enmod headers' in directory '/root'
2019-03-18 05:31:56,214 [salt.state       :300 ][INFO    ][13754] {'pid': 13789, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-03-18 05:31:56,215 [salt.state       :1951][INFO    ][13754] Completed state [a2enmod headers] at time 05:31:56.215165 duration_in_ms=49.616
2019-03-18 05:31:56,215 [salt.state       :1780][INFO    ][13754] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:31:56.215460
2019-03-18 05:31:56,215 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-03-18 05:31:56,227 [salt.state       :300 ][INFO    ][13754] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-03-18 05:31:56,227 [salt.state       :1951][INFO    ][13754] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:31:56.227852 duration_in_ms=12.392
2019-03-18 05:31:56,228 [salt.state       :1780][INFO    ][13754] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:31:56.228256
2019-03-18 05:31:56,228 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-03-18 05:31:56,289 [salt.state       :300 ][INFO    ][13754] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-03-18 05:31:56,289 [salt.state       :1951][INFO    ][13754] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:31:56.289429 duration_in_ms=61.171
2019-03-18 05:31:56,290 [salt.state       :1780][INFO    ][13754] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:31:56.290072
2019-03-18 05:31:56,290 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-03-18 05:31:56,354 [salt.state       :300 ][INFO    ][13754] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-03-18 05:31:56,355 [salt.state       :1951][INFO    ][13754] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:31:56.355195 duration_in_ms=65.122
2019-03-18 05:31:56,355 [salt.state       :1780][INFO    ][13754] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:31:56.355773
2019-03-18 05:31:56,356 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-03-18 05:31:56,420 [salt.state       :300 ][INFO    ][13754] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-03-18 05:31:56,420 [salt.state       :1951][INFO    ][13754] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:31:56.420866 duration_in_ms=65.093
2019-03-18 05:31:56,421 [salt.state       :1780][INFO    ][13754] Running state [/root/.pgpass] at time 05:31:56.421152
2019-03-18 05:31:56,421 [salt.state       :1813][INFO    ][13754] Executing state file.managed for [/root/.pgpass]
2019-03-18 05:31:56,468 [salt.state       :300 ][INFO    ][13754] File /root/.pgpass is in the correct state
2019-03-18 05:31:56,468 [salt.state       :1951][INFO    ][13754] Completed state [/root/.pgpass] at time 05:31:56.468802 duration_in_ms=47.649
2019-03-18 05:31:56,472 [salt.state       :1780][INFO    ][13754] Running state [maas-region syncdb --noinput] at time 05:31:56.472720
2019-03-18 05:31:56,473 [salt.state       :1813][INFO    ][13754] Executing state cmd.run for [maas-region syncdb --noinput]
2019-03-18 05:31:56,473 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-03-18 05:31:58,130 [salt.state       :300 ][INFO    ][13754] {'pid': 13805, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: auth, sessions, maasserver, sites, contenttypes, piston3, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-03-18 05:31:58,130 [salt.state       :1951][INFO    ][13754] Completed state [maas-region syncdb --noinput] at time 05:31:58.130661 duration_in_ms=1657.942
2019-03-18 05:31:58,130 [salt.state       :2022][WARNING ][13754] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-18 05:31:58,131 [salt.state       :1780][INFO    ][13754] Running state [maas-regiond] at time 05:31:58.131828
2019-03-18 05:31:58,132 [salt.state       :1813][INFO    ][13754] Executing state service.running for [maas-regiond]
2019-03-18 05:31:58,134 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:58,169 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-03-18 05:31:58,187 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-03-18 05:31:58,204 [salt.state       :300 ][INFO    ][13754] The service maas-regiond is already running
2019-03-18 05:31:58,205 [salt.state       :1951][INFO    ][13754] Completed state [maas-regiond] at time 05:31:58.205287 duration_in_ms=73.457
2019-03-18 05:31:58,208 [salt.state       :1780][INFO    ][13754] Running state [bind9] at time 05:31:58.208389
2019-03-18 05:31:58,209 [salt.state       :1813][INFO    ][13754] Executing state service.running for [bind9]
2019-03-18 05:31:58,210 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:58,225 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-03-18 05:31:58,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-03-18 05:31:58,251 [salt.state       :300 ][INFO    ][13754] The service bind9 is already running
2019-03-18 05:31:58,251 [salt.state       :1951][INFO    ][13754] Completed state [bind9] at time 05:31:58.251563 duration_in_ms=43.175
2019-03-18 05:31:58,252 [salt.state       :1780][INFO    ][13754] Running state [apache2] at time 05:31:58.252662
2019-03-18 05:31:58,252 [salt.state       :1813][INFO    ][13754] Executing state service.running for [apache2]
2019-03-18 05:31:58,253 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-03-18 05:31:58,266 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-03-18 05:31:58,277 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-03-18 05:31:58,292 [salt.state       :300 ][INFO    ][13754] The service apache2 is already running
2019-03-18 05:31:58,292 [salt.state       :1951][INFO    ][13754] Completed state [apache2] at time 05:31:58.292361 duration_in_ms=39.698
2019-03-18 05:31:58,294 [salt.state       :1780][INFO    ][13754] Running state [maasng.wait_for_http_code] at time 05:31:58.294055
2019-03-18 05:31:58,294 [salt.state       :1813][INFO    ][13754] Executing state module.run for [maasng.wait_for_http_code]
2019-03-18 05:31:58,294 [salt.utils.decorators:613 ][WARNING ][13754] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:31:58,396 [salt.state       :300 ][INFO    ][13754] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-03-18 05:31:58,396 [salt.state       :1951][INFO    ][13754] Completed state [maasng.wait_for_http_code] at time 05:31:58.396733 duration_in_ms=102.675
2019-03-18 05:31:58,398 [salt.state       :1780][INFO    ][13754] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:31:58.398133
2019-03-18 05:31:58,398 [salt.state       :1813][INFO    ][13754] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-03-18 05:31:58,399 [salt.state       :300 ][INFO    ][13754] /var/lib/maas/.setup_admin exists
2019-03-18 05:31:58,399 [salt.state       :1951][INFO    ][13754] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:31:58.399816 duration_in_ms=1.683
2019-03-18 05:31:58,401 [salt.state       :1780][INFO    ][13754] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:58.400971
2019-03-18 05:31:58,401 [salt.state       :1813][INFO    ][13754] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:31:58,402 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13754] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:31:59,842 [salt.state       :300 ][INFO    ][13754] {'pid': 13826, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:31:59,843 [salt.state       :1951][INFO    ][13754] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:59.843099 duration_in_ms=1442.127
2019-03-18 05:31:59,855 [salt.state       :1780][INFO    ][13754] Running state [maas_region_boot_source_resources_mirror] at time 05:31:59.855160
2019-03-18 05:31:59,855 [salt.state       :1813][INFO    ][13754] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-03-18 05:31:59,965 [salt.state       :300 ][INFO    ][13754] {'changes': {}}
2019-03-18 05:31:59,966 [salt.state       :1951][INFO    ][13754] Completed state [maas_region_boot_source_resources_mirror] at time 05:31:59.966112 duration_in_ms=110.95
2019-03-18 05:31:59,967 [salt.state       :1780][INFO    ][13754] Running state [maasng.boot_resources_import] at time 05:31:59.967351
2019-03-18 05:31:59,967 [salt.state       :1813][INFO    ][13754] Executing state module.run for [maasng.boot_resources_import]
2019-03-18 05:31:59,968 [salt.utils.decorators:613 ][WARNING ][13754] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:32:00,098 [salt.loaded.ext.module.maasng:1600][INFO    ][13754] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-03-18 05:32:05,180 [salt.loaded.ext.module.maasng:1600][INFO    ][13754] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-03-18 05:32:09,660 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053209647940
2019-03-18 05:32:09,684 [salt.minion      :1432][INFO    ][13854] Starting a new job with PID 13854
2019-03-18 05:32:09,708 [salt.minion      :1711][INFO    ][13854] Returning information for job: 20190318053209647940
2019-03-18 05:32:10,243 [salt.loaded.ext.module.maasng:1600][INFO    ][13754] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-03-18 05:32:15,357 [salt.state       :300 ][INFO    ][13754] {'ret': True}
2019-03-18 05:32:15,358 [salt.state       :1951][INFO    ][13754] Completed state [maasng.boot_resources_import] at time 05:32:15.357959 duration_in_ms=15390.607
2019-03-18 05:32:15,359 [salt.state       :1780][INFO    ][13754] Running state [maas_region_boot_sources_selection_xenial] at time 05:32:15.359183
2019-03-18 05:32:15,359 [salt.state       :1813][INFO    ][13754] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-03-18 05:32:15,584 [salt.state       :300 ][INFO    ][13754] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-03-18 05:32:15,585 [salt.state       :1951][INFO    ][13754] Completed state [maas_region_boot_sources_selection_xenial] at time 05:32:15.584928 duration_in_ms=225.745
2019-03-18 05:32:15,586 [salt.state       :1780][INFO    ][13754] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:32:15.586094
2019-03-18 05:32:15,586 [salt.state       :1813][INFO    ][13754] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-03-18 05:32:15,587 [salt.utils.decorators:613 ][WARNING ][13754] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:32:15,587 [salt.loaded.ext.module.maasng:1771][INFO    ][13754] boot-sources sync initiated for ALL Rack's
2019-03-18 05:32:16,650 [salt.state       :300 ][INFO    ][13754] {'ret': True}
2019-03-18 05:32:16,650 [salt.state       :1951][INFO    ][13754] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:32:16.650819 duration_in_ms=1064.724
2019-03-18 05:32:16,653 [salt.state       :1780][INFO    ][13754] Running state [maas.process_maas_config] at time 05:32:16.652947
2019-03-18 05:32:16,653 [salt.state       :1813][INFO    ][13754] Executing state module.run for [maas.process_maas_config]
2019-03-18 05:32:16,654 [salt.utils.decorators:613 ][WARNING ][13754] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:32:16,654 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=enable_http_proxy value=True
2019-03-18 05:32:16,718 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=upstream_dns value=8.8.8.8
2019-03-18 05:32:16,788 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=commissioning_distro_series value=xenial
2019-03-18 05:32:19,782 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=default_osystem value=ubuntu
2019-03-18 05:32:19,842 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=active_discovery_interval value=600
2019-03-18 05:32:19,897 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=dnssec_validation value=no
2019-03-18 05:32:19,962 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=maas_name value=mas01
2019-03-18 05:32:20,031 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=network_discovery value=enabled
2019-03-18 05:32:20,162 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=enable_third_party_drivers value=True
2019-03-18 05:32:20,253 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=default_storage_layout value=lvm
2019-03-18 05:32:20,309 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=ntp_external_only value=True
2019-03-18 05:32:20,378 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=disk_erase_with_secure_erase value=False
2019-03-18 05:32:20,435 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=default_distro_series value=xenial
2019-03-18 05:32:20,508 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-03-18 05:32:20,633 [salt.state       :300 ][INFO    ][13754] {'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-03-18 05:32:20,634 [salt.state       :1951][INFO    ][13754] Completed state [maas.process_maas_config] at time 05:32:20.633958 duration_in_ms=3981.01
2019-03-18 05:32:20,634 [salt.state       :1780][INFO    ][13754] Running state [pxe_admin] at time 05:32:20.634908
2019-03-18 05:32:20,635 [salt.state       :1813][INFO    ][13754] Executing state maasng.fabric_present for [pxe_admin]
2019-03-18 05:32:20,697 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ytbh83', 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/'}]
2019-03-18 05:32:20,770 [salt.loaded.ext.module.maasng:1008][WARNING ][13754] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-03-18 05:32:20,770 [salt.loaded.ext.module.maasng:1011][WARNING ][13754] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-03-18 05:32:20,849 [salt.state       :300 ][INFO    ][13754] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-03-18 05:32:20,850 [salt.state       :1951][INFO    ][13754] Completed state [pxe_admin] at time 05:32:20.850186 duration_in_ms=215.277
2019-03-18 05:32:20,850 [salt.state       :1780][INFO    ][13754] Running state [vlan 0] at time 05:32:20.850681
2019-03-18 05:32:20,851 [salt.state       :1813][INFO    ][13754] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-18 05:32:20,920 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/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'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'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/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'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'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ytbh83', 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'id': 2}]
2019-03-18 05:32:21,021 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'id': 1, u'name': u'fabric-1'}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ytbh83', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'name': u'pxe_admin'}]
2019-03-18 05:32:21,273 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-03-18 05:32:21,345 [salt.state       :300 ][INFO    ][13754] {'new': 'Vlan untagged was updated'}
2019-03-18 05:32:21,346 [salt.state       :1951][INFO    ][13754] Completed state [vlan 0] at time 05:32:21.346335 duration_in_ms=495.653
2019-03-18 05:32:21,348 [salt.state       :1780][INFO    ][13754] Running state [192.168.11.0/24] at time 05:32:21.347936
2019-03-18 05:32:21,348 [salt.state       :1813][INFO    ][13754] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-03-18 05:32:21,572 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-03-18 05:32:21,573 [salt.loaded.ext.module.maasng:1235][WARNING ][13754] Ignoring parameter vlan:0
2019-03-18 05:32:21,645 [salt.state       :300 ][INFO    ][13754] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-03-18 05:32:21,646 [salt.state       :1951][INFO    ][13754] Completed state [192.168.11.0/24] at time 05:32:21.646218 duration_in_ms=298.282
2019-03-18 05:32:21,647 [salt.state       :1780][INFO    ][13754] Running state [maas_create_iprange_1] at time 05:32:21.647924
2019-03-18 05:32:21,648 [salt.state       :1813][INFO    ][13754] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-03-18 05:32:21,704 [salt.state       :300 ][INFO    ][13754] Iprange maas_create_iprange_1 already exist.
2019-03-18 05:32:21,704 [salt.state       :1951][INFO    ][13754] Completed state [maas_create_iprange_1] at time 05:32:21.704711 duration_in_ms=56.787
2019-03-18 05:32:21,705 [salt.state       :1780][INFO    ][13754] Running state [vlan 0] at time 05:32:21.705043
2019-03-18 05:32:21,705 [salt.state       :1813][INFO    ][13754] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-18 05:32:21,770 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ytbh83', 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/'}]
2019-03-18 05:32:21,871 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-03-18 05:32:22,153 [salt.loaded.ext.module.maasng:945 ][INFO    ][13754] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ytbh83', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-03-18 05:32:22,256 [salt.state       :300 ][INFO    ][13754] {'new': 'Vlan untagged was updated'}
2019-03-18 05:32:22,256 [salt.state       :1951][INFO    ][13754] Completed state [vlan 0] at time 05:32:22.256791 duration_in_ms=551.747
2019-03-18 05:32:22,257 [salt.state       :1780][INFO    ][13754] Running state [opnfv] at time 05:32:22.257689
2019-03-18 05:32:22,258 [salt.state       :1813][INFO    ][13754] Executing state maasng.sshkey_present for [opnfv]
2019-03-18 05:32:22,309 [salt.loaded.ext.module.maasng:1903][INFO    ][13754] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-03-18 05:32:22,310 [salt.state       :300 ][INFO    ][13754] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-03-18 05:32:22,310 [salt.state       :1951][INFO    ][13754] Completed state [opnfv] at time 05:32:22.310375 duration_in_ms=52.686
2019-03-18 05:32:22,311 [salt.state       :1780][INFO    ][13754] Running state [maas.process_tags] at time 05:32:22.311247
2019-03-18 05:32:22,311 [salt.state       :1813][INFO    ][13754] Executing state module.run for [maas.process_tags]
2019-03-18 05:32:22,312 [salt.utils.decorators:613 ][WARNING ][13754] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:32:22,357 [salt.loaded.ext.module.maas:92  ][INFO    ][13754] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-03-18 05:32:22,423 [salt.state       :300 ][INFO    ][13754] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-03-18 05:32:22,423 [salt.state       :1951][INFO    ][13754] Completed state [maas.process_tags] at time 05:32:22.423905 duration_in_ms=112.657
2019-03-18 05:32:22,429 [salt.minion      :1711][INFO    ][13754] Returning information for job: 20190318053154629583
2019-03-18 05:32:23,036 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318053223024224
2019-03-18 05:32:23,056 [salt.minion      :1432][INFO    ][14224] Starting a new job with PID 14224
2019-03-18 05:32:26,614 [salt.state       :915 ][INFO    ][14224] Loading fresh modules for state activity
2019-03-18 05:32:26,702 [salt.state       :1780][INFO    ][14224] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:32:26.702680
2019-03-18 05:32:26,703 [salt.state       :1813][INFO    ][14224] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:32:26,704 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14224] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:32:28,107 [salt.state       :300 ][INFO    ][14224] {'pid': 14254, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:32:28,108 [salt.state       :1951][INFO    ][14224] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:32:28.107868 duration_in_ms=1405.189
2019-03-18 05:32:28,110 [salt.state       :1780][INFO    ][14224] Running state [maas.process_machines] at time 05:32:28.110262
2019-03-18 05:32:28,110 [salt.state       :1813][INFO    ][14224] Executing state module.run for [maas.process_machines]
2019-03-18 05:32:28,112 [salt.utils.decorators:613 ][WARNING ][14224] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:32:28,741 [salt.loaded.ext.module.maas:412 ][WARNING ][14224] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:32:28,742 [salt.loaded.ext.module.maas:92  ][INFO    ][14224] 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=dhmbhe architecture=amd64/generic power_parameters_power_user=admin
2019-03-18 05:32:30,030 [salt.loaded.ext.module.maas:412 ][WARNING ][14224] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:32:30,031 [salt.loaded.ext.module.maas:92  ][INFO    ][14224] 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=wwhmpp architecture=amd64/generic power_parameters_power_user=admin
2019-03-18 05:32:31,202 [salt.loaded.ext.module.maas:412 ][WARNING ][14224] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:32:31,203 [salt.loaded.ext.module.maas:92  ][INFO    ][14224] 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=pbx3hc architecture=amd64/generic power_parameters_power_user=admin
2019-03-18 05:32:32,479 [salt.loaded.ext.module.maas:412 ][WARNING ][14224] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:32:32,480 [salt.loaded.ext.module.maas:92  ][INFO    ][14224] 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=syqpep architecture=amd64/generic power_parameters_power_user=admin
2019-03-18 05:32:33,605 [salt.loaded.ext.module.maas:412 ][WARNING ][14224] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-18 05:32:33,606 [salt.loaded.ext.module.maas:92  ][INFO    ][14224] 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=fhf8cb architecture=amd64/generic power_parameters_power_user=admin
2019-03-18 05:32:34,856 [salt.state       :300 ][INFO    ][14224] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-03-18 05:32:34,857 [salt.state       :1951][INFO    ][14224] Completed state [maas.process_machines] at time 05:32:34.857183 duration_in_ms=6746.92
2019-03-18 05:32:34,861 [salt.minion      :1711][INFO    ][14224] Returning information for job: 20190318053223024224
2019-03-18 05:33:08,119 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318053308106039
2019-03-18 05:33:08,142 [salt.minion      :1432][INFO    ][14507] Starting a new job with PID 14507
2019-03-18 05:33:11,651 [salt.state       :915 ][INFO    ][14507] Loading fresh modules for state activity
2019-03-18 05:33:11,742 [salt.state       :1780][INFO    ][14507] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:33:11.742365
2019-03-18 05:33:11,742 [salt.state       :1813][INFO    ][14507] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:33:11,744 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14507] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:33:13,138 [salt.state       :300 ][INFO    ][14507] {'pid': 14514, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:33:13,139 [salt.state       :1951][INFO    ][14507] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:33:13.139120 duration_in_ms=1396.756
2019-03-18 05:33:13,140 [salt.state       :1780][INFO    ][14507] Running state [maas.wait_for_machine_status] at time 05:33:13.140632
2019-03-18 05:33:13,140 [salt.state       :1813][INFO    ][14507] Executing state module.run for [maas.wait_for_machine_status]
2019-03-18 05:33:13,141 [salt.utils.decorators:613 ][WARNING ][14507] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:33:15,117 [salt.loaded.ext.module.maas:993 ][INFO    ][14507] Machine pbx3hc mark broken
2019-03-18 05:33:15,730 [salt.loaded.ext.module.maas:996 ][INFO    ][14507] Machine pbx3hc mark fixed
2019-03-18 05:33:16,728 [salt.loaded.ext.module.maas:684 ][INFO    ][14507] deploymachines hwe_kernel=hwe-16.04 system_id=pbx3hc distro_series=xenial
2019-03-18 05:33:20,735 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.41052699s left)
2019-03-18 05:33:23,165 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053323149745
2019-03-18 05:33:23,189 [salt.minion      :1432][INFO    ][14594] Starting a new job with PID 14594
2019-03-18 05:33:23,210 [salt.minion      :1711][INFO    ][14594] Returning information for job: 20190318053323149745
2019-03-18 05:33:53,218 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053353203381
2019-03-18 05:33:53,243 [salt.minion      :1432][INFO    ][14626] Starting a new job with PID 14626
2019-03-18 05:33:53,263 [salt.minion      :1711][INFO    ][14626] Returning information for job: 20190318053353203381
2019-03-18 05:33:54,180 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1458.96528792s left)
2019-03-18 05:34:23,474 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053423416886
2019-03-18 05:34:23,498 [salt.minion      :1432][INFO    ][14669] Starting a new job with PID 14669
2019-03-18 05:34:23,521 [salt.minion      :1711][INFO    ][14669] Returning information for job: 20190318053423416886
2019-03-18 05:34:27,819 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.32640791s left)
2019-03-18 05:34:53,526 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053453512852
2019-03-18 05:34:53,551 [salt.minion      :1432][INFO    ][14700] Starting a new job with PID 14700
2019-03-18 05:34:53,571 [salt.minion      :1711][INFO    ][14700] Returning information for job: 20190318053453512852
2019-03-18 05:35:00,394 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.75111699s left)
2019-03-18 05:35:23,572 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053523558399
2019-03-18 05:35:23,596 [salt.minion      :1432][INFO    ][14796] Starting a new job with PID 14796
2019-03-18 05:35:23,620 [salt.minion      :1711][INFO    ][14796] Returning information for job: 20190318053523558399
2019-03-18 05:35:33,957 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.1878171s left)
2019-03-18 05:35:53,632 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053553619636
2019-03-18 05:35:53,657 [salt.minion      :1432][INFO    ][14882] Starting a new job with PID 14882
2019-03-18 05:35:53,678 [salt.minion      :1711][INFO    ][14882] Returning information for job: 20190318053553619636
2019-03-18 05:36:07,628 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.51685095s left)
2019-03-18 05:36:23,691 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053623677106
2019-03-18 05:36:23,716 [salt.minion      :1432][INFO    ][14958] Starting a new job with PID 14958
2019-03-18 05:36:23,740 [salt.minion      :1711][INFO    ][14958] Returning information for job: 20190318053623677106
2019-03-18 05:36:41,508 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1291.63744092s left)
2019-03-18 05:36:53,765 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053653753617
2019-03-18 05:36:53,790 [salt.minion      :1432][INFO    ][15070] Starting a new job with PID 15070
2019-03-18 05:36:53,811 [salt.minion      :1711][INFO    ][15070] Returning information for job: 20190318053653753617
2019-03-18 05:37:14,718 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.42691708s left)
2019-03-18 05:37:23,828 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053723815552
2019-03-18 05:37:23,854 [salt.minion      :1432][INFO    ][15126] Starting a new job with PID 15126
2019-03-18 05:37:23,877 [salt.minion      :1711][INFO    ][15126] Returning information for job: 20190318053723815552
2019-03-18 05:37:48,222 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1224.92277789s left)
2019-03-18 05:37:53,902 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053753889035
2019-03-18 05:37:53,927 [salt.minion      :1432][INFO    ][15191] Starting a new job with PID 15191
2019-03-18 05:37:53,949 [salt.minion      :1711][INFO    ][15191] Returning information for job: 20190318053753889035
2019-03-18 05:38:21,474 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.67114711s left)
2019-03-18 05:38:23,973 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053823961132
2019-03-18 05:38:23,999 [salt.minion      :1432][INFO    ][15262] Starting a new job with PID 15262
2019-03-18 05:38:24,021 [salt.minion      :1711][INFO    ][15262] Returning information for job: 20190318053823961132
2019-03-18 05:38:54,053 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053854040872
2019-03-18 05:38:54,077 [salt.minion      :1432][INFO    ][15366] Starting a new job with PID 15366
2019-03-18 05:38:54,099 [salt.minion      :1711][INFO    ][15366] Returning information for job: 20190318053854040872
2019-03-18 05:38:54,994 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1158.15083098s left)
2019-03-18 05:39:24,139 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053924127425
2019-03-18 05:39:24,163 [salt.minion      :1432][INFO    ][15427] Starting a new job with PID 15427
2019-03-18 05:39:24,184 [salt.minion      :1711][INFO    ][15427] Returning information for job: 20190318053924127425
2019-03-18 05:39:28,086 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1125.0589931s left)
2019-03-18 05:39:54,224 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318053954211660
2019-03-18 05:39:54,250 [salt.minion      :1432][INFO    ][15460] Starting a new job with PID 15460
2019-03-18 05:39:54,272 [salt.minion      :1711][INFO    ][15460] Returning information for job: 20190318053954211660
2019-03-18 05:40:01,728 [salt.loaded.ext.module.maas:1023][INFO    ][14507] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.41754007s left)
2019-03-18 05:40:24,324 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command saltutil.find_job with jid 20190318054024311987
2019-03-18 05:40:24,350 [salt.minion      :1432][INFO    ][15538] Starting a new job with PID 15538
2019-03-18 05:40:24,376 [salt.minion      :1711][INFO    ][15538] Returning information for job: 20190318054024311987
2019-03-18 05:40:35,411 [salt.state       :300 ][INFO    ][14507] {'ret': True}
2019-03-18 05:40:35,412 [salt.state       :1951][INFO    ][14507] Completed state [maas.wait_for_machine_status] at time 05:40:35.412217 duration_in_ms=442271.583
2019-03-18 05:40:35,415 [salt.minion      :1711][INFO    ][14507] Returning information for job: 20190318053308106039
2019-03-18 05:40:36,095 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318054036082080
2019-03-18 05:40:36,122 [salt.minion      :1432][INFO    ][15614] Starting a new job with PID 15614
2019-03-18 05:40:39,729 [salt.state       :915 ][INFO    ][15614] Loading fresh modules for state activity
2019-03-18 05:40:39,872 [salt.state       :1780][INFO    ][15614] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:39.872561
2019-03-18 05:40:39,873 [salt.state       :1813][INFO    ][15614] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:40:39,874 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15614] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:40:41,264 [salt.state       :300 ][INFO    ][15614] {'pid': 15629, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:40:41,264 [salt.state       :1951][INFO    ][15614] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:41.264473 duration_in_ms=1391.912
2019-03-18 05:40:41,265 [salt.state       :1780][INFO    ][15614] Running state [maas_machines_storage_cmp002_lvm] at time 05:40:41.265853
2019-03-18 05:40:41,266 [salt.state       :1813][INFO    ][15614] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-03-18 05:40:41,914 [salt.state       :300 ][INFO    ][15614] Machine cmp002 is not in Ready state.
2019-03-18 05:40:41,914 [salt.state       :1951][INFO    ][15614] Completed state [maas_machines_storage_cmp002_lvm] at time 05:40:41.914728 duration_in_ms=648.871
2019-03-18 05:40:41,915 [salt.state       :1780][INFO    ][15614] Running state [maas_machines_storage_cmp001_lvm] at time 05:40:41.915557
2019-03-18 05:40:41,916 [salt.state       :1813][INFO    ][15614] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-03-18 05:40:42,390 [salt.state       :300 ][INFO    ][15614] Machine cmp001 is not in Ready state.
2019-03-18 05:40:42,391 [salt.state       :1951][INFO    ][15614] Completed state [maas_machines_storage_cmp001_lvm] at time 05:40:42.391412 duration_in_ms=475.853
2019-03-18 05:40:42,394 [salt.minion      :1711][INFO    ][15614] Returning information for job: 20190318054036082080
2019-03-18 05:40:43,010 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318054042997785
2019-03-18 05:40:43,036 [salt.minion      :1432][INFO    ][15639] Starting a new job with PID 15639
2019-03-18 05:40:43,649 [salt.state       :915 ][INFO    ][15639] Loading fresh modules for state activity
2019-03-18 05:40:43,733 [salt.state       :1780][INFO    ][15639] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:43.733320
2019-03-18 05:40:43,733 [salt.state       :1813][INFO    ][15639] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:40:43,735 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15639] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:40:45,300 [salt.state       :300 ][INFO    ][15639] {'pid': 15646, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:40:45,301 [salt.state       :1951][INFO    ][15639] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:45.301458 duration_in_ms=1568.137
2019-03-18 05:40:45,304 [salt.state       :1780][INFO    ][15639] Running state [maas.deploy_machines] at time 05:40:45.304056
2019-03-18 05:40:45,304 [salt.state       :1813][INFO    ][15639] Executing state module.run for [maas.deploy_machines]
2019-03-18 05:40:45,305 [salt.utils.decorators:613 ][WARNING ][15639] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:40:46,028 [salt.state       :300 ][INFO    ][15639] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-03-18 05:40:46,028 [salt.state       :1951][INFO    ][15639] Completed state [maas.deploy_machines] at time 05:40:46.028817 duration_in_ms=724.761
2019-03-18 05:40:46,032 [salt.minion      :1711][INFO    ][15639] Returning information for job: 20190318054042997785
2019-03-18 05:40:46,650 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command state.apply with jid 20190318054046635683
2019-03-18 05:40:46,675 [salt.minion      :1432][INFO    ][15655] Starting a new job with PID 15655
2019-03-18 05:40:47,284 [salt.state       :915 ][INFO    ][15655] Loading fresh modules for state activity
2019-03-18 05:40:47,375 [salt.state       :1780][INFO    ][15655] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:47.375778
2019-03-18 05:40:47,376 [salt.state       :1813][INFO    ][15655] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-18 05:40:47,378 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-18 05:40:48,822 [salt.state       :300 ][INFO    ][15655] {'pid': 15662, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-18 05:40:48,823 [salt.state       :1951][INFO    ][15655] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:48.823305 duration_in_ms=1447.528
2019-03-18 05:40:48,824 [salt.state       :1780][INFO    ][15655] Running state [maas.wait_for_machine_status] at time 05:40:48.824468
2019-03-18 05:40:48,824 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maas.wait_for_machine_status]
2019-03-18 05:40:48,825 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-18 05:40:52,428 [salt.state       :300 ][INFO    ][15655] {'ret': True}
2019-03-18 05:40:52,428 [salt.state       :1951][INFO    ][15655] Completed state [maas.wait_for_machine_status] at time 05:40:52.428628 duration_in_ms=3604.157
2019-03-18 05:40:52,432 [salt.minion      :1711][INFO    ][15655] Returning information for job: 20190318054046635683
2019-03-18 06:10:13,609 [salt.utils.schedule:1377][INFO    ][7597] Running scheduled job: __mine_interval
2019-03-18 07:10:13,609 [salt.utils.schedule:1377][INFO    ][7597] Running scheduled job: __mine_interval
2019-03-18 07:20:17,446 [salt.minion      :1308][INFO    ][7597] User sudo_ubuntu Executing command cp.push_dir with jid 20190318072017434354
2019-03-18 07:20:17,468 [salt.minion      :1432][INFO    ][22929] Starting a new job with PID 22929
