2019-05-25 05:12:48,397 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-25 05:13:38,448 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-25 05:14:28,498 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-25 05:15:18,545 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-25 05:16:08,594 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-25 05:18:16,768 [salt.utils.decorators:613 ][WARNING ][2714] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:18:17,390 [salt.utils.decorators:613 ][WARNING ][2714] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:18:19,506 [salt.loaded.int.states.file:2298][WARNING ][2850] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-25 05:18:25,240 [salt.state       :2022][WARNING ][2966] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-25 05:18:27,781 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:18:41,856 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:19:17,803 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:19:18,803 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:19:22,393 [salt.loaded.ext.module.maasng:1008][WARNING ][2966] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-25 05:19:22,394 [salt.loaded.ext.module.maasng:1011][WARNING ][2966] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-25 05:19:23,303 [salt.loaded.ext.module.maasng:1235][WARNING ][2966] Ignoring parameter vlan:0
2019-05-25 05:19:24,527 [salt.utils.decorators:613 ][WARNING ][2966] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:19:26,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5913] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-25 05:19:26,273 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5913] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-25 05:19:26,295 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-05-25 05:19:27,269 [salt.cli.daemons :293 ][INFO    ][5984] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-05-25 05:19:27,372 [salt.cli.daemons :82  ][INFO    ][5984] Starting up the Salt Minion
2019-05-25 05:19:27,373 [salt.utils.event :1017][INFO    ][5984] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-05-25 05:19:28,257 [salt.minion      :976 ][INFO    ][5984] Creating minion process manager
2019-05-25 05:19:29,670 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5984] Executing command ['date', '+%z'] in directory '/root'
2019-05-25 05:19:29,689 [salt.utils.schedule:568 ][INFO    ][5984] Updating job settings for scheduled job: __mine_interval
2019-05-25 05:19:29,690 [salt.minion      :1108][INFO    ][5984] Added mine.update to scheduler
2019-05-25 05:19:29,694 [salt.minion      :1975][INFO    ][5984] Minion is starting as user 'root'
2019-05-25 05:19:29,706 [salt.minion      :2336][INFO    ][5984] Minion is ready to receive requests!
2019-05-25 05:19:30,598 [salt.utils.decorators:613 ][WARNING ][5923] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:19:30,676 [salt.loaded.ext.module.maas:412 ][WARNING ][5923] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:19:32,173 [salt.loaded.ext.module.maas:412 ][WARNING ][5923] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:19:33,628 [salt.loaded.ext.module.maas:412 ][WARNING ][5923] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:19:35,102 [salt.loaded.ext.module.maas:412 ][WARNING ][5923] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:19:36,557 [salt.loaded.ext.module.maas:412 ][WARNING ][5923] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:20:09,013 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525052009000257
2019-05-25 05:20:09,037 [salt.minion      :1432][INFO    ][6391] Starting a new job with PID 6391
2019-05-25 05:20:12,819 [salt.state       :915 ][INFO    ][6391] Loading fresh modules for state activity
2019-05-25 05:20:12,848 [salt.fileclient  :1219][INFO    ][6391] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-25 05:20:12,874 [salt.state       :1780][INFO    ][6391] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:20:12.874788
2019-05-25 05:20:12,875 [salt.state       :1813][INFO    ][6391] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:20:12,876 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6391] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:20:14,240 [salt.state       :300 ][INFO    ][6391] {'pid': 6399, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:20:14,240 [salt.state       :1951][INFO    ][6391] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:20:14.240522 duration_in_ms=1365.735
2019-05-25 05:20:14,242 [salt.state       :1780][INFO    ][6391] Running state [maas.wait_for_machine_status] at time 05:20:14.242043
2019-05-25 05:20:14,242 [salt.state       :1813][INFO    ][6391] Executing state module.run for [maas.wait_for_machine_status]
2019-05-25 05:20:14,242 [salt.utils.decorators:613 ][WARNING ][6391] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:20:15,225 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.02218008s left)
2019-05-25 05:20:24,107 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052024094322
2019-05-25 05:20:24,131 [salt.minion      :1432][INFO    ][6426] Starting a new job with PID 6426
2019-05-25 05:20:24,156 [salt.minion      :1711][INFO    ][6426] Returning information for job: 20190525052024094322
2019-05-25 05:20:46,130 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.11710405s left)
2019-05-25 05:20:54,158 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052054145800
2019-05-25 05:20:54,182 [salt.minion      :1432][INFO    ][6471] Starting a new job with PID 6471
2019-05-25 05:20:54,205 [salt.minion      :1711][INFO    ][6471] Returning information for job: 20190525052054145800
2019-05-25 05:21:17,155 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.09166503s left)
2019-05-25 05:21:24,198 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052124186968
2019-05-25 05:21:24,219 [salt.minion      :1432][INFO    ][6611] Starting a new job with PID 6611
2019-05-25 05:21:24,240 [salt.minion      :1711][INFO    ][6611] Returning information for job: 20190525052124186968
2019-05-25 05:21:48,579 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.66800404s left)
2019-05-25 05:21:54,250 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052154234934
2019-05-25 05:21:54,275 [salt.minion      :1432][INFO    ][6743] Starting a new job with PID 6743
2019-05-25 05:21:54,297 [salt.minion      :1711][INFO    ][6743] Returning information for job: 20190525052154234934
2019-05-25 05:22:20,211 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.03560805s left)
2019-05-25 05:22:24,314 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052224299034
2019-05-25 05:22:24,337 [salt.minion      :1432][INFO    ][6920] Starting a new job with PID 6920
2019-05-25 05:22:24,361 [salt.minion      :1711][INFO    ][6920] Returning information for job: 20190525052224299034
2019-05-25 05:22:51,837 [salt.loaded.ext.module.maas:1023][INFO    ][6391] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.40974212s left)
2019-05-25 05:22:54,378 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052254357954
2019-05-25 05:22:54,403 [salt.minion      :1432][INFO    ][7507] Starting a new job with PID 7507
2019-05-25 05:22:54,426 [salt.minion      :1711][INFO    ][7507] Returning information for job: 20190525052254357954
2019-05-25 05:23:24,438 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052324424251
2019-05-25 05:23:24,460 [salt.minion      :1432][INFO    ][7667] Starting a new job with PID 7667
2019-05-25 05:23:24,480 [salt.minion      :1711][INFO    ][7667] Returning information for job: 20190525052324424251
2019-05-25 05:23:24,833 [salt.state       :300 ][INFO    ][6391] {'ret': True}
2019-05-25 05:23:24,833 [salt.state       :1951][INFO    ][6391] Completed state [maas.wait_for_machine_status] at time 05:23:24.833555 duration_in_ms=190591.509
2019-05-25 05:23:24,837 [salt.minion      :1711][INFO    ][6391] Returning information for job: 20190525052009000257
2019-05-25 05:23:25,469 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525052325454941
2019-05-25 05:23:25,491 [salt.minion      :1432][INFO    ][7674] Starting a new job with PID 7674
2019-05-25 05:23:29,258 [salt.state       :915 ][INFO    ][7674] Loading fresh modules for state activity
2019-05-25 05:23:29,310 [salt.fileclient  :1219][INFO    ][7674] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-25 05:23:29,398 [salt.state       :1780][INFO    ][7674] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:29.398841
2019-05-25 05:23:29,399 [salt.state       :1813][INFO    ][7674] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:23:29,400 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7674] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:23:30,775 [salt.state       :300 ][INFO    ][7674] {'pid': 7787, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:23:30,775 [salt.state       :1951][INFO    ][7674] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:30.775390 duration_in_ms=1376.549
2019-05-25 05:23:30,776 [salt.state       :1780][INFO    ][7674] Running state [maas_machines_storage_cmp002_lvm] at time 05:23:30.776695
2019-05-25 05:23:30,776 [salt.state       :1813][INFO    ][7674] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-25 05:23:32,067 [salt.loaded.ext.module.maasng:610 ][INFO    ][7674] hn8hrs
2019-05-25 05:23:32,067 [salt.loaded.ext.module.maasng:626 ][INFO    ][7674] sda
2019-05-25 05:23:32,993 [salt.loaded.ext.module.maasng:361 ][INFO    ][7674] hn8hrs
2019-05-25 05:23:33,133 [salt.loaded.ext.module.maasng:367 ][INFO    ][7674] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'8aa42e06-39ac-460d-a16c-378fb14f4e21', u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hn8hrs', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'f84bd7e9-5145-4361-a921-9e4ef8a6485b', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 5, u'device_id': 4}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'hn8hrs', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/'}, {u'model': None, u'block_size': 4096, u'uuid': u'd168fe90-64da-4617-80c3-4c958ec564bd', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'0a8e7c0b-f99d-43f2-a680-e98115ad1992', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hn8hrs', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'size': 2397988454400, u'used_size': 2397988454400, u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/10/'}]
2019-05-25 05:23:33,133 [salt.loaded.ext.module.maasng:632 ][INFO    ][7674] vgroot
2019-05-25 05:23:33,134 [salt.loaded.ext.module.maasng:635 ][INFO    ][7674] lvroot
2019-05-25 05:23:33,134 [salt.loaded.ext.module.maasng:639 ][INFO    ][7674] 107374182400
2019-05-25 05:23:33,849 [salt.loaded.ext.module.maasng:645 ][INFO    ][7674] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.42'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'address_ttl': None, u'system_id': u'hn8hrs', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'owner_data': {}, u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'aa6531c1-1059-4ffd-9dd8-3a87f7624d86', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hn8hrs', u'device_id': 4, u'filesystem': {u'uuid': u'862bf2c9-b7b1-4b90-83eb-ea99fef7e645', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hn8hrs', 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'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/14/', u'uuid': u'f0b37f7b-db59-4f86-bbf7-1abf20b27724', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'hn8hrs', u'partition_table_type': None, u'filesystem': {u'uuid': u'925ecfd6-5c9c-443d-a30b-09157f91c573', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 14, u'serial': None, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'on', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'aa6531c1-1059-4ffd-9dd8-3a87f7624d86', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hn8hrs', u'device_id': 4, u'filesystem': {u'uuid': u'862bf2c9-b7b1-4b90-83eb-ea99fef7e645', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hn8hrs', 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'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'hn8hrs', u'id': 9}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'aa6531c1-1059-4ffd-9dd8-3a87f7624d86', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hn8hrs', u'device_id': 4, u'filesystem': {u'uuid': u'862bf2c9-b7b1-4b90-83eb-ea99fef7e645', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hn8hrs', 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'block_size': 4096, u'type': u'physical', u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 33, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'system_id': u'hn8hrs', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/interfaces/4/'}, {u'name': u'enp8s0', u'links': [{u'id': 34, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'hn8hrs', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/interfaces/15/'}, {u'name': u'enp7s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'hn8hrs', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/interfaces/16/'}, {u'name': u'enp9s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'hn8hrs', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/interfaces/17/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'modules-final', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/blockdevices/14/', u'uuid': u'f0b37f7b-db59-4f86-bbf7-1abf20b27724', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'hn8hrs', u'partition_table_type': None, u'filesystem': {u'uuid': u'925ecfd6-5c9c-443d-a30b-09157f91c573', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 14, u'serial': None, u'size': 107374182400}], u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 33, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'system_id': u'hn8hrs', u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/hn8hrs/interfaces/4/'}, u'min_hwe_kernel': u'hwe-16.04', u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/hn8hrs/'}
2019-05-25 05:23:33,851 [salt.state       :300 ][INFO    ][7674] {'new': {'storage_layout': 'lvm'}}
2019-05-25 05:23:33,852 [salt.state       :1951][INFO    ][7674] Completed state [maas_machines_storage_cmp002_lvm] at time 05:23:33.851953 duration_in_ms=3075.254
2019-05-25 05:23:33,852 [salt.state       :1780][INFO    ][7674] Running state [maas_machines_storage_cmp001_lvm] at time 05:23:33.852554
2019-05-25 05:23:33,853 [salt.state       :1813][INFO    ][7674] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-25 05:23:35,310 [salt.loaded.ext.module.maasng:610 ][INFO    ][7674] sr44wc
2019-05-25 05:23:35,310 [salt.loaded.ext.module.maasng:626 ][INFO    ][7674] sda
2019-05-25 05:23:36,011 [salt.loaded.ext.module.maasng:361 ][INFO    ][7674] sr44wc
2019-05-25 05:23:36,138 [salt.loaded.ext.module.maasng:367 ][INFO    ][7674] [{u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'c8a3424d-a6ed-4792-9ab3-4281221cbbdb', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sr44wc', u'device_id': 5, u'filesystem': {u'uuid': u'c0a0d0dc-8fa7-4b06-a807-6b62e9eb54dd', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'sr44wc', 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'block_size': 4096, u'type': u'physical', u'id': 5, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/11/', u'uuid': u'28832c83-98a3-4348-a558-bc91729611a7', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'sr44wc', u'partition_table_type': None, u'filesystem': {u'uuid': u'76a04d69-f40f-49ae-8e97-73d4db4a1a00', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'serial': None, u'size': 2397988454400}]
2019-05-25 05:23:36,138 [salt.loaded.ext.module.maasng:632 ][INFO    ][7674] vgroot
2019-05-25 05:23:36,139 [salt.loaded.ext.module.maasng:635 ][INFO    ][7674] lvroot
2019-05-25 05:23:36,139 [salt.loaded.ext.module.maasng:639 ][INFO    ][7674] 107374182400
2019-05-25 05:23:36,867 [salt.loaded.ext.module.maasng:645 ][INFO    ][7674] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'sr44wc', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/', u'type': u'physical', u'id': 5, u'partitions': [{u'size': 2397992648704, u'uuid': u'de73ab1a-3ade-4cfa-9992-b63e367a12a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sr44wc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'a4c7d1de-ff6a-41d0-a4f5-0db3e0a1b3c0', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/partition/10'}]}, u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'address_ttl': None, u'system_id': u'sr44wc', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'ip_addresses': [u'192.168.11.38'], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'sr44wc', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/', u'type': u'physical', u'id': 5, u'partitions': [{u'size': 2397992648704, u'uuid': u'de73ab1a-3ade-4cfa-9992-b63e367a12a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sr44wc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'a4c7d1de-ff6a-41d0-a4f5-0db3e0a1b3c0', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/partition/10'}]}, {u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'fd8be8ac-5367-4f86-83a0-a9a74fb29d67', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'b878987a-0eff-45e9-9afd-8a6caf5b3f27', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'sr44wc', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/15/', u'type': u'virtual', u'id': 15, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'on', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'sr44wc', u'id': 10}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 38, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'effective_mtu': 1500, u'id': 5, u'system_id': u'sr44wc', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 40, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'id': 21, u'system_id': u'sr44wc', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/interfaces/21/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 41, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'id': 22, u'system_id': u'sr44wc', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/interfaces/22/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 42, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'id': 23, u'system_id': u'sr44wc', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/interfaces/23/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'sr44wc', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/', u'type': u'physical', u'id': 5, u'partitions': [{u'size': 2397992648704, u'uuid': u'de73ab1a-3ade-4cfa-9992-b63e367a12a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sr44wc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'a4c7d1de-ff6a-41d0-a4f5-0db3e0a1b3c0', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/5/partition/10'}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'fd8be8ac-5367-4f86-83a0-a9a74fb29d67', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'b878987a-0eff-45e9-9afd-8a6caf5b3f27', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'sr44wc', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/blockdevices/15/', u'type': u'virtual', u'id': 15, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 38, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'effective_mtu': 1500, u'id': 5, u'system_id': u'sr44wc', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/sr44wc/interfaces/5/'}, u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/sr44wc/'}
2019-05-25 05:23:36,869 [salt.state       :300 ][INFO    ][7674] {'new': {'storage_layout': 'lvm'}}
2019-05-25 05:23:36,870 [salt.state       :1951][INFO    ][7674] Completed state [maas_machines_storage_cmp001_lvm] at time 05:23:36.870010 duration_in_ms=3017.455
2019-05-25 05:23:36,874 [salt.minion      :1711][INFO    ][7674] Returning information for job: 20190525052325454941
2019-05-25 05:23:37,457 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525052337445127
2019-05-25 05:23:37,481 [salt.minion      :1432][INFO    ][7852] Starting a new job with PID 7852
2019-05-25 05:23:38,224 [salt.state       :915 ][INFO    ][7852] Loading fresh modules for state activity
2019-05-25 05:23:38,264 [salt.fileclient  :1219][INFO    ][7852] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-25 05:23:38,302 [salt.state       :1780][INFO    ][7852] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:38.302032
2019-05-25 05:23:38,302 [salt.state       :1813][INFO    ][7852] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:23:38,304 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7852] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:23:39,771 [salt.state       :300 ][INFO    ][7852] {'pid': 7859, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:23:39,772 [salt.state       :1951][INFO    ][7852] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:39.772012 duration_in_ms=1469.981
2019-05-25 05:23:39,773 [salt.state       :1780][INFO    ][7852] Running state [maas.deploy_machines] at time 05:23:39.773220
2019-05-25 05:23:39,773 [salt.state       :1813][INFO    ][7852] Executing state module.run for [maas.deploy_machines]
2019-05-25 05:23:39,774 [salt.utils.decorators:613 ][WARNING ][7852] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:23:40,331 [salt.loaded.ext.module.maas:684 ][INFO    ][7852] deploymachines hwe_kernel=hwe-16.04 system_id=hn8hrs distro_series=xenial
2019-05-25 05:23:42,948 [salt.loaded.ext.module.maas:684 ][INFO    ][7852] deploymachines hwe_kernel=hwe-16.04 system_id=sr44wc distro_series=xenial
2019-05-25 05:23:45,751 [salt.loaded.ext.module.maas:684 ][INFO    ][7852] deploymachines hwe_kernel=hwe-16.04 system_id=yb8ywt distro_series=xenial
2019-05-25 05:23:48,515 [salt.loaded.ext.module.maas:684 ][INFO    ][7852] deploymachines hwe_kernel=hwe-16.04 system_id=r37qkb distro_series=xenial
2019-05-25 05:23:51,306 [salt.loaded.ext.module.maas:684 ][INFO    ][7852] deploymachines hwe_kernel=hwe-16.04 system_id=nbgetb distro_series=xenial
2019-05-25 05:23:52,500 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052352487064
2019-05-25 05:23:52,523 [salt.minion      :1432][INFO    ][8116] Starting a new job with PID 8116
2019-05-25 05:23:52,545 [salt.minion      :1711][INFO    ][8116] Returning information for job: 20190525052352487064
2019-05-25 05:23:53,695 [salt.state       :300 ][INFO    ][7852] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-25 05:23:53,695 [salt.state       :1951][INFO    ][7852] Completed state [maas.deploy_machines] at time 05:23:53.695704 duration_in_ms=13922.482
2019-05-25 05:23:53,699 [salt.minion      :1711][INFO    ][7852] Returning information for job: 20190525052337445127
2019-05-25 05:23:54,318 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525052354305433
2019-05-25 05:23:54,340 [salt.minion      :1432][INFO    ][8133] Starting a new job with PID 8133
2019-05-25 05:23:57,947 [salt.state       :915 ][INFO    ][8133] Loading fresh modules for state activity
2019-05-25 05:23:57,997 [salt.fileclient  :1219][INFO    ][8133] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-25 05:23:58,037 [salt.state       :1780][INFO    ][8133] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:58.037151
2019-05-25 05:23:58,037 [salt.state       :1813][INFO    ][8133] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:23:58,039 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8133] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:23:59,435 [salt.state       :300 ][INFO    ][8133] {'pid': 8147, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:23:59,435 [salt.state       :1951][INFO    ][8133] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:23:59.435937 duration_in_ms=1398.786
2019-05-25 05:23:59,437 [salt.state       :1780][INFO    ][8133] Running state [maas.wait_for_machine_status] at time 05:23:59.437477
2019-05-25 05:23:59,437 [salt.state       :1813][INFO    ][8133] Executing state module.run for [maas.wait_for_machine_status]
2019-05-25 05:23:59,438 [salt.utils.decorators:613 ][WARNING ][8133] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:24:02,697 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.74454308s left)
2019-05-25 05:24:09,347 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052409331362
2019-05-25 05:24:09,367 [salt.minion      :1432][INFO    ][8160] Starting a new job with PID 8160
2019-05-25 05:24:09,390 [salt.minion      :1711][INFO    ][8160] Returning information for job: 20190525052409331362
2019-05-25 05:24:36,243 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.19945002s left)
2019-05-25 05:24:39,387 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052439373471
2019-05-25 05:24:39,411 [salt.minion      :1432][INFO    ][8214] Starting a new job with PID 8214
2019-05-25 05:24:39,433 [salt.minion      :1711][INFO    ][8214] Returning information for job: 20190525052439373471
2019-05-25 05:25:09,455 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052509442506
2019-05-25 05:25:09,480 [salt.minion      :1432][INFO    ][8234] Starting a new job with PID 8234
2019-05-25 05:25:09,503 [salt.minion      :1711][INFO    ][8234] Returning information for job: 20190525052509442506
2019-05-25 05:25:09,703 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.73856616s left)
2019-05-25 05:25:39,503 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052539490316
2019-05-25 05:25:39,528 [salt.minion      :1432][INFO    ][8353] Starting a new job with PID 8353
2019-05-25 05:25:39,549 [salt.minion      :1711][INFO    ][8353] Returning information for job: 20190525052539490316
2019-05-25 05:25:42,847 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.59499407s left)
2019-05-25 05:26:09,559 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052609547286
2019-05-25 05:26:09,583 [salt.minion      :1432][INFO    ][8518] Starting a new job with PID 8518
2019-05-25 05:26:09,606 [salt.minion      :1711][INFO    ][8518] Returning information for job: 20190525052609547286
2019-05-25 05:26:16,356 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.08597612s left)
2019-05-25 05:26:39,615 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052639602535
2019-05-25 05:26:39,639 [salt.minion      :1432][INFO    ][9252] Starting a new job with PID 9252
2019-05-25 05:26:39,662 [salt.minion      :1711][INFO    ][9252] Returning information for job: 20190525052639602535
2019-05-25 05:26:49,439 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.00268006s left)
2019-05-25 05:27:09,675 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052709662238
2019-05-25 05:27:09,699 [salt.minion      :1432][INFO    ][9272] Starting a new job with PID 9272
2019-05-25 05:27:09,723 [salt.minion      :1711][INFO    ][9272] Returning information for job: 20190525052709662238
2019-05-25 05:27:22,308 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.13439822s left)
2019-05-25 05:27:39,734 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052739721949
2019-05-25 05:27:39,758 [salt.minion      :1432][INFO    ][9490] Starting a new job with PID 9490
2019-05-25 05:27:39,780 [salt.minion      :1711][INFO    ][9490] Returning information for job: 20190525052739721949
2019-05-25 05:27:55,709 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.73331618s left)
2019-05-25 05:28:09,800 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052809784322
2019-05-25 05:28:09,824 [salt.minion      :1432][INFO    ][9520] Starting a new job with PID 9520
2019-05-25 05:28:09,846 [salt.minion      :1711][INFO    ][9520] Returning information for job: 20190525052809784322
2019-05-25 05:28:28,641 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.8011601s left)
2019-05-25 05:28:39,862 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052839849745
2019-05-25 05:28:39,886 [salt.minion      :1432][INFO    ][9997] Starting a new job with PID 9997
2019-05-25 05:28:39,908 [salt.minion      :1711][INFO    ][9997] Returning information for job: 20190525052839849745
2019-05-25 05:29:02,199 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.24310923s left)
2019-05-25 05:29:09,933 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052909919672
2019-05-25 05:29:09,956 [salt.minion      :1432][INFO    ][10025] Starting a new job with PID 10025
2019-05-25 05:29:09,979 [salt.minion      :1711][INFO    ][10025] Returning information for job: 20190525052909919672
2019-05-25 05:29:35,769 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.67316508s left)
2019-05-25 05:29:40,010 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525052939997097
2019-05-25 05:29:40,034 [salt.minion      :1432][INFO    ][10530] Starting a new job with PID 10530
2019-05-25 05:29:40,056 [salt.minion      :1711][INFO    ][10530] Returning information for job: 20190525052939997097
2019-05-25 05:30:09,439 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.00331521s left)
2019-05-25 05:30:10,088 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053010075215
2019-05-25 05:30:10,111 [salt.minion      :1432][INFO    ][10549] Starting a new job with PID 10549
2019-05-25 05:30:10,135 [salt.minion      :1711][INFO    ][10549] Returning information for job: 20190525053010075215
2019-05-25 05:30:40,169 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053040156077
2019-05-25 05:30:40,191 [salt.minion      :1432][INFO    ][10663] Starting a new job with PID 10663
2019-05-25 05:30:40,208 [salt.minion      :1711][INFO    ][10663] Returning information for job: 20190525053040156077
2019-05-25 05:30:43,189 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.25339007s left)
2019-05-25 05:31:10,250 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053110237406
2019-05-25 05:31:10,274 [salt.minion      :1432][INFO    ][10706] Starting a new job with PID 10706
2019-05-25 05:31:10,296 [salt.minion      :1711][INFO    ][10706] Returning information for job: 20190525053110237406
2019-05-25 05:31:16,710 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.73184705s left)
2019-05-25 05:31:40,287 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053140278418
2019-05-25 05:31:40,308 [salt.minion      :1432][INFO    ][10955] Starting a new job with PID 10955
2019-05-25 05:31:40,330 [salt.minion      :1711][INFO    ][10955] Returning information for job: 20190525053140278418
2019-05-25 05:31:50,208 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1779.23445702s left)
2019-05-25 05:32:10,390 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053210377245
2019-05-25 05:32:10,414 [salt.minion      :1432][INFO    ][11029] Starting a new job with PID 11029
2019-05-25 05:32:10,438 [salt.minion      :1711][INFO    ][11029] Returning information for job: 20190525053210377245
2019-05-25 05:32:23,661 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1745.78081107s left)
2019-05-25 05:32:40,501 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053240489330
2019-05-25 05:32:40,526 [salt.minion      :1432][INFO    ][11509] Starting a new job with PID 11509
2019-05-25 05:32:40,548 [salt.minion      :1711][INFO    ][11509] Returning information for job: 20190525053240489330
2019-05-25 05:32:57,198 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1712.24434114s left)
2019-05-25 05:33:10,627 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053310610625
2019-05-25 05:33:10,652 [salt.minion      :1432][INFO    ][11528] Starting a new job with PID 11528
2019-05-25 05:33:10,676 [salt.minion      :1711][INFO    ][11528] Returning information for job: 20190525053310610625
2019-05-25 05:33:30,699 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1678.74259019s left)
2019-05-25 05:33:40,756 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053340743298
2019-05-25 05:33:40,779 [salt.minion      :1432][INFO    ][11587] Starting a new job with PID 11587
2019-05-25 05:33:40,801 [salt.minion      :1711][INFO    ][11587] Returning information for job: 20190525053340743298
2019-05-25 05:34:04,311 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1645.13055706s left)
2019-05-25 05:34:10,884 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053410870908
2019-05-25 05:34:10,909 [salt.minion      :1432][INFO    ][11607] Starting a new job with PID 11607
2019-05-25 05:34:10,933 [salt.minion      :1711][INFO    ][11607] Returning information for job: 20190525053410870908
2019-05-25 05:34:37,629 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1611.81358504s left)
2019-05-25 05:34:41,031 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053441014922
2019-05-25 05:34:41,055 [salt.minion      :1432][INFO    ][11663] Starting a new job with PID 11663
2019-05-25 05:34:41,078 [salt.minion      :1711][INFO    ][11663] Returning information for job: 20190525053441014922
2019-05-25 05:35:11,115 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.32666206s left)
2019-05-25 05:35:11,178 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053511165645
2019-05-25 05:35:11,202 [salt.minion      :1432][INFO    ][11683] Starting a new job with PID 11683
2019-05-25 05:35:11,226 [salt.minion      :1711][INFO    ][11683] Returning information for job: 20190525053511165645
2019-05-25 05:35:41,348 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053541330780
2019-05-25 05:35:41,370 [salt.minion      :1432][INFO    ][11739] Starting a new job with PID 11739
2019-05-25 05:35:41,394 [salt.minion      :1711][INFO    ][11739] Returning information for job: 20190525053541330780
2019-05-25 05:35:44,562 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1544.87972021s left)
2019-05-25 05:36:11,517 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053611504319
2019-05-25 05:36:11,541 [salt.minion      :1432][INFO    ][11767] Starting a new job with PID 11767
2019-05-25 05:36:11,564 [salt.minion      :1711][INFO    ][11767] Returning information for job: 20190525053611504319
2019-05-25 05:36:18,018 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1511.42377806s left)
2019-05-25 05:36:41,695 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053641681593
2019-05-25 05:36:41,718 [salt.minion      :1432][INFO    ][11826] Starting a new job with PID 11826
2019-05-25 05:36:41,743 [salt.minion      :1711][INFO    ][11826] Returning information for job: 20190525053641681593
2019-05-25 05:36:51,300 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1478.14211416s left)
2019-05-25 05:37:11,886 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053711873244
2019-05-25 05:37:11,910 [salt.minion      :1432][INFO    ][11846] Starting a new job with PID 11846
2019-05-25 05:37:11,932 [salt.minion      :1711][INFO    ][11846] Returning information for job: 20190525053711873244
2019-05-25 05:37:24,468 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1444.974298s left)
2019-05-25 05:37:42,082 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053742069651
2019-05-25 05:37:42,106 [salt.minion      :1432][INFO    ][11906] Starting a new job with PID 11906
2019-05-25 05:37:42,130 [salt.minion      :1711][INFO    ][11906] Returning information for job: 20190525053742069651
2019-05-25 05:37:57,970 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1411.47151804s left)
2019-05-25 05:38:12,289 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053812276248
2019-05-25 05:38:12,313 [salt.minion      :1432][INFO    ][11926] Starting a new job with PID 11926
2019-05-25 05:38:12,335 [salt.minion      :1711][INFO    ][11926] Returning information for job: 20190525053812276248
2019-05-25 05:38:31,464 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1377.97838616s left)
2019-05-25 05:38:42,305 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053842293124
2019-05-25 05:38:42,329 [salt.minion      :1432][INFO    ][12125] Starting a new job with PID 12125
2019-05-25 05:38:42,353 [salt.minion      :1711][INFO    ][12125] Returning information for job: 20190525053842293124
2019-05-25 05:39:05,145 [salt.loaded.ext.module.maas:1023][INFO    ][8133] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1344.29648614s left)
2019-05-25 05:39:12,326 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053912313278
2019-05-25 05:39:12,350 [salt.minion      :1432][INFO    ][12150] Starting a new job with PID 12150
2019-05-25 05:39:12,371 [salt.minion      :1711][INFO    ][12150] Returning information for job: 20190525053912313278
2019-05-25 05:39:38,072 [salt.loaded.ext.module.maas:993 ][INFO    ][8133] Machine r37qkb mark broken
2019-05-25 05:39:38,848 [salt.loaded.ext.module.maas:996 ][INFO    ][8133] Machine r37qkb mark fixed
2019-05-25 05:39:40,039 [salt.loaded.ext.module.maas:684 ][INFO    ][8133] deploymachines hwe_kernel=hwe-16.04 system_id=r37qkb distro_series=xenial
2019-05-25 05:39:42,365 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525053942351831
2019-05-25 05:39:42,386 [salt.minion      :1432][INFO    ][12266] Starting a new job with PID 12266
2019-05-25 05:39:42,411 [salt.minion      :1711][INFO    ][12266] Returning information for job: 20190525053942351831
2019-05-25 05:39:42,699 [salt.loaded.ext.module.maas:160 ][ERROR   ][8133] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-05-25 05:39:42,701 [salt.state       :302 ][ERROR   ][8133] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-05-25 05:39:42,701 [salt.state       :1951][INFO    ][8133] Completed state [maas.wait_for_machine_status] at time 05:39:42.701500 duration_in_ms=943264.017
2019-05-25 05:39:42,711 [salt.minion      :1711][INFO    ][8133] Returning information for job: 20190525052354305433
2019-05-25 05:39:53,473 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command pillar.get with jid 20190525053953461433
2019-05-25 05:39:53,495 [salt.minion      :1432][INFO    ][12297] Starting a new job with PID 12297
2019-05-25 05:39:53,500 [salt.minion      :1711][INFO    ][12297] Returning information for job: 20190525053953461433
2019-05-25 05:39:54,006 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command service.status with jid 20190525053953994254
2019-05-25 05:39:54,028 [salt.minion      :1432][INFO    ][12302] Starting a new job with PID 12302
2019-05-25 05:39:54,415 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12302] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-25 05:39:54,449 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12302] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-25 05:39:54,464 [salt.minion      :1711][INFO    ][12302] Returning information for job: 20190525053953994254
2019-05-25 05:39:54,995 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525053954983036
2019-05-25 05:39:55,016 [salt.minion      :1432][INFO    ][12313] Starting a new job with PID 12313
2019-05-25 05:39:58,773 [salt.state       :915 ][INFO    ][12313] Loading fresh modules for state activity
2019-05-25 05:39:59,167 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'salt-minion --version' in directory '/root'
2019-05-25 05:39:59,504 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'salt-minion --version' in directory '/root'
2019-05-25 05:40:00,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'salt-minion --version' in directory '/root'
2019-05-25 05:40:00,688 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'salt-minion --version' in directory '/root'
2019-05-25 05:40:02,047 [salt.state       :1780][INFO    ][12313] Running state [salt-minion] at time 05:40:02.047840
2019-05-25 05:40:02,048 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [salt-minion]
2019-05-25 05:40:02,048 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-25 05:40:02,130 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,131 [salt.state       :1951][INFO    ][12313] Completed state [salt-minion] at time 05:40:02.131227 duration_in_ms=83.387
2019-05-25 05:40:02,131 [salt.state       :1780][INFO    ][12313] Running state [salt_minion_dependency_packages] at time 05:40:02.131542
2019-05-25 05:40:02,131 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-25 05:40:02,137 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,137 [salt.state       :1951][INFO    ][12313] Completed state [salt_minion_dependency_packages] at time 05:40:02.137947 duration_in_ms=6.405
2019-05-25 05:40:02,140 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/minion.d/minion.conf] at time 05:40:02.140838
2019-05-25 05:40:02,141 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-25 05:40:02,351 [salt.state       :300 ][INFO    ][12313] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-25 05:40:02,352 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/minion.d/minion.conf] at time 05:40:02.352203 duration_in_ms=211.365
2019-05-25 05:40:02,352 [salt.state       :1780][INFO    ][12313] Running state [python-netaddr] at time 05:40:02.352468
2019-05-25 05:40:02,352 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [python-netaddr]
2019-05-25 05:40:02,359 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,359 [salt.state       :1951][INFO    ][12313] Completed state [python-netaddr] at time 05:40:02.359820 duration_in_ms=7.351
2019-05-25 05:40:02,363 [salt.state       :1780][INFO    ][12313] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:40:02.362980
2019-05-25 05:40:02,363 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-25 05:40:02,373 [salt.state       :300 ][INFO    ][12313] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-25 05:40:02,374 [salt.state       :1951][INFO    ][12313] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:40:02.373976 duration_in_ms=10.995
2019-05-25 05:40:02,375 [salt.state       :1780][INFO    ][12313] Running state [salt-minion] at time 05:40:02.374997
2019-05-25 05:40:02,375 [salt.state       :1813][INFO    ][12313] Executing state service.running for [salt-minion]
2019-05-25 05:40:02,375 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:02,413 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-25 05:40:02,430 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-25 05:40:02,447 [salt.state       :300 ][INFO    ][12313] The service salt-minion is already running
2019-05-25 05:40:02,448 [salt.state       :1951][INFO    ][12313] Completed state [salt-minion] at time 05:40:02.447956 duration_in_ms=72.958
2019-05-25 05:40:02,450 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains.d] at time 05:40:02.449982
2019-05-25 05:40:02,450 [salt.state       :1813][INFO    ][12313] Executing state file.directory for [/etc/salt/grains.d]
2019-05-25 05:40:02,451 [salt.state       :300 ][INFO    ][12313] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-25 05:40:02,452 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains.d] at time 05:40:02.451972 duration_in_ms=1.989
2019-05-25 05:40:02,452 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains] at time 05:40:02.452886
2019-05-25 05:40:02,453 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/grains]
2019-05-25 05:40:02,454 [salt.state       :300 ][INFO    ][12313] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-25 05:40:02,454 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains] at time 05:40:02.454304 duration_in_ms=1.418
2019-05-25 05:40:02,454 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains.d/placeholder] at time 05:40:02.454936
2019-05-25 05:40:02,455 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-25 05:40:02,456 [salt.state       :300 ][INFO    ][12313] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-25 05:40:02,456 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains.d/placeholder] at time 05:40:02.456304 duration_in_ms=1.368
2019-05-25 05:40:02,457 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains.d/sphinx] at time 05:40:02.456946
2019-05-25 05:40:02,457 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-25 05:40:02,471 [salt.state       :300 ][INFO    ][12313] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-25 05:40:02,472 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains.d/sphinx] at time 05:40:02.472251 duration_in_ms=15.306
2019-05-25 05:40:02,475 [salt.state       :1780][INFO    ][12313] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.475132
2019-05-25 05:40:02,475 [salt.state       :1813][INFO    ][12313] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-25 05:40:02,476 [salt.state       :300 ][INFO    ][12313] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-25 05:40:02,476 [salt.state       :1951][INFO    ][12313] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.476288 duration_in_ms=1.156
2019-05-25 05:40:02,476 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains.d/dns_records] at time 05:40:02.476933
2019-05-25 05:40:02,477 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-25 05:40:02,489 [salt.state       :300 ][INFO    ][12313] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-25 05:40:02,490 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains.d/dns_records] at time 05:40:02.490084 duration_in_ms=13.151
2019-05-25 05:40:02,491 [salt.state       :1780][INFO    ][12313] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.491300
2019-05-25 05:40:02,491 [salt.state       :1813][INFO    ][12313] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-25 05:40:02,492 [salt.state       :300 ][INFO    ][12313] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-25 05:40:02,492 [salt.state       :1951][INFO    ][12313] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.492423 duration_in_ms=1.123
2019-05-25 05:40:02,493 [salt.state       :1780][INFO    ][12313] Running state [/etc/salt/grains.d/salt] at time 05:40:02.493065
2019-05-25 05:40:02,493 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-25 05:40:02,507 [salt.state       :300 ][INFO    ][12313] File /etc/salt/grains.d/salt is in the correct state
2019-05-25 05:40:02,508 [salt.state       :1951][INFO    ][12313] Completed state [/etc/salt/grains.d/salt] at time 05:40:02.508107 duration_in_ms=15.041
2019-05-25 05:40:02,509 [salt.state       :1780][INFO    ][12313] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.509269
2019-05-25 05:40:02,509 [salt.state       :1813][INFO    ][12313] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-25 05:40:02,510 [salt.state       :300 ][INFO    ][12313] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-25 05:40:02,510 [salt.state       :1951][INFO    ][12313] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:40:02.510389 duration_in_ms=1.119
2019-05-25 05:40:02,512 [salt.state       :1780][INFO    ][12313] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:40:02.512926
2019-05-25 05:40:02,513 [salt.state       :1813][INFO    ][12313] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-25 05:40:02,513 [salt.state       :300 ][INFO    ][12313] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-25 05:40:02,514 [salt.state       :1951][INFO    ][12313] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:40:02.514066 duration_in_ms=1.14
2019-05-25 05:40:02,515 [salt.state       :1780][INFO    ][12313] Running state [mine.update] at time 05:40:02.514964
2019-05-25 05:40:02,515 [salt.state       :1813][INFO    ][12313] Executing state module.wait for [mine.update]
2019-05-25 05:40:02,515 [salt.state       :300 ][INFO    ][12313] No changes made for mine.update
2019-05-25 05:40:02,516 [salt.state       :1951][INFO    ][12313] Completed state [mine.update] at time 05:40:02.516011 duration_in_ms=1.048
2019-05-25 05:40:02,516 [salt.state       :1780][INFO    ][12313] Running state [ca-certificates] at time 05:40:02.516329
2019-05-25 05:40:02,516 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [ca-certificates]
2019-05-25 05:40:02,525 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,526 [salt.state       :1951][INFO    ][12313] Completed state [ca-certificates] at time 05:40:02.526205 duration_in_ms=9.876
2019-05-25 05:40:02,527 [salt.state       :1780][INFO    ][12313] Running state [update-ca-certificates] at time 05:40:02.527097
2019-05-25 05:40:02,527 [salt.state       :1813][INFO    ][12313] Executing state cmd.wait for [update-ca-certificates]
2019-05-25 05:40:02,527 [salt.state       :300 ][INFO    ][12313] No changes made for update-ca-certificates
2019-05-25 05:40:02,528 [salt.state       :1951][INFO    ][12313] Completed state [update-ca-certificates] at time 05:40:02.528140 duration_in_ms=1.044
2019-05-25 05:40:02,528 [salt.state       :1780][INFO    ][12313] Running state [iptables] at time 05:40:02.528443
2019-05-25 05:40:02,528 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [iptables]
2019-05-25 05:40:02,537 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,537 [salt.state       :1951][INFO    ][12313] Completed state [iptables] at time 05:40:02.537498 duration_in_ms=9.054
2019-05-25 05:40:02,537 [salt.state       :1780][INFO    ][12313] Running state [iptables-persistent] at time 05:40:02.537810
2019-05-25 05:40:02,538 [salt.state       :1813][INFO    ][12313] Executing state pkg.installed for [iptables-persistent]
2019-05-25 05:40:02,546 [salt.state       :300 ][INFO    ][12313] All specified packages are already installed
2019-05-25 05:40:02,546 [salt.state       :1951][INFO    ][12313] Completed state [iptables-persistent] at time 05:40:02.546453 duration_in_ms=8.643
2019-05-25 05:40:02,547 [salt.state       :1780][INFO    ][12313] Running state [iptables_modules_v4_load] at time 05:40:02.547660
2019-05-25 05:40:02,548 [salt.state       :1813][INFO    ][12313] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-25 05:40:02,548 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'lsmod' in directory '/root'
2019-05-25 05:40:02,573 [salt.state       :300 ][INFO    ][12313] Kernel modules iptable_filter, ip_tables are already present
2019-05-25 05:40:02,574 [salt.state       :1951][INFO    ][12313] Completed state [iptables_modules_v4_load] at time 05:40:02.574116 duration_in_ms=26.455
2019-05-25 05:40:02,575 [salt.state       :1780][INFO    ][12313] Running state [/etc/iptables/rules.v4] at time 05:40:02.575165
2019-05-25 05:40:02,575 [salt.state       :1813][INFO    ][12313] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-25 05:40:02,693 [salt.state       :300 ][INFO    ][12313] File /etc/iptables/rules.v4 is in the correct state
2019-05-25 05:40:02,693 [salt.state       :1951][INFO    ][12313] Completed state [/etc/iptables/rules.v4] at time 05:40:02.693923 duration_in_ms=118.758
2019-05-25 05:40:02,695 [salt.state       :1780][INFO    ][12313] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:40:02.695098
2019-05-25 05:40:02,695 [salt.state       :1813][INFO    ][12313] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-25 05:40:02,696 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-25 05:40:02,716 [salt.state       :300 ][INFO    ][12313] onlyif execution failed
2019-05-25 05:40:02,716 [salt.state       :1951][INFO    ][12313] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:40:02.716645 duration_in_ms=21.545
2019-05-25 05:40:02,718 [salt.state       :1780][INFO    ][12313] Running state [netfilter-persistent] at time 05:40:02.718201
2019-05-25 05:40:02,718 [salt.state       :1813][INFO    ][12313] Executing state service.running for [netfilter-persistent]
2019-05-25 05:40:02,719 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:02,740 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-25 05:40:02,759 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-25 05:40:02,777 [salt.state       :300 ][INFO    ][12313] The service netfilter-persistent is already running
2019-05-25 05:40:02,778 [salt.state       :1951][INFO    ][12313] Completed state [netfilter-persistent] at time 05:40:02.778136 duration_in_ms=59.934
2019-05-25 05:40:02,779 [salt.state       :1780][INFO    ][12313] Running state [iptables_extra.remove_stale_tables] at time 05:40:02.779427
2019-05-25 05:40:02,779 [salt.state       :1813][INFO    ][12313] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-25 05:40:02,780 [salt.state       :300 ][INFO    ][12313] No changes made for iptables_extra.remove_stale_tables
2019-05-25 05:40:02,780 [salt.state       :1951][INFO    ][12313] Completed state [iptables_extra.remove_stale_tables] at time 05:40:02.780808 duration_in_ms=1.382
2019-05-25 05:40:02,781 [salt.state       :1780][INFO    ][12313] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:40:02.781186
2019-05-25 05:40:02,781 [salt.state       :1813][INFO    ][12313] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-25 05:40:02,782 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12313] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-25 05:40:02,798 [salt.state       :300 ][INFO    ][12313] onlyif execution failed
2019-05-25 05:40:02,799 [salt.state       :1951][INFO    ][12313] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:40:02.799345 duration_in_ms=18.159
2019-05-25 05:40:02,801 [salt.state       :1780][INFO    ][12313] Running state [/etc/iptables/rules.v6] at time 05:40:02.801046
2019-05-25 05:40:02,801 [salt.state       :1813][INFO    ][12313] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-25 05:40:02,802 [salt.state       :300 ][INFO    ][12313] File /etc/iptables/rules.v6 is not present
2019-05-25 05:40:02,802 [salt.state       :1951][INFO    ][12313] Completed state [/etc/iptables/rules.v6] at time 05:40:02.802781 duration_in_ms=1.735
2019-05-25 05:40:02,804 [salt.state       :1780][INFO    ][12313] Running state [iptables_extra.flush_all] at time 05:40:02.803987
2019-05-25 05:40:02,804 [salt.state       :1813][INFO    ][12313] Executing state module.wait for [iptables_extra.flush_all]
2019-05-25 05:40:02,805 [salt.state       :300 ][INFO    ][12313] No changes made for iptables_extra.flush_all
2019-05-25 05:40:02,805 [salt.state       :1951][INFO    ][12313] Completed state [iptables_extra.flush_all] at time 05:40:02.805362 duration_in_ms=1.376
2019-05-25 05:40:02,842 [salt.minion      :1711][INFO    ][12313] Returning information for job: 20190525053954983036
2019-05-25 05:40:03,493 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054003480086
2019-05-25 05:40:03,517 [salt.minion      :1432][INFO    ][12388] Starting a new job with PID 12388
2019-05-25 05:40:04,272 [salt.state       :915 ][INFO    ][12388] Loading fresh modules for state activity
2019-05-25 05:40:04,931 [salt.state       :1780][INFO    ][12388] Running state [maas-rack-controller] at time 05:40:04.931201
2019-05-25 05:40:04,931 [salt.state       :1813][INFO    ][12388] Executing state pkg.installed for [maas-rack-controller]
2019-05-25 05:40:04,932 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12388] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-25 05:40:05,040 [salt.state       :300 ][INFO    ][12388] All specified packages are already installed
2019-05-25 05:40:05,040 [salt.state       :1951][INFO    ][12388] Completed state [maas-rack-controller] at time 05:40:05.040893 duration_in_ms=109.692
2019-05-25 05:40:05,041 [salt.state       :1780][INFO    ][12388] Running state [ipmitool] at time 05:40:05.041283
2019-05-25 05:40:05,041 [salt.state       :1813][INFO    ][12388] Executing state pkg.installed for [ipmitool]
2019-05-25 05:40:05,049 [salt.state       :300 ][INFO    ][12388] All specified packages are already installed
2019-05-25 05:40:05,049 [salt.state       :1951][INFO    ][12388] Completed state [ipmitool] at time 05:40:05.049542 duration_in_ms=8.259
2019-05-25 05:40:05,053 [salt.state       :1780][INFO    ][12388] Running state [/etc/maas/rackd.conf] at time 05:40:05.053147
2019-05-25 05:40:05,053 [salt.state       :1813][INFO    ][12388] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-25 05:40:05,054 [salt.state       :300 ][INFO    ][12388] No changes needed to be made
2019-05-25 05:40:05,055 [salt.state       :1951][INFO    ][12388] Completed state [/etc/maas/rackd.conf] at time 05:40:05.054973 duration_in_ms=1.826
2019-05-25 05:40:05,055 [salt.state       :1780][INFO    ][12388] Running state [/etc/maas/rackd.conf] at time 05:40:05.055244
2019-05-25 05:40:05,055 [salt.state       :1813][INFO    ][12388] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-25 05:40:05,055 [salt.loaded.int.states.file:2298][WARNING ][12388] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-25 05:40:05,056 [salt.state       :300 ][INFO    ][12388] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-25 05:40:05,056 [salt.state       :1951][INFO    ][12388] Completed state [/etc/maas/rackd.conf] at time 05:40:05.056737 duration_in_ms=1.493
2019-05-25 05:40:05,057 [salt.state       :1780][INFO    ][12388] Running state [maas-rackd] at time 05:40:05.057858
2019-05-25 05:40:05,058 [salt.state       :1813][INFO    ][12388] Executing state service.running for [maas-rackd]
2019-05-25 05:40:05,058 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12388] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:05,094 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12388] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-25 05:40:05,111 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12388] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-25 05:40:05,128 [salt.state       :300 ][INFO    ][12388] The service maas-rackd is already running
2019-05-25 05:40:05,129 [salt.state       :1951][INFO    ][12388] Completed state [maas-rackd] at time 05:40:05.129051 duration_in_ms=71.192
2019-05-25 05:40:05,130 [salt.minion      :1711][INFO    ][12388] Returning information for job: 20190525054003480086
2019-05-25 05:40:05,757 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054005743686
2019-05-25 05:40:05,781 [salt.minion      :1432][INFO    ][12411] Starting a new job with PID 12411
2019-05-25 05:40:06,546 [salt.state       :915 ][INFO    ][12411] Loading fresh modules for state activity
2019-05-25 05:40:07,320 [salt.state       :1780][INFO    ][12411] Running state [maas-region-controller] at time 05:40:07.320607
2019-05-25 05:40:07,320 [salt.state       :1813][INFO    ][12411] Executing state pkg.installed for [maas-region-controller]
2019-05-25 05:40:07,321 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-25 05:40:07,422 [salt.state       :300 ][INFO    ][12411] All specified packages are already installed
2019-05-25 05:40:07,422 [salt.state       :1951][INFO    ][12411] Completed state [maas-region-controller] at time 05:40:07.422892 duration_in_ms=102.284
2019-05-25 05:40:07,423 [salt.state       :1780][INFO    ][12411] Running state [python-oauth] at time 05:40:07.423310
2019-05-25 05:40:07,423 [salt.state       :1813][INFO    ][12411] Executing state pkg.installed for [python-oauth]
2019-05-25 05:40:07,432 [salt.state       :300 ][INFO    ][12411] All specified packages are already installed
2019-05-25 05:40:07,432 [salt.state       :1951][INFO    ][12411] Completed state [python-oauth] at time 05:40:07.432313 duration_in_ms=9.002
2019-05-25 05:40:07,436 [salt.state       :1780][INFO    ][12411] Running state [/etc/maas/regiond.conf] at time 05:40:07.436252
2019-05-25 05:40:07,436 [salt.state       :1813][INFO    ][12411] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-25 05:40:07,479 [salt.state       :300 ][INFO    ][12411] No changes needed to be made
2019-05-25 05:40:07,479 [salt.state       :1951][INFO    ][12411] Completed state [/etc/maas/regiond.conf] at time 05:40:07.479839 duration_in_ms=43.586
2019-05-25 05:40:07,480 [salt.state       :1780][INFO    ][12411] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:40:07.480654
2019-05-25 05:40:07,481 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-25 05:40:07,586 [salt.state       :300 ][INFO    ][12411] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-25 05:40:07,587 [salt.state       :1951][INFO    ][12411] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:40:07.587155 duration_in_ms=106.501
2019-05-25 05:40:07,588 [salt.state       :1780][INFO    ][12411] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:40:07.588162
2019-05-25 05:40:07,588 [salt.state       :1813][INFO    ][12411] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-25 05:40:07,607 [salt.state       :300 ][INFO    ][12411] No changes needed to be made
2019-05-25 05:40:07,607 [salt.state       :1951][INFO    ][12411] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:40:07.607572 duration_in_ms=19.408
2019-05-25 05:40:07,608 [salt.state       :1780][INFO    ][12411] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:40:07.608629
2019-05-25 05:40:07,609 [salt.state       :1813][INFO    ][12411] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-25 05:40:07,630 [salt.state       :300 ][INFO    ][12411] No changes needed to be made
2019-05-25 05:40:07,630 [salt.state       :1951][INFO    ][12411] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:40:07.630474 duration_in_ms=21.845
2019-05-25 05:40:07,631 [salt.state       :1780][INFO    ][12411] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:40:07.631104
2019-05-25 05:40:07,631 [salt.state       :1813][INFO    ][12411] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-25 05:40:07,660 [salt.state       :300 ][INFO    ][12411] No changes needed to be made
2019-05-25 05:40:07,661 [salt.state       :1951][INFO    ][12411] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:40:07.660975 duration_in_ms=29.872
2019-05-25 05:40:07,661 [salt.state       :1780][INFO    ][12411] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:40:07.661505
2019-05-25 05:40:07,661 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-25 05:40:07,673 [salt.state       :300 ][INFO    ][12411] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-25 05:40:07,673 [salt.state       :1951][INFO    ][12411] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:40:07.673224 duration_in_ms=11.718
2019-05-25 05:40:07,676 [salt.state       :1780][INFO    ][12411] Running state [a2enmod headers] at time 05:40:07.676791
2019-05-25 05:40:07,677 [salt.state       :1813][INFO    ][12411] Executing state cmd.run for [a2enmod headers]
2019-05-25 05:40:07,678 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command 'a2enmod headers' in directory '/root'
2019-05-25 05:40:07,730 [salt.state       :300 ][INFO    ][12411] {'pid': 12433, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-25 05:40:07,731 [salt.state       :1951][INFO    ][12411] Completed state [a2enmod headers] at time 05:40:07.731152 duration_in_ms=54.361
2019-05-25 05:40:07,731 [salt.state       :1780][INFO    ][12411] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:40:07.731460
2019-05-25 05:40:07,731 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-25 05:40:07,743 [salt.state       :300 ][INFO    ][12411] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-25 05:40:07,743 [salt.state       :1951][INFO    ][12411] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:40:07.743173 duration_in_ms=11.713
2019-05-25 05:40:07,743 [salt.state       :1780][INFO    ][12411] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:40:07.743612
2019-05-25 05:40:07,743 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-25 05:40:07,796 [salt.state       :300 ][INFO    ][12411] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-25 05:40:07,797 [salt.state       :1951][INFO    ][12411] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:40:07.797064 duration_in_ms=53.451
2019-05-25 05:40:07,798 [salt.state       :1780][INFO    ][12411] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:40:07.797925
2019-05-25 05:40:07,798 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-25 05:40:07,874 [salt.state       :300 ][INFO    ][12411] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-25 05:40:07,874 [salt.state       :1951][INFO    ][12411] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:40:07.874579 duration_in_ms=76.655
2019-05-25 05:40:07,875 [salt.state       :1780][INFO    ][12411] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:40:07.875227
2019-05-25 05:40:07,875 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-25 05:40:07,940 [salt.state       :300 ][INFO    ][12411] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-25 05:40:07,940 [salt.state       :1951][INFO    ][12411] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:40:07.940360 duration_in_ms=65.132
2019-05-25 05:40:07,940 [salt.state       :1780][INFO    ][12411] Running state [/root/.pgpass] at time 05:40:07.940700
2019-05-25 05:40:07,941 [salt.state       :1813][INFO    ][12411] Executing state file.managed for [/root/.pgpass]
2019-05-25 05:40:07,993 [salt.state       :300 ][INFO    ][12411] File /root/.pgpass is in the correct state
2019-05-25 05:40:07,994 [salt.state       :1951][INFO    ][12411] Completed state [/root/.pgpass] at time 05:40:07.994186 duration_in_ms=53.486
2019-05-25 05:40:08,000 [salt.state       :1780][INFO    ][12411] Running state [maas-region syncdb --noinput] at time 05:40:08.000013
2019-05-25 05:40:08,000 [salt.state       :1813][INFO    ][12411] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-25 05:40:08,001 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-25 05:40:09,851 [salt.state       :300 ][INFO    ][12411] {'pid': 12446, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: maasserver, piston3, sites, sessions, contenttypes, metadataserver, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-25 05:40:09,852 [salt.state       :1951][INFO    ][12411] Completed state [maas-region syncdb --noinput] at time 05:40:09.852455 duration_in_ms=1852.44
2019-05-25 05:40:09,853 [salt.state       :2022][WARNING ][12411] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-25 05:40:09,854 [salt.state       :1780][INFO    ][12411] Running state [maas-regiond] at time 05:40:09.854189
2019-05-25 05:40:09,854 [salt.state       :1813][INFO    ][12411] Executing state service.running for [maas-regiond]
2019-05-25 05:40:09,855 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:09,888 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-25 05:40:09,903 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-25 05:40:09,917 [salt.state       :300 ][INFO    ][12411] The service maas-regiond is already running
2019-05-25 05:40:09,918 [salt.state       :1951][INFO    ][12411] Completed state [maas-regiond] at time 05:40:09.918167 duration_in_ms=63.978
2019-05-25 05:40:09,919 [salt.state       :1780][INFO    ][12411] Running state [bind9] at time 05:40:09.919354
2019-05-25 05:40:09,919 [salt.state       :1813][INFO    ][12411] Executing state service.running for [bind9]
2019-05-25 05:40:09,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:09,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-25 05:40:09,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-25 05:40:09,962 [salt.state       :300 ][INFO    ][12411] The service bind9 is already running
2019-05-25 05:40:09,962 [salt.state       :1951][INFO    ][12411] Completed state [bind9] at time 05:40:09.962909 duration_in_ms=43.555
2019-05-25 05:40:09,964 [salt.state       :1780][INFO    ][12411] Running state [apache2] at time 05:40:09.964398
2019-05-25 05:40:09,964 [salt.state       :1813][INFO    ][12411] Executing state service.running for [apache2]
2019-05-25 05:40:09,965 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-25 05:40:09,980 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-25 05:40:09,996 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-25 05:40:10,016 [salt.state       :300 ][INFO    ][12411] The service apache2 is already running
2019-05-25 05:40:10,017 [salt.state       :1951][INFO    ][12411] Completed state [apache2] at time 05:40:10.016937 duration_in_ms=52.539
2019-05-25 05:40:10,018 [salt.state       :1780][INFO    ][12411] Running state [maasng.wait_for_http_code] at time 05:40:10.018596
2019-05-25 05:40:10,019 [salt.state       :1813][INFO    ][12411] Executing state module.run for [maasng.wait_for_http_code]
2019-05-25 05:40:10,019 [salt.utils.decorators:613 ][WARNING ][12411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:10,026 [salt.state       :300 ][INFO    ][12411] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-25 05:40:10,027 [salt.state       :1951][INFO    ][12411] Completed state [maasng.wait_for_http_code] at time 05:40:10.027140 duration_in_ms=8.544
2019-05-25 05:40:10,027 [salt.state       :1780][INFO    ][12411] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:40:10.027918
2019-05-25 05:40:10,028 [salt.state       :1813][INFO    ][12411] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-25 05:40:10,028 [salt.state       :300 ][INFO    ][12411] /var/lib/maas/.setup_admin exists
2019-05-25 05:40:10,028 [salt.state       :1951][INFO    ][12411] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:40:10.028847 duration_in_ms=0.929
2019-05-25 05:40:10,029 [salt.state       :1780][INFO    ][12411] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:10.029452
2019-05-25 05:40:10,029 [salt.state       :1813][INFO    ][12411] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:40:10,030 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12411] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:40:11,338 [salt.state       :300 ][INFO    ][12411] {'pid': 12465, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:40:11,339 [salt.state       :1951][INFO    ][12411] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:11.338991 duration_in_ms=1309.537
2019-05-25 05:40:11,347 [salt.state       :1780][INFO    ][12411] Running state [maas_region_boot_source_resources_mirror] at time 05:40:11.347140
2019-05-25 05:40:11,347 [salt.state       :1813][INFO    ][12411] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-25 05:40:11,438 [salt.state       :300 ][INFO    ][12411] {'changes': {}}
2019-05-25 05:40:11,438 [salt.state       :1951][INFO    ][12411] Completed state [maas_region_boot_source_resources_mirror] at time 05:40:11.438638 duration_in_ms=91.498
2019-05-25 05:40:11,439 [salt.state       :1780][INFO    ][12411] Running state [maasng.boot_resources_import] at time 05:40:11.439740
2019-05-25 05:40:11,440 [salt.state       :1813][INFO    ][12411] Executing state module.run for [maasng.boot_resources_import]
2019-05-25 05:40:11,440 [salt.utils.decorators:613 ][WARNING ][12411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:11,553 [salt.loaded.ext.module.maasng:1600][INFO    ][12411] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-25 05:40:16,610 [salt.loaded.ext.module.maasng:1600][INFO    ][12411] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-25 05:40:20,816 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054020802858
2019-05-25 05:40:20,840 [salt.minion      :1432][INFO    ][12489] Starting a new job with PID 12489
2019-05-25 05:40:20,863 [salt.minion      :1711][INFO    ][12489] Returning information for job: 20190525054020802858
2019-05-25 05:40:21,755 [salt.loaded.ext.module.maasng:1600][INFO    ][12411] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-25 05:40:26,862 [salt.state       :300 ][INFO    ][12411] {'ret': True}
2019-05-25 05:40:26,862 [salt.state       :1951][INFO    ][12411] Completed state [maasng.boot_resources_import] at time 05:40:26.862630 duration_in_ms=15422.888
2019-05-25 05:40:26,863 [salt.state       :1780][INFO    ][12411] Running state [maas_region_boot_sources_selection_xenial] at time 05:40:26.863898
2019-05-25 05:40:26,864 [salt.state       :1813][INFO    ][12411] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-25 05:40:27,071 [salt.state       :300 ][INFO    ][12411] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-25 05:40:27,072 [salt.state       :1951][INFO    ][12411] Completed state [maas_region_boot_sources_selection_xenial] at time 05:40:27.072161 duration_in_ms=208.262
2019-05-25 05:40:27,073 [salt.state       :1780][INFO    ][12411] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:40:27.073613
2019-05-25 05:40:27,074 [salt.state       :1813][INFO    ][12411] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-25 05:40:27,074 [salt.utils.decorators:613 ][WARNING ][12411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:27,075 [salt.loaded.ext.module.maasng:1771][INFO    ][12411] boot-sources sync initiated for ALL Rack's
2019-05-25 05:40:28,026 [salt.state       :300 ][INFO    ][12411] {'ret': True}
2019-05-25 05:40:28,027 [salt.state       :1951][INFO    ][12411] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:40:28.027405 duration_in_ms=953.791
2019-05-25 05:40:28,029 [salt.state       :1780][INFO    ][12411] Running state [maas.process_maas_config] at time 05:40:28.029610
2019-05-25 05:40:28,030 [salt.state       :1813][INFO    ][12411] Executing state module.run for [maas.process_maas_config]
2019-05-25 05:40:28,030 [salt.utils.decorators:613 ][WARNING ][12411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:28,031 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=enable_http_proxy value=True
2019-05-25 05:40:28,088 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=upstream_dns value=8.8.8.8
2019-05-25 05:40:28,162 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=commissioning_distro_series value=xenial
2019-05-25 05:40:31,159 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=default_osystem value=ubuntu
2019-05-25 05:40:31,227 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=active_discovery_interval value=600
2019-05-25 05:40:31,288 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=dnssec_validation value=no
2019-05-25 05:40:31,341 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=maas_name value=mas01
2019-05-25 05:40:31,389 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=network_discovery value=enabled
2019-05-25 05:40:31,497 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=enable_third_party_drivers value=True
2019-05-25 05:40:31,558 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=default_storage_layout value=lvm
2019-05-25 05:40:31,610 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=ntp_external_only value=True
2019-05-25 05:40:31,676 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-25 05:40:31,728 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=default_distro_series value=xenial
2019-05-25 05:40:31,788 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-25 05:40:31,872 [salt.state       :300 ][INFO    ][12411] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-25 05:40:31,873 [salt.state       :1951][INFO    ][12411] Completed state [maas.process_maas_config] at time 05:40:31.872954 duration_in_ms=3843.343
2019-05-25 05:40:31,873 [salt.state       :1780][INFO    ][12411] Running state [pxe_admin] at time 05:40:31.873853
2019-05-25 05:40:31,874 [salt.state       :1813][INFO    ][12411] Executing state maasng.fabric_present for [pxe_admin]
2019-05-25 05:40:31,931 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:31,991 [salt.loaded.ext.module.maasng:1008][WARNING ][12411] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-25 05:40:31,991 [salt.loaded.ext.module.maasng:1011][WARNING ][12411] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-25 05:40:32,069 [salt.state       :300 ][INFO    ][12411] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-25 05:40:32,070 [salt.state       :1951][INFO    ][12411] Completed state [pxe_admin] at time 05:40:32.069909 duration_in_ms=196.056
2019-05-25 05:40:32,070 [salt.state       :1780][INFO    ][12411] Running state [vlan 0] at time 05:40:32.070322
2019-05-25 05:40:32,070 [salt.state       :1813][INFO    ][12411] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-25 05:40:32,122 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ea4x7r', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-25 05:40:32,227 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ea4x7r', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:32,539 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ea4x7r', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-25 05:40:32,618 [salt.state       :300 ][INFO    ][12411] {'new': 'Vlan untagged was updated'}
2019-05-25 05:40:32,618 [salt.state       :1951][INFO    ][12411] Completed state [vlan 0] at time 05:40:32.618547 duration_in_ms=548.224
2019-05-25 05:40:32,620 [salt.state       :1780][INFO    ][12411] Running state [192.168.11.0/24] at time 05:40:32.620078
2019-05-25 05:40:32,620 [salt.state       :1813][INFO    ][12411] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-25 05:40:32,832 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:32,833 [salt.loaded.ext.module.maasng:1235][WARNING ][12411] Ignoring parameter vlan:0
2019-05-25 05:40:32,897 [salt.state       :300 ][INFO    ][12411] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-25 05:40:32,897 [salt.state       :1951][INFO    ][12411] Completed state [192.168.11.0/24] at time 05:40:32.897420 duration_in_ms=277.342
2019-05-25 05:40:32,898 [salt.state       :1780][INFO    ][12411] Running state [maas_create_iprange_1] at time 05:40:32.898626
2019-05-25 05:40:32,899 [salt.state       :1813][INFO    ][12411] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-25 05:40:32,944 [salt.state       :300 ][INFO    ][12411] Iprange maas_create_iprange_1 already exist.
2019-05-25 05:40:32,944 [salt.state       :1951][INFO    ][12411] Completed state [maas_create_iprange_1] at time 05:40:32.944416 duration_in_ms=45.79
2019-05-25 05:40:32,944 [salt.state       :1780][INFO    ][12411] Running state [vlan 0] at time 05:40:32.944872
2019-05-25 05:40:32,945 [salt.state       :1813][INFO    ][12411] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-25 05:40:33,010 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ea4x7r', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:33,130 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'ea4x7r', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:33,383 [salt.loaded.ext.module.maasng:945 ][INFO    ][12411] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ea4x7r', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-05-25 05:40:33,480 [salt.state       :300 ][INFO    ][12411] {'new': 'Vlan untagged was updated'}
2019-05-25 05:40:33,480 [salt.state       :1951][INFO    ][12411] Completed state [vlan 0] at time 05:40:33.480720 duration_in_ms=535.846
2019-05-25 05:40:33,481 [salt.state       :1780][INFO    ][12411] Running state [opnfv] at time 05:40:33.481722
2019-05-25 05:40:33,482 [salt.state       :1813][INFO    ][12411] Executing state maasng.sshkey_present for [opnfv]
2019-05-25 05:40:33,527 [salt.loaded.ext.module.maasng:1903][INFO    ][12411] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-25 05:40:33,528 [salt.state       :300 ][INFO    ][12411] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-25 05:40:33,528 [salt.state       :1951][INFO    ][12411] Completed state [opnfv] at time 05:40:33.528388 duration_in_ms=46.667
2019-05-25 05:40:33,529 [salt.state       :1780][INFO    ][12411] Running state [maas.process_tags] at time 05:40:33.529130
2019-05-25 05:40:33,529 [salt.state       :1813][INFO    ][12411] Executing state module.run for [maas.process_tags]
2019-05-25 05:40:33,530 [salt.utils.decorators:613 ][WARNING ][12411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:33,588 [salt.loaded.ext.module.maas:92  ][INFO    ][12411] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-25 05:40:33,648 [salt.state       :300 ][INFO    ][12411] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-25 05:40:33,649 [salt.state       :1951][INFO    ][12411] Completed state [maas.process_tags] at time 05:40:33.649007 duration_in_ms=119.874
2019-05-25 05:40:33,653 [salt.minion      :1711][INFO    ][12411] Returning information for job: 20190525054005743686
2019-05-25 05:40:34,156 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054034145598
2019-05-25 05:40:34,175 [salt.minion      :1432][INFO    ][12887] Starting a new job with PID 12887
2019-05-25 05:40:37,939 [salt.state       :915 ][INFO    ][12887] Loading fresh modules for state activity
2019-05-25 05:40:38,035 [salt.state       :1780][INFO    ][12887] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:38.035860
2019-05-25 05:40:38,036 [salt.state       :1813][INFO    ][12887] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:40:38,038 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12887] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:40:39,493 [salt.state       :300 ][INFO    ][12887] {'pid': 12911, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:40:39,493 [salt.state       :1951][INFO    ][12887] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:40:39.493447 duration_in_ms=1457.589
2019-05-25 05:40:39,494 [salt.state       :1780][INFO    ][12887] Running state [maas.process_machines] at time 05:40:39.494669
2019-05-25 05:40:39,494 [salt.state       :1813][INFO    ][12887] Executing state module.run for [maas.process_machines]
2019-05-25 05:40:39,495 [salt.utils.decorators:613 ][WARNING ][12887] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:40:40,223 [salt.loaded.ext.module.maas:412 ][WARNING ][12887] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:40:40,223 [salt.loaded.ext.module.maas:92  ][INFO    ][12887] 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=hn8hrs architecture=amd64/generic power_parameters_power_user=admin
2019-05-25 05:40:41,491 [salt.loaded.ext.module.maas:412 ][WARNING ][12887] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:40:41,492 [salt.loaded.ext.module.maas:92  ][INFO    ][12887] 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=sr44wc architecture=amd64/generic power_parameters_power_user=admin
2019-05-25 05:40:42,742 [salt.loaded.ext.module.maas:412 ][WARNING ][12887] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:40:42,743 [salt.loaded.ext.module.maas:92  ][INFO    ][12887] 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=yb8ywt architecture=amd64/generic power_parameters_power_user=admin
2019-05-25 05:40:44,049 [salt.loaded.ext.module.maas:412 ][WARNING ][12887] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:40:44,049 [salt.loaded.ext.module.maas:92  ][INFO    ][12887] 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=r37qkb architecture=amd64/generic power_parameters_power_user=admin
2019-05-25 05:40:45,340 [salt.loaded.ext.module.maas:412 ][WARNING ][12887] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-25 05:40:45,341 [salt.loaded.ext.module.maas:92  ][INFO    ][12887] 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=nbgetb architecture=amd64/generic power_parameters_power_user=admin
2019-05-25 05:40:46,353 [salt.state       :300 ][INFO    ][12887] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-25 05:40:46,353 [salt.state       :1951][INFO    ][12887] Completed state [maas.process_machines] at time 05:40:46.353568 duration_in_ms=6858.896
2019-05-25 05:40:46,357 [salt.minion      :1711][INFO    ][12887] Returning information for job: 20190525054034145598
2019-05-25 05:41:18,971 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054118922792
2019-05-25 05:41:18,992 [salt.minion      :1432][INFO    ][13142] Starting a new job with PID 13142
2019-05-25 05:41:22,876 [salt.state       :915 ][INFO    ][13142] Loading fresh modules for state activity
2019-05-25 05:41:22,970 [salt.state       :1780][INFO    ][13142] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:41:22.970085
2019-05-25 05:41:22,970 [salt.state       :1813][INFO    ][13142] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:41:22,972 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13142] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:41:24,280 [salt.state       :300 ][INFO    ][13142] {'pid': 13165, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:41:24,281 [salt.state       :1951][INFO    ][13142] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:41:24.281423 duration_in_ms=1311.337
2019-05-25 05:41:24,283 [salt.state       :1780][INFO    ][13142] Running state [maas.wait_for_machine_status] at time 05:41:24.283737
2019-05-25 05:41:24,284 [salt.state       :1813][INFO    ][13142] Executing state module.run for [maas.wait_for_machine_status]
2019-05-25 05:41:24,284 [salt.utils.decorators:613 ][WARNING ][13142] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:41:26,842 [salt.loaded.ext.module.maas:993 ][INFO    ][13142] Machine r37qkb mark broken
2019-05-25 05:41:27,365 [salt.loaded.ext.module.maas:996 ][INFO    ][13142] Machine r37qkb mark fixed
2019-05-25 05:41:28,543 [salt.loaded.ext.module.maas:684 ][INFO    ][13142] deploymachines hwe_kernel=hwe-16.04 system_id=r37qkb distro_series=xenial
2019-05-25 05:41:31,513 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.78131485s left)
2019-05-25 05:41:34,057 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054134045165
2019-05-25 05:41:34,080 [salt.minion      :1432][INFO    ][13258] Starting a new job with PID 13258
2019-05-25 05:41:34,107 [salt.minion      :1711][INFO    ][13258] Returning information for job: 20190525054134045165
2019-05-25 05:42:04,115 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054204103245
2019-05-25 05:42:04,138 [salt.minion      :1432][INFO    ][13285] Starting a new job with PID 13285
2019-05-25 05:42:04,161 [salt.minion      :1711][INFO    ][13285] Returning information for job: 20190525054204103245
2019-05-25 05:42:04,613 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.68152285s left)
2019-05-25 05:42:34,181 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054234131600
2019-05-25 05:42:34,203 [salt.minion      :1432][INFO    ][13335] Starting a new job with PID 13335
2019-05-25 05:42:34,229 [salt.minion      :1711][INFO    ][13335] Returning information for job: 20190525054234131600
2019-05-25 05:42:38,078 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1426.21604991s left)
2019-05-25 05:43:04,229 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054304216183
2019-05-25 05:43:04,253 [salt.minion      :1432][INFO    ][13353] Starting a new job with PID 13353
2019-05-25 05:43:04,278 [salt.minion      :1711][INFO    ][13353] Returning information for job: 20190525054304216183
2019-05-25 05:43:11,464 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.83012486s left)
2019-05-25 05:43:34,285 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054334270423
2019-05-25 05:43:34,309 [salt.minion      :1432][INFO    ][13493] Starting a new job with PID 13493
2019-05-25 05:43:34,336 [salt.minion      :1711][INFO    ][13493] Returning information for job: 20190525054334270423
2019-05-25 05:43:45,092 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.20295596s left)
2019-05-25 05:44:04,346 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054404333065
2019-05-25 05:44:04,370 [salt.minion      :1432][INFO    ][13518] Starting a new job with PID 13518
2019-05-25 05:44:04,395 [salt.minion      :1711][INFO    ][13518] Returning information for job: 20190525054404333065
2019-05-25 05:44:18,586 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.70888305s left)
2019-05-25 05:44:34,406 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054434393210
2019-05-25 05:44:34,430 [salt.minion      :1432][INFO    ][13691] Starting a new job with PID 13691
2019-05-25 05:44:34,454 [salt.minion      :1711][INFO    ][13691] Returning information for job: 20190525054434393210
2019-05-25 05:44:51,966 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1292.32825398s left)
2019-05-25 05:45:04,466 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054504453861
2019-05-25 05:45:04,491 [salt.minion      :1432][INFO    ][13713] Starting a new job with PID 13713
2019-05-25 05:45:04,515 [salt.minion      :1711][INFO    ][13713] Returning information for job: 20190525054504453861
2019-05-25 05:45:25,628 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1258.66635203s left)
2019-05-25 05:45:34,530 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054534518595
2019-05-25 05:45:34,551 [salt.minion      :1432][INFO    ][13794] Starting a new job with PID 13794
2019-05-25 05:45:34,575 [salt.minion      :1711][INFO    ][13794] Returning information for job: 20190525054534518595
2019-05-25 05:45:58,973 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1225.32117391s left)
2019-05-25 05:46:04,596 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054604582805
2019-05-25 05:46:04,620 [salt.minion      :1432][INFO    ][13815] Starting a new job with PID 13815
2019-05-25 05:46:04,644 [salt.minion      :1711][INFO    ][13815] Returning information for job: 20190525054604582805
2019-05-25 05:46:32,357 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1191.93727803s left)
2019-05-25 05:46:34,676 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054634662786
2019-05-25 05:46:34,699 [salt.minion      :1432][INFO    ][13974] Starting a new job with PID 13974
2019-05-25 05:46:34,724 [salt.minion      :1711][INFO    ][13974] Returning information for job: 20190525054634662786
2019-05-25 05:47:04,752 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054704739121
2019-05-25 05:47:04,776 [salt.minion      :1432][INFO    ][13998] Starting a new job with PID 13998
2019-05-25 05:47:04,800 [salt.minion      :1711][INFO    ][13998] Returning information for job: 20190525054704739121
2019-05-25 05:47:05,884 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1158.41019702s left)
2019-05-25 05:47:34,836 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054734821994
2019-05-25 05:47:34,859 [salt.minion      :1432][INFO    ][14117] Starting a new job with PID 14117
2019-05-25 05:47:34,884 [salt.minion      :1711][INFO    ][14117] Returning information for job: 20190525054734821994
2019-05-25 05:47:39,548 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1124.7469089s left)
2019-05-25 05:48:04,923 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054804909652
2019-05-25 05:48:04,948 [salt.minion      :1432][INFO    ][14137] Starting a new job with PID 14137
2019-05-25 05:48:04,971 [salt.minion      :1711][INFO    ][14137] Returning information for job: 20190525054804909652
2019-05-25 05:48:12,825 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1091.46998405s left)
2019-05-25 05:48:35,025 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054835012995
2019-05-25 05:48:35,048 [salt.minion      :1432][INFO    ][14230] Starting a new job with PID 14230
2019-05-25 05:48:35,075 [salt.minion      :1711][INFO    ][14230] Returning information for job: 20190525054835012995
2019-05-25 05:48:45,974 [salt.loaded.ext.module.maas:1023][INFO    ][13142] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1058.32052803s left)
2019-05-25 05:49:05,106 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command saltutil.find_job with jid 20190525054905091705
2019-05-25 05:49:05,134 [salt.minion      :1432][INFO    ][14278] Starting a new job with PID 14278
2019-05-25 05:49:05,170 [salt.minion      :1711][INFO    ][14278] Returning information for job: 20190525054905091705
2019-05-25 05:49:19,525 [salt.state       :300 ][INFO    ][13142] {'ret': True}
2019-05-25 05:49:19,525 [salt.state       :1951][INFO    ][13142] Completed state [maas.wait_for_machine_status] at time 05:49:19.525622 duration_in_ms=475241.884
2019-05-25 05:49:19,574 [salt.minion      :1711][INFO    ][13142] Returning information for job: 20190525054118922792
2019-05-25 05:49:20,221 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054920211386
2019-05-25 05:49:20,244 [salt.minion      :1432][INFO    ][14308] Starting a new job with PID 14308
2019-05-25 05:49:24,052 [salt.state       :915 ][INFO    ][14308] Loading fresh modules for state activity
2019-05-25 05:49:24,198 [salt.state       :1780][INFO    ][14308] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:24.198774
2019-05-25 05:49:24,199 [salt.state       :1813][INFO    ][14308] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:49:24,200 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14308] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:49:25,547 [salt.state       :300 ][INFO    ][14308] {'pid': 14333, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:49:25,548 [salt.state       :1951][INFO    ][14308] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:25.548052 duration_in_ms=1349.279
2019-05-25 05:49:25,549 [salt.state       :1780][INFO    ][14308] Running state [maas_machines_storage_cmp002_lvm] at time 05:49:25.549329
2019-05-25 05:49:25,549 [salt.state       :1813][INFO    ][14308] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-25 05:49:26,355 [salt.state       :300 ][INFO    ][14308] Machine cmp002 is not in Ready state.
2019-05-25 05:49:26,356 [salt.state       :1951][INFO    ][14308] Completed state [maas_machines_storage_cmp002_lvm] at time 05:49:26.356060 duration_in_ms=806.729
2019-05-25 05:49:26,356 [salt.state       :1780][INFO    ][14308] Running state [maas_machines_storage_cmp001_lvm] at time 05:49:26.356675
2019-05-25 05:49:26,357 [salt.state       :1813][INFO    ][14308] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-25 05:49:27,102 [salt.state       :300 ][INFO    ][14308] Machine cmp001 is not in Ready state.
2019-05-25 05:49:27,102 [salt.state       :1951][INFO    ][14308] Completed state [maas_machines_storage_cmp001_lvm] at time 05:49:27.102573 duration_in_ms=745.896
2019-05-25 05:49:27,107 [salt.minion      :1711][INFO    ][14308] Returning information for job: 20190525054920211386
2019-05-25 05:49:27,637 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054927622356
2019-05-25 05:49:27,655 [salt.minion      :1432][INFO    ][14370] Starting a new job with PID 14370
2019-05-25 05:49:28,279 [salt.state       :915 ][INFO    ][14370] Loading fresh modules for state activity
2019-05-25 05:49:28,324 [salt.state       :1780][INFO    ][14370] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:28.323984
2019-05-25 05:49:28,324 [salt.state       :1813][INFO    ][14370] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:49:28,325 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14370] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:49:29,585 [salt.state       :300 ][INFO    ][14370] {'pid': 14471, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:49:29,586 [salt.state       :1951][INFO    ][14370] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:29.586620 duration_in_ms=1262.634
2019-05-25 05:49:29,589 [salt.state       :1780][INFO    ][14370] Running state [maas.deploy_machines] at time 05:49:29.589192
2019-05-25 05:49:29,589 [salt.state       :1813][INFO    ][14370] Executing state module.run for [maas.deploy_machines]
2019-05-25 05:49:29,591 [salt.utils.decorators:613 ][WARNING ][14370] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:49:30,373 [salt.state       :300 ][INFO    ][14370] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-25 05:49:30,373 [salt.state       :1951][INFO    ][14370] Completed state [maas.deploy_machines] at time 05:49:30.373569 duration_in_ms=784.375
2019-05-25 05:49:30,377 [salt.minion      :1711][INFO    ][14370] Returning information for job: 20190525054927622356
2019-05-25 05:49:31,008 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command state.apply with jid 20190525054930998758
2019-05-25 05:49:31,030 [salt.minion      :1432][INFO    ][14506] Starting a new job with PID 14506
2019-05-25 05:49:31,789 [salt.state       :915 ][INFO    ][14506] Loading fresh modules for state activity
2019-05-25 05:49:31,838 [salt.state       :1780][INFO    ][14506] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:31.838003
2019-05-25 05:49:31,838 [salt.state       :1813][INFO    ][14506] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-25 05:49:31,839 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14506] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-25 05:49:33,277 [salt.state       :300 ][INFO    ][14506] {'pid': 14513, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-25 05:49:33,278 [salt.state       :1951][INFO    ][14506] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:33.278106 duration_in_ms=1440.103
2019-05-25 05:49:33,279 [salt.state       :1780][INFO    ][14506] Running state [maas.wait_for_machine_status] at time 05:49:33.279622
2019-05-25 05:49:33,279 [salt.state       :1813][INFO    ][14506] Executing state module.run for [maas.wait_for_machine_status]
2019-05-25 05:49:33,280 [salt.utils.decorators:613 ][WARNING ][14506] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-25 05:49:36,959 [salt.state       :300 ][INFO    ][14506] {'ret': True}
2019-05-25 05:49:36,960 [salt.state       :1951][INFO    ][14506] Completed state [maas.wait_for_machine_status] at time 05:49:36.960185 duration_in_ms=3680.561
2019-05-25 05:49:36,964 [salt.minion      :1711][INFO    ][14506] Returning information for job: 20190525054930998758
2019-05-25 06:19:30,707 [salt.utils.schedule:1377][INFO    ][5984] Running scheduled job: __mine_interval
2019-05-25 07:16:39,752 [salt.minion      :1308][INFO    ][5984] User sudo_ubuntu Executing command cp.push_dir with jid 20190525071639739926
2019-05-25 07:16:39,778 [salt.minion      :1432][INFO    ][20702] Starting a new job with PID 20702
