2019-11-29 12:49:05,127 [salt.utils.decorators:613 ][WARNING ][2334] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:49:05,676 [salt.utils.decorators:613 ][WARNING ][2334] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:49:07,705 [salt.loaded.int.states.file:2298][WARNING ][2507] 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-11-29 12:49:25,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3059] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-29 12:49:25,756 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3059] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-29 12:49:25,774 [salt.utils.parsers:1051][WARNING ][354] Minion received a SIGTERM. Exiting.
2019-11-29 12:49:26,747 [salt.cli.daemons :293 ][INFO    ][3175] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-11-29 12:49:26,858 [salt.cli.daemons :82  ][INFO    ][3175] Starting up the Salt Minion
2019-11-29 12:49:26,859 [salt.utils.event :1017][INFO    ][3175] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-11-29 12:49:27,685 [salt.minion      :976 ][INFO    ][3175] Creating minion process manager
2019-11-29 12:49:29,112 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3175] Executing command ['date', '+%z'] in directory '/root'
2019-11-29 12:49:29,126 [salt.utils.schedule:568 ][INFO    ][3175] Updating job settings for scheduled job: __mine_interval
2019-11-29 12:49:29,127 [salt.minion      :1108][INFO    ][3175] Added mine.update to scheduler
2019-11-29 12:49:29,131 [salt.minion      :1975][INFO    ][3175] Minion is starting as user 'root'
2019-11-29 12:49:29,143 [salt.minion      :2336][INFO    ][3175] Minion is ready to receive requests!
2019-11-29 12:49:31,046 [salt.state       :2022][WARNING ][3062] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-29 12:49:33,455 [salt.utils.decorators:613 ][WARNING ][3062] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:49:39,363 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129124939348209
2019-11-29 12:49:39,382 [salt.minion      :1432][INFO    ][3643] Starting a new job with PID 3643
2019-11-29 12:49:39,398 [salt.minion      :1711][INFO    ][3643] Returning information for job: 20191129124939348209
2019-11-29 12:50:03,221 [salt.utils.decorators:613 ][WARNING ][3062] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:50:09,415 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125009402628
2019-11-29 12:50:09,437 [salt.minion      :1432][INFO    ][4007] Starting a new job with PID 4007
2019-11-29 12:50:09,459 [salt.minion      :1711][INFO    ][4007] Returning information for job: 20191129125009402628
2019-11-29 12:50:39,479 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125039460189
2019-11-29 12:50:39,501 [salt.minion      :1432][INFO    ][4325] Starting a new job with PID 4325
2019-11-29 12:50:39,520 [salt.minion      :1711][INFO    ][4325] Returning information for job: 20191129125039460189
2019-11-29 12:50:40,158 [salt.utils.decorators:613 ][WARNING ][3062] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:50:41,027 [salt.utils.decorators:613 ][WARNING ][3062] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:50:44,894 [salt.loaded.ext.module.maasng:1008][WARNING ][3062] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-11-29 12:50:44,895 [salt.loaded.ext.module.maasng:1011][WARNING ][3062] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-11-29 12:50:45,594 [salt.loaded.ext.module.maasng:1235][WARNING ][3062] Ignoring parameter vlan:0
2019-11-29 12:50:47,227 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129125047217214
2019-11-29 12:50:47,243 [salt.minion      :1432][INFO    ][4666] Starting a new job with PID 4666
2019-11-29 12:50:50,952 [salt.state       :915 ][INFO    ][4666] Loading fresh modules for state activity
2019-11-29 12:50:51,012 [salt.fileclient  :1219][INFO    ][4666] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-11-29 12:50:51,052 [salt.state       :1780][INFO    ][4666] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:50:51.052863
2019-11-29 12:50:51,053 [salt.state       :1813][INFO    ][4666] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 12:50:51,055 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4666] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 12:50:52,498 [salt.state       :300 ][INFO    ][4666] {'pid': 4695, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 12:50:52,499 [salt.state       :1951][INFO    ][4666] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:50:52.499445 duration_in_ms=1446.579
2019-11-29 12:50:52,502 [salt.state       :1780][INFO    ][4666] Running state [maas.process_machines] at time 12:50:52.502187
2019-11-29 12:50:52,502 [salt.state       :1813][INFO    ][4666] Executing state module.run for [maas.process_machines]
2019-11-29 12:50:52,504 [salt.utils.decorators:613 ][WARNING ][4666] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:50:52,572 [salt.loaded.ext.module.maas:412 ][WARNING ][4666] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 12:50:52,572 [salt.loaded.ext.module.maas:92  ][INFO    ][4666] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 12:50:54,196 [salt.loaded.ext.module.maas:412 ][WARNING ][4666] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 12:50:54,196 [salt.loaded.ext.module.maas:92  ][INFO    ][4666] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 12:50:55,560 [salt.loaded.ext.module.maas:412 ][WARNING ][4666] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 12:50:55,561 [salt.loaded.ext.module.maas:92  ][INFO    ][4666] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 12:50:56,530 [salt.loaded.ext.module.maas:412 ][WARNING ][4666] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 12:50:56,531 [salt.loaded.ext.module.maas:92  ][INFO    ][4666] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 12:50:57,985 [salt.loaded.ext.module.maas:412 ][WARNING ][4666] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 12:50:57,986 [salt.loaded.ext.module.maas:92  ][INFO    ][4666] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 12:50:59,269 [salt.state       :300 ][INFO    ][4666] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-29 12:50:59,270 [salt.state       :1951][INFO    ][4666] Completed state [maas.process_machines] at time 12:50:59.270272 duration_in_ms=6768.083
2019-11-29 12:50:59,274 [salt.minion      :1711][INFO    ][4666] Returning information for job: 20191129125047217214
2019-11-29 12:51:30,355 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129125130338504
2019-11-29 12:51:30,375 [salt.minion      :1432][INFO    ][5018] Starting a new job with PID 5018
2019-11-29 12:51:34,177 [salt.state       :915 ][INFO    ][5018] Loading fresh modules for state activity
2019-11-29 12:51:34,232 [salt.fileclient  :1219][INFO    ][5018] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-29 12:51:34,279 [salt.state       :1780][INFO    ][5018] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:51:34.279108
2019-11-29 12:51:34,279 [salt.state       :1813][INFO    ][5018] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 12:51:34,281 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5018] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 12:51:35,760 [salt.state       :300 ][INFO    ][5018] {'pid': 5026, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 12:51:35,760 [salt.state       :1951][INFO    ][5018] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:51:35.760787 duration_in_ms=1481.679
2019-11-29 12:51:35,762 [salt.state       :1780][INFO    ][5018] Running state [maas.wait_for_machine_status] at time 12:51:35.762381
2019-11-29 12:51:35,762 [salt.state       :1813][INFO    ][5018] Executing state module.run for [maas.wait_for_machine_status]
2019-11-29 12:51:35,763 [salt.utils.decorators:613 ][WARNING ][5018] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:51:36,794 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.97332406s left)
2019-11-29 12:51:45,461 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125145445328
2019-11-29 12:51:45,484 [salt.minion      :1432][INFO    ][5052] Starting a new job with PID 5052
2019-11-29 12:51:45,507 [salt.minion      :1711][INFO    ][5052] Returning information for job: 20191129125145445328
2019-11-29 12:52:07,764 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.00354099s left)
2019-11-29 12:52:15,505 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125215491986
2019-11-29 12:52:15,527 [salt.minion      :1432][INFO    ][5086] Starting a new job with PID 5086
2019-11-29 12:52:15,552 [salt.minion      :1711][INFO    ][5086] Returning information for job: 20191129125215491986
2019-11-29 12:52:38,847 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.92006588s left)
2019-11-29 12:52:45,544 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125245531360
2019-11-29 12:52:45,560 [salt.minion      :1432][INFO    ][5237] Starting a new job with PID 5237
2019-11-29 12:52:45,571 [salt.minion      :1711][INFO    ][5237] Returning information for job: 20191129125245531360
2019-11-29 12:53:10,135 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.63261104s left)
2019-11-29 12:53:15,575 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125315563112
2019-11-29 12:53:15,598 [salt.minion      :1432][INFO    ][5399] Starting a new job with PID 5399
2019-11-29 12:53:15,622 [salt.minion      :1711][INFO    ][5399] Returning information for job: 20191129125315563112
2019-11-29 12:53:41,616 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.15108895s left)
2019-11-29 12:53:45,646 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125345633870
2019-11-29 12:53:45,667 [salt.minion      :1432][INFO    ][5976] Starting a new job with PID 5976
2019-11-29 12:53:45,690 [salt.minion      :1711][INFO    ][5976] Returning information for job: 20191129125345633870
2019-11-29 12:54:13,503 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.26395893s left)
2019-11-29 12:54:15,710 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125415690673
2019-11-29 12:54:15,733 [salt.minion      :1432][INFO    ][6146] Starting a new job with PID 6146
2019-11-29 12:54:15,756 [salt.minion      :1711][INFO    ][6146] Returning information for job: 20191129125415690673
2019-11-29 12:54:45,779 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125445761727
2019-11-29 12:54:45,802 [salt.minion      :1432][INFO    ][6307] Starting a new job with PID 6307
2019-11-29 12:54:45,826 [salt.minion      :1711][INFO    ][6307] Returning information for job: 20191129125445761727
2019-11-29 12:54:46,523 [salt.loaded.ext.module.maas:1023][INFO    ][5018] Waiting status:Ready|Deployed for machines:['cmp002']
sleep for:30s Timeout:1500s (1309.24393892s left)
2019-11-29 12:55:15,848 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125515831582
2019-11-29 12:55:15,871 [salt.minion      :1432][INFO    ][6382] Starting a new job with PID 6382
2019-11-29 12:55:15,895 [salt.minion      :1711][INFO    ][6382] Returning information for job: 20191129125515831582
2019-11-29 12:55:20,051 [salt.state       :300 ][INFO    ][5018] {'ret': True}
2019-11-29 12:55:20,052 [salt.state       :1951][INFO    ][5018] Completed state [maas.wait_for_machine_status] at time 12:55:20.052114 duration_in_ms=224289.731
2019-11-29 12:55:20,056 [salt.minion      :1711][INFO    ][5018] Returning information for job: 20191129125130338504
2019-11-29 12:55:20,711 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129125520697697
2019-11-29 12:55:20,733 [salt.minion      :1432][INFO    ][6395] Starting a new job with PID 6395
2019-11-29 12:55:24,548 [salt.state       :915 ][INFO    ][6395] Loading fresh modules for state activity
2019-11-29 12:55:24,602 [salt.fileclient  :1219][INFO    ][6395] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-29 12:55:24,692 [salt.state       :1780][INFO    ][6395] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:24.692860
2019-11-29 12:55:24,693 [salt.state       :1813][INFO    ][6395] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 12:55:24,694 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6395] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 12:55:26,094 [salt.state       :300 ][INFO    ][6395] {'pid': 6402, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 12:55:26,095 [salt.state       :1951][INFO    ][6395] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:26.095142 duration_in_ms=1402.282
2019-11-29 12:55:26,098 [salt.state       :1780][INFO    ][6395] Running state [maas_machines_storage_cmp002_lvm] at time 12:55:26.098359
2019-11-29 12:55:26,098 [salt.state       :1813][INFO    ][6395] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-29 12:55:27,569 [salt.loaded.ext.module.maasng:610 ][INFO    ][6395] qwkryq
2019-11-29 12:55:27,570 [salt.loaded.ext.module.maasng:626 ][INFO    ][6395] sda
2019-11-29 12:55:28,265 [salt.loaded.ext.module.maasng:361 ][INFO    ][6395] qwkryq
2019-11-29 12:55:28,386 [salt.loaded.ext.module.maasng:367 ][INFO    ][6395] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'5ced8ed1-ce0b-4f2a-a984-660af0cc323c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qwkryq', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'e885d669-28d3-4cde-b147-50584216f851', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'device_id': 5}], u'filesystem': None, u'name': u'sda', u'system_id': u'qwkryq', 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'used_for': u'GPT partitioned with 1 partition', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/'}, {u'size': 2397988454400, u'model': None, u'available_size': 0, u'uuid': u'ad6f4cff-a98c-4b70-bc3f-312b7c0453f0', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'83784b1f-7661-4985-b419-1351c4d48313', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'qwkryq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/13/'}]
2019-11-29 12:55:28,386 [salt.loaded.ext.module.maasng:632 ][INFO    ][6395] vgroot
2019-11-29 12:55:28,387 [salt.loaded.ext.module.maasng:635 ][INFO    ][6395] lvroot
2019-11-29 12:55:28,387 [salt.loaded.ext.module.maasng:639 ][INFO    ][6395] 107374182400
2019-11-29 12:55:29,059 [salt.loaded.ext.module.maasng:645 ][INFO    ][6395] {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'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'mode': u'dhcp', u'id': 47}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'qwkryq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/interfaces/4/'}, u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/qwkryq/', u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'qwkryq', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'ec8cd6d2-afa4-4242-9fe6-7caf29bbda9c', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qwkryq', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'9c77eba7-71c8-462f-8b10-ad1503eb6a66', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 10, u'device_id': 5}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'qwkryq', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}, {u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/15/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'qwkryq', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'4dc1ef65-abd1-406b-b989-414c6c6e9f99', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 15, u'serial': None, u'uuid': u'78ac8c27-c776-4960-978d-ce64fc804117'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'ec8cd6d2-afa4-4242-9fe6-7caf29bbda9c', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qwkryq', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'9c77eba7-71c8-462f-8b10-ad1503eb6a66', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 10, u'device_id': 5}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'qwkryq', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}], u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'qwkryq', u'id': 10}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/15/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'qwkryq', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'4dc1ef65-abd1-406b-b989-414c6c6e9f99', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 15, u'serial': None, u'uuid': u'78ac8c27-c776-4960-978d-ce64fc804117'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'mode': u'dhcp', u'id': 47}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, 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'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'qwkryq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/interfaces/4/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 48, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6d', u'enabled': True, u'id': 13, u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'qwkryq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/interfaces/13/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 50, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6b', u'enabled': True, u'id': 17, u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'qwkryq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/interfaces/17/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 52, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6c', u'enabled': True, u'id': 18, u'discovered': None, u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'qwkryq', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/interfaces/18/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'ec8cd6d2-afa4-4242-9fe6-7caf29bbda9c', u'resource_uri': u'/MAAS/api/2.0/nodes/qwkryq/blockdevices/5/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qwkryq', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'9c77eba7-71c8-462f-8b10-ad1503eb6a66', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 10, u'device_id': 5}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'qwkryq', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'uuid': None}}
2019-11-29 12:55:29,062 [salt.state       :300 ][INFO    ][6395] {'new': {'storage_layout': 'lvm'}}
2019-11-29 12:55:29,062 [salt.state       :1951][INFO    ][6395] Completed state [maas_machines_storage_cmp002_lvm] at time 12:55:29.062309 duration_in_ms=2963.949
2019-11-29 12:55:29,062 [salt.state       :1780][INFO    ][6395] Running state [maas_machines_storage_cmp001_lvm] at time 12:55:29.062869
2019-11-29 12:55:29,063 [salt.state       :1813][INFO    ][6395] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-29 12:55:30,475 [salt.loaded.ext.module.maasng:610 ][INFO    ][6395] ar3db6
2019-11-29 12:55:30,476 [salt.loaded.ext.module.maasng:626 ][INFO    ][6395] sda
2019-11-29 12:55:31,242 [salt.loaded.ext.module.maasng:361 ][INFO    ][6395] ar3db6
2019-11-29 12:55:31,356 [salt.loaded.ext.module.maasng:367 ][INFO    ][6395] [{u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/', u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'id': 3, u'system_id': u'ar3db6', u'block_size': 4096, u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'2d71b488-6863-4dde-a93d-427c1fec3020', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ar3db6', u'device_id': 3, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'6347ce62-af85-4956-9524-fda87e371ff5', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/partition/7'}]}, {u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/12/', u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 2397988454400, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'255cb551-4942-45e4-a2a0-f4f9bef0461c', u'fstype': u'ext4'}, u'uuid': u'7e3d422c-8381-4ebe-be95-66910726e9b0', u'id': 12, u'system_id': u'ar3db6', u'block_size': 4096, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'size': 2397988454400, u'type': u'virtual', u'serial': None, u'partitions': []}]
2019-11-29 12:55:31,356 [salt.loaded.ext.module.maasng:632 ][INFO    ][6395] vgroot
2019-11-29 12:55:31,356 [salt.loaded.ext.module.maasng:635 ][INFO    ][6395] lvroot
2019-11-29 12:55:31,357 [salt.loaded.ext.module.maasng:639 ][INFO    ][6395] 107374182400
2019-11-29 12:55:32,058 [salt.loaded.ext.module.maasng:645 ][INFO    ][6395] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', 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': 43, u'mode': u'dhcp'}], u'tags': [], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'name': u'untagged', 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'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', 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'system_id': u'ar3db6', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'testing_status': 2, 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'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ar3db6', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/', u'type': u'physical', u'id': 3, u'partitions': [{u'uuid': u'4c451df2-2e6c-45c1-80ff-fe301e94f77a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ar3db6', u'device_id': 3, u'filesystem': {u'uuid': u'445ec35e-7f1c-4114-a9fe-25ca5ba946ee', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/partition/11', u'type': u'partition', u'id': 11, u'size': 2397992648704}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/ar3db6/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'owner_data': {}, u'system_id': u'ar3db6', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.38'], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/', u'available_size': 0, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'uuid': None, u'name': u'sda', u'system_id': u'ar3db6', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 3, u'partitions': [{u'uuid': u'4c451df2-2e6c-45c1-80ff-fe301e94f77a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ar3db6', u'device_id': 3, u'filesystem': {u'uuid': u'445ec35e-7f1c-4114-a9fe-25ca5ba946ee', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/partition/11', u'type': u'partition', u'id': 11, u'size': 2397992648704}]}, {u'size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/16/', u'available_size': 0, u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'uuid': u'8b23894f-116d-4570-8f4e-87b7ae23db75', u'name': u'vgroot-lvroot', u'system_id': u'ar3db6', u'partition_table_type': None, u'filesystem': {u'uuid': u'b507b31f-f91e-49a8-8ded-65c9eb98dae9', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 16, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ar3db6', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/', u'type': u'physical', u'id': 3, u'partitions': [{u'uuid': u'4c451df2-2e6c-45c1-80ff-fe301e94f77a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ar3db6', u'device_id': 3, u'filesystem': {u'uuid': u'445ec35e-7f1c-4114-a9fe-25ca5ba946ee', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/3/partition/11', u'type': u'partition', u'id': 11, u'size': 2397992648704}]}], u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'ar3db6', u'id': 11}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', 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': 43, u'mode': u'dhcp'}], u'tags': [], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'name': u'untagged', 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'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', 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'system_id': u'ar3db6', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 44, u'mode': u'link_up'}], u'tags': [], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'ar3db6', u'mac_address': u'00:25:b5:a0:00:5d', u'id': 10, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'id': 45, u'mode': u'link_up'}], u'tags': [], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'ar3db6', u'mac_address': u'00:25:b5:a0:00:5b', u'id': 11, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/interfaces/11/'}, {u'name': u'enp8s0', u'links': [{u'id': 46, u'mode': u'link_up'}], u'tags': [], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'ar3db6', u'mac_address': u'00:25:b5:a0:00:5c', u'id': 15, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/interfaces/15/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'8b23894f-116d-4570-8f4e-87b7ae23db75', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'ar3db6', u'partition_table_type': None, u'filesystem': {u'uuid': u'b507b31f-f91e-49a8-8ded-65c9eb98dae9', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ar3db6/blockdevices/16/', u'type': u'virtual', u'id': 16, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-29 12:55:32,060 [salt.state       :300 ][INFO    ][6395] {'new': {'storage_layout': 'lvm'}}
2019-11-29 12:55:32,061 [salt.state       :1951][INFO    ][6395] Completed state [maas_machines_storage_cmp001_lvm] at time 12:55:32.061190 duration_in_ms=2998.319
2019-11-29 12:55:32,065 [salt.minion      :1711][INFO    ][6395] Returning information for job: 20191129125520697697
2019-11-29 12:55:32,715 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129125532701777
2019-11-29 12:55:32,736 [salt.minion      :1432][INFO    ][6432] Starting a new job with PID 6432
2019-11-29 12:55:33,518 [salt.state       :915 ][INFO    ][6432] Loading fresh modules for state activity
2019-11-29 12:55:33,572 [salt.fileclient  :1219][INFO    ][6432] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-29 12:55:33,616 [salt.state       :1780][INFO    ][6432] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:33.616618
2019-11-29 12:55:33,617 [salt.state       :1813][INFO    ][6432] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 12:55:33,619 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6432] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 12:55:35,164 [salt.state       :300 ][INFO    ][6432] {'pid': 6439, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 12:55:35,164 [salt.state       :1951][INFO    ][6432] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:35.164523 duration_in_ms=1547.906
2019-11-29 12:55:35,166 [salt.state       :1780][INFO    ][6432] Running state [maas.deploy_machines] at time 12:55:35.166266
2019-11-29 12:55:35,166 [salt.state       :1813][INFO    ][6432] Executing state module.run for [maas.deploy_machines]
2019-11-29 12:55:35,167 [salt.utils.decorators:613 ][WARNING ][6432] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:55:35,812 [salt.loaded.ext.module.maas:684 ][INFO    ][6432] deploymachines hwe_kernel=hwe-16.04 system_id=qwkryq distro_series=xenial
2019-11-29 12:55:38,459 [salt.loaded.ext.module.maas:684 ][INFO    ][6432] deploymachines hwe_kernel=hwe-16.04 system_id=ar3db6 distro_series=xenial
2019-11-29 12:55:41,029 [salt.loaded.ext.module.maas:684 ][INFO    ][6432] deploymachines hwe_kernel=hwe-16.04 system_id=t4mkgg distro_series=xenial
2019-11-29 12:55:43,627 [salt.loaded.ext.module.maas:684 ][INFO    ][6432] deploymachines hwe_kernel=hwe-16.04 system_id=mdnqb3 distro_series=xenial
2019-11-29 12:55:46,227 [salt.loaded.ext.module.maas:684 ][INFO    ][6432] deploymachines hwe_kernel=hwe-16.04 system_id=bh7kpt distro_series=xenial
2019-11-29 12:55:47,798 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125547785259
2019-11-29 12:55:47,818 [salt.minion      :1432][INFO    ][6715] Starting a new job with PID 6715
2019-11-29 12:55:47,841 [salt.minion      :1711][INFO    ][6715] Returning information for job: 20191129125547785259
2019-11-29 12:55:48,753 [salt.state       :300 ][INFO    ][6432] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-29 12:55:48,754 [salt.state       :1951][INFO    ][6432] Completed state [maas.deploy_machines] at time 12:55:48.754212 duration_in_ms=13587.946
2019-11-29 12:55:48,757 [salt.minion      :1711][INFO    ][6432] Returning information for job: 20191129125532701777
2019-11-29 12:55:49,345 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129125549331758
2019-11-29 12:55:49,368 [salt.minion      :1432][INFO    ][6732] Starting a new job with PID 6732
2019-11-29 12:55:53,101 [salt.state       :915 ][INFO    ][6732] Loading fresh modules for state activity
2019-11-29 12:55:53,154 [salt.fileclient  :1219][INFO    ][6732] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-29 12:55:53,198 [salt.state       :1780][INFO    ][6732] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:53.198050
2019-11-29 12:55:53,198 [salt.state       :1813][INFO    ][6732] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 12:55:53,200 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6732] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 12:55:54,602 [salt.state       :300 ][INFO    ][6732] {'pid': 6746, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 12:55:54,603 [salt.state       :1951][INFO    ][6732] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:55:54.603119 duration_in_ms=1405.07
2019-11-29 12:55:54,605 [salt.state       :1780][INFO    ][6732] Running state [maas.wait_for_machine_status] at time 12:55:54.605618
2019-11-29 12:55:54,606 [salt.state       :1813][INFO    ][6732] Executing state module.run for [maas.wait_for_machine_status]
2019-11-29 12:55:54,606 [salt.utils.decorators:613 ][WARNING ][6732] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 12:55:57,445 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.17154002s left)
2019-11-29 12:56:04,390 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125604375229
2019-11-29 12:56:04,413 [salt.minion      :1432][INFO    ][6774] Starting a new job with PID 6774
2019-11-29 12:56:04,434 [salt.minion      :1711][INFO    ][6774] Returning information for job: 20191129125604375229
2019-11-29 12:56:30,810 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.80703592s left)
2019-11-29 12:56:34,434 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125634420181
2019-11-29 12:56:34,456 [salt.minion      :1432][INFO    ][6803] Starting a new job with PID 6803
2019-11-29 12:56:34,479 [salt.minion      :1711][INFO    ][6803] Returning information for job: 20191129125634420181
2019-11-29 12:57:04,222 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.39492393s left)
2019-11-29 12:57:04,539 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125704526202
2019-11-29 12:57:04,560 [salt.minion      :1432][INFO    ][6846] Starting a new job with PID 6846
2019-11-29 12:57:04,579 [salt.minion      :1711][INFO    ][6846] Returning information for job: 20191129125704526202
2019-11-29 12:57:34,579 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125734566933
2019-11-29 12:57:34,593 [salt.minion      :1432][INFO    ][6966] Starting a new job with PID 6966
2019-11-29 12:57:34,604 [salt.minion      :1711][INFO    ][6966] Returning information for job: 20191129125734566933
2019-11-29 12:57:37,439 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.17741513s left)
2019-11-29 12:58:04,604 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125804594005
2019-11-29 12:58:04,624 [salt.minion      :1432][INFO    ][7172] Starting a new job with PID 7172
2019-11-29 12:58:04,647 [salt.minion      :1711][INFO    ][7172] Returning information for job: 20191129125804594005
2019-11-29 12:58:10,912 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.70471501s left)
2019-11-29 12:58:34,660 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125834642405
2019-11-29 12:58:34,682 [salt.minion      :1432][INFO    ][7296] Starting a new job with PID 7296
2019-11-29 12:58:34,704 [salt.minion      :1711][INFO    ][7296] Returning information for job: 20191129125834642405
2019-11-29 12:58:44,345 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.27171993s left)
2019-11-29 12:59:04,722 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125904710183
2019-11-29 12:59:04,743 [salt.minion      :1432][INFO    ][7929] Starting a new job with PID 7929
2019-11-29 12:59:04,765 [salt.minion      :1711][INFO    ][7929] Returning information for job: 20191129125904710183
2019-11-29 12:59:17,847 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.76972294s left)
2019-11-29 12:59:34,777 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129125934764399
2019-11-29 12:59:34,800 [salt.minion      :1432][INFO    ][8062] Starting a new job with PID 8062
2019-11-29 12:59:34,824 [salt.minion      :1711][INFO    ][8062] Returning information for job: 20191129125934764399
2019-11-29 12:59:51,389 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.22765398s left)
2019-11-29 13:00:04,844 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130004830669
2019-11-29 13:00:04,864 [salt.minion      :1432][INFO    ][8203] Starting a new job with PID 8203
2019-11-29 13:00:04,881 [salt.minion      :1711][INFO    ][8203] Returning information for job: 20191129130004830669
2019-11-29 13:00:25,022 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.59433413s left)
2019-11-29 13:00:34,898 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130034885361
2019-11-29 13:00:34,921 [salt.minion      :1432][INFO    ][8272] Starting a new job with PID 8272
2019-11-29 13:00:34,946 [salt.minion      :1711][INFO    ][8272] Returning information for job: 20191129130034885361
2019-11-29 13:00:58,187 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.42971015s left)
2019-11-29 13:01:04,979 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130104969529
2019-11-29 13:01:04,999 [salt.minion      :1432][INFO    ][8762] Starting a new job with PID 8762
2019-11-29 13:01:05,015 [salt.minion      :1711][INFO    ][8762] Returning information for job: 20191129130104969529
2019-11-29 13:01:31,767 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.84973001s left)
2019-11-29 13:01:35,053 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130135040926
2019-11-29 13:01:35,075 [salt.minion      :1432][INFO    ][8892] Starting a new job with PID 8892
2019-11-29 13:01:35,100 [salt.minion      :1711][INFO    ][8892] Returning information for job: 20191129130135040926
2019-11-29 13:02:05,147 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130205133423
2019-11-29 13:02:05,165 [salt.minion      :1432][INFO    ][9209] Starting a new job with PID 9209
2019-11-29 13:02:05,180 [salt.minion      :1711][INFO    ][9209] Returning information for job: 20191129130205133423
2019-11-29 13:02:05,256 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.36078811s left)
2019-11-29 13:02:35,210 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130235196985
2019-11-29 13:02:35,231 [salt.minion      :1432][INFO    ][9267] Starting a new job with PID 9267
2019-11-29 13:02:35,255 [salt.minion      :1711][INFO    ][9267] Returning information for job: 20191129130235196985
2019-11-29 13:02:38,932 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.68426108s left)
2019-11-29 13:03:05,307 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130305293656
2019-11-29 13:03:05,328 [salt.minion      :1432][INFO    ][9383] Starting a new job with PID 9383
2019-11-29 13:03:05,353 [salt.minion      :1711][INFO    ][9383] Returning information for job: 20191129130305293656
2019-11-29 13:03:12,126 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.49009609s left)
2019-11-29 13:03:35,433 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130335421548
2019-11-29 13:03:35,457 [salt.minion      :1432][INFO    ][9564] Starting a new job with PID 9564
2019-11-29 13:03:35,478 [salt.minion      :1711][INFO    ][9564] Returning information for job: 20191129130335421548
2019-11-29 13:03:45,056 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1779.5610311s left)
2019-11-29 13:04:05,540 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130405527018
2019-11-29 13:04:05,560 [salt.minion      :1432][INFO    ][9881] Starting a new job with PID 9881
2019-11-29 13:04:05,583 [salt.minion      :1711][INFO    ][9881] Returning information for job: 20191129130405527018
2019-11-29 13:04:18,579 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1746.0372591s left)
2019-11-29 13:04:35,655 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130435643297
2019-11-29 13:04:35,677 [salt.minion      :1432][INFO    ][10009] Starting a new job with PID 10009
2019-11-29 13:04:35,703 [salt.minion      :1711][INFO    ][10009] Returning information for job: 20191129130435643297
2019-11-29 13:04:52,030 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1712.58677793s left)
2019-11-29 13:05:05,781 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130505767733
2019-11-29 13:05:05,804 [salt.minion      :1432][INFO    ][10082] Starting a new job with PID 10082
2019-11-29 13:05:05,829 [salt.minion      :1711][INFO    ][10082] Returning information for job: 20191129130505767733
2019-11-29 13:05:25,356 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1679.26076412s left)
2019-11-29 13:05:35,913 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130535900474
2019-11-29 13:05:35,935 [salt.minion      :1432][INFO    ][10118] Starting a new job with PID 10118
2019-11-29 13:05:35,961 [salt.minion      :1711][INFO    ][10118] Returning information for job: 20191129130535900474
2019-11-29 13:05:58,835 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1645.78159499s left)
2019-11-29 13:06:06,057 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130606043684
2019-11-29 13:06:06,080 [salt.minion      :1432][INFO    ][10158] Starting a new job with PID 10158
2019-11-29 13:06:06,104 [salt.minion      :1711][INFO    ][10158] Returning information for job: 20191129130606043684
2019-11-29 13:06:31,955 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1612.66166806s left)
2019-11-29 13:06:36,202 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130636189611
2019-11-29 13:06:36,218 [salt.minion      :1432][INFO    ][10194] Starting a new job with PID 10194
2019-11-29 13:06:36,240 [salt.minion      :1711][INFO    ][10194] Returning information for job: 20191129130636189611
2019-11-29 13:07:05,306 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1579.311625s left)
2019-11-29 13:07:06,352 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130706337181
2019-11-29 13:07:06,375 [salt.minion      :1432][INFO    ][10234] Starting a new job with PID 10234
2019-11-29 13:07:06,398 [salt.minion      :1711][INFO    ][10234] Returning information for job: 20191129130706337181
2019-11-29 13:07:36,519 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130736503699
2019-11-29 13:07:36,545 [salt.minion      :1432][INFO    ][10273] Starting a new job with PID 10273
2019-11-29 13:07:36,569 [salt.minion      :1711][INFO    ][10273] Returning information for job: 20191129130736503699
2019-11-29 13:07:38,808 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1545.80868602s left)
2019-11-29 13:08:06,696 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130806680661
2019-11-29 13:08:06,718 [salt.minion      :1432][INFO    ][10322] Starting a new job with PID 10322
2019-11-29 13:08:06,742 [salt.minion      :1711][INFO    ][10322] Returning information for job: 20191129130806680661
2019-11-29 13:08:12,194 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1512.42303705s left)
2019-11-29 13:08:36,884 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130836871180
2019-11-29 13:08:36,908 [salt.minion      :1432][INFO    ][10363] Starting a new job with PID 10363
2019-11-29 13:08:36,931 [salt.minion      :1711][INFO    ][10363] Returning information for job: 20191129130836871180
2019-11-29 13:08:45,504 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1479.11256003s left)
2019-11-29 13:09:07,075 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130907061847
2019-11-29 13:09:07,097 [salt.minion      :1432][INFO    ][10400] Starting a new job with PID 10400
2019-11-29 13:09:07,122 [salt.minion      :1711][INFO    ][10400] Returning information for job: 20191129130907061847
2019-11-29 13:09:19,044 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1445.57275796s left)
2019-11-29 13:09:37,277 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129130937264612
2019-11-29 13:09:37,300 [salt.minion      :1432][INFO    ][10578] Starting a new job with PID 10578
2019-11-29 13:09:37,323 [salt.minion      :1711][INFO    ][10578] Returning information for job: 20191129130937264612
2019-11-29 13:09:51,967 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1412.64968896s left)
2019-11-29 13:10:07,485 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131007472108
2019-11-29 13:10:07,507 [salt.minion      :1432][INFO    ][10625] Starting a new job with PID 10625
2019-11-29 13:10:07,530 [salt.minion      :1711][INFO    ][10625] Returning information for job: 20191129131007472108
2019-11-29 13:10:25,412 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1379.20481205s left)
2019-11-29 13:10:37,707 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131037694957
2019-11-29 13:10:37,729 [salt.minion      :1432][INFO    ][10666] Starting a new job with PID 10666
2019-11-29 13:10:37,753 [salt.minion      :1711][INFO    ][10666] Returning information for job: 20191129131037694957
2019-11-29 13:10:58,550 [salt.loaded.ext.module.maas:1023][INFO    ][6732] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1346.06653404s left)
2019-11-29 13:11:07,730 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131107717391
2019-11-29 13:11:07,753 [salt.minion      :1432][INFO    ][10707] Starting a new job with PID 10707
2019-11-29 13:11:07,775 [salt.minion      :1711][INFO    ][10707] Returning information for job: 20191129131107717391
2019-11-29 13:11:30,614 [salt.loaded.ext.module.maas:993 ][INFO    ][6732] Machine t4mkgg mark broken
2019-11-29 13:11:31,400 [salt.loaded.ext.module.maas:996 ][INFO    ][6732] Machine t4mkgg mark fixed
2019-11-29 13:11:32,645 [salt.loaded.ext.module.maas:684 ][INFO    ][6732] deploymachines hwe_kernel=hwe-16.04 system_id=t4mkgg distro_series=xenial
2019-11-29 13:11:35,443 [salt.loaded.ext.module.maas:160 ][ERROR   ][6732] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-11-29 13:11:35,445 [salt.state       :302 ][ERROR   ][6732] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-11-29 13:11:35,446 [salt.state       :1951][INFO    ][6732] Completed state [maas.wait_for_machine_status] at time 13:11:35.445969 duration_in_ms=940840.346
2019-11-29 13:11:35,456 [salt.minion      :1711][INFO    ][6732] Returning information for job: 20191129125549331758
2019-11-29 13:11:46,259 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command pillar.get with jid 20191129131146246678
2019-11-29 13:11:46,282 [salt.minion      :1432][INFO    ][10822] Starting a new job with PID 10822
2019-11-29 13:11:46,291 [salt.minion      :1711][INFO    ][10822] Returning information for job: 20191129131146246678
2019-11-29 13:11:46,769 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command service.status with jid 20191129131146756187
2019-11-29 13:11:46,790 [salt.minion      :1432][INFO    ][10827] Starting a new job with PID 10827
2019-11-29 13:11:47,178 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10827] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-29 13:11:47,212 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10827] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-29 13:11:47,227 [salt.minion      :1711][INFO    ][10827] Returning information for job: 20191129131146756187
2019-11-29 13:11:47,769 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129131147762568
2019-11-29 13:11:47,790 [salt.minion      :1432][INFO    ][10838] Starting a new job with PID 10838
2019-11-29 13:11:51,537 [salt.state       :915 ][INFO    ][10838] Loading fresh modules for state activity
2019-11-29 13:11:51,971 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'salt-minion --version' in directory '/root'
2019-11-29 13:11:52,303 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'salt-minion --version' in directory '/root'
2019-11-29 13:11:53,185 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'salt-minion --version' in directory '/root'
2019-11-29 13:11:53,559 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'salt-minion --version' in directory '/root'
2019-11-29 13:11:54,893 [salt.state       :1780][INFO    ][10838] Running state [salt-minion] at time 13:11:54.893747
2019-11-29 13:11:54,894 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [salt-minion]
2019-11-29 13:11:54,894 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-29 13:11:54,983 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:54,984 [salt.state       :1951][INFO    ][10838] Completed state [salt-minion] at time 13:11:54.984172 duration_in_ms=90.425
2019-11-29 13:11:54,984 [salt.state       :1780][INFO    ][10838] Running state [salt_minion_dependency_packages] at time 13:11:54.984526
2019-11-29 13:11:54,984 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-29 13:11:54,991 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:54,991 [salt.state       :1951][INFO    ][10838] Completed state [salt_minion_dependency_packages] at time 13:11:54.991715 duration_in_ms=7.19
2019-11-29 13:11:54,994 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/minion.d/minion.conf] at time 13:11:54.994876
2019-11-29 13:11:54,995 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-29 13:11:55,210 [salt.state       :300 ][INFO    ][10838] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-29 13:11:55,210 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/minion.d/minion.conf] at time 13:11:55.210270 duration_in_ms=215.393
2019-11-29 13:11:55,210 [salt.state       :1780][INFO    ][10838] Running state [python-netaddr] at time 13:11:55.210576
2019-11-29 13:11:55,210 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [python-netaddr]
2019-11-29 13:11:55,218 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:55,218 [salt.state       :1951][INFO    ][10838] Completed state [python-netaddr] at time 13:11:55.218885 duration_in_ms=8.309
2019-11-29 13:11:55,222 [salt.state       :1780][INFO    ][10838] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 13:11:55.222300
2019-11-29 13:11:55,222 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-29 13:11:55,234 [salt.state       :300 ][INFO    ][10838] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-29 13:11:55,234 [salt.state       :1951][INFO    ][10838] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 13:11:55.234449 duration_in_ms=12.15
2019-11-29 13:11:55,235 [salt.state       :1780][INFO    ][10838] Running state [salt-minion] at time 13:11:55.235529
2019-11-29 13:11:55,235 [salt.state       :1813][INFO    ][10838] Executing state service.running for [salt-minion]
2019-11-29 13:11:55,236 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-29 13:11:55,273 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-29 13:11:55,290 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-29 13:11:55,307 [salt.state       :300 ][INFO    ][10838] The service salt-minion is already running
2019-11-29 13:11:55,307 [salt.state       :1951][INFO    ][10838] Completed state [salt-minion] at time 13:11:55.307847 duration_in_ms=72.318
2019-11-29 13:11:55,309 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains.d] at time 13:11:55.309623
2019-11-29 13:11:55,310 [salt.state       :1813][INFO    ][10838] Executing state file.directory for [/etc/salt/grains.d]
2019-11-29 13:11:55,311 [salt.state       :300 ][INFO    ][10838] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-29 13:11:55,311 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains.d] at time 13:11:55.311358 duration_in_ms=1.735
2019-11-29 13:11:55,312 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains] at time 13:11:55.312153
2019-11-29 13:11:55,312 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/grains]
2019-11-29 13:11:55,313 [salt.state       :300 ][INFO    ][10838] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-29 13:11:55,313 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains] at time 13:11:55.313400 duration_in_ms=1.248
2019-11-29 13:11:55,313 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains.d/placeholder] at time 13:11:55.313945
2019-11-29 13:11:55,314 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-29 13:11:55,314 [salt.state       :300 ][INFO    ][10838] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-29 13:11:55,315 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains.d/placeholder] at time 13:11:55.315059 duration_in_ms=1.114
2019-11-29 13:11:55,315 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains.d/sphinx] at time 13:11:55.315567
2019-11-29 13:11:55,315 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-29 13:11:55,329 [salt.state       :300 ][INFO    ][10838] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-29 13:11:55,330 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains.d/sphinx] at time 13:11:55.330183 duration_in_ms=14.615
2019-11-29 13:11:55,332 [salt.state       :1780][INFO    ][10838] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.332596
2019-11-29 13:11:55,332 [salt.state       :1813][INFO    ][10838] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-29 13:11:55,333 [salt.state       :300 ][INFO    ][10838] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-29 13:11:55,333 [salt.state       :1951][INFO    ][10838] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.333546 duration_in_ms=0.95
2019-11-29 13:11:55,334 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains.d/dns_records] at time 13:11:55.334069
2019-11-29 13:11:55,334 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-29 13:11:55,347 [salt.state       :300 ][INFO    ][10838] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-29 13:11:55,348 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains.d/dns_records] at time 13:11:55.347985 duration_in_ms=13.915
2019-11-29 13:11:55,349 [salt.state       :1780][INFO    ][10838] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.349012
2019-11-29 13:11:55,349 [salt.state       :1813][INFO    ][10838] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-29 13:11:55,349 [salt.state       :300 ][INFO    ][10838] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-29 13:11:55,350 [salt.state       :1951][INFO    ][10838] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.349977 duration_in_ms=0.965
2019-11-29 13:11:55,350 [salt.state       :1780][INFO    ][10838] Running state [/etc/salt/grains.d/salt] at time 13:11:55.350497
2019-11-29 13:11:55,350 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-29 13:11:55,365 [salt.state       :300 ][INFO    ][10838] File /etc/salt/grains.d/salt is in the correct state
2019-11-29 13:11:55,366 [salt.state       :1951][INFO    ][10838] Completed state [/etc/salt/grains.d/salt] at time 13:11:55.365987 duration_in_ms=15.49
2019-11-29 13:11:55,367 [salt.state       :1780][INFO    ][10838] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.366947
2019-11-29 13:11:55,367 [salt.state       :1813][INFO    ][10838] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-29 13:11:55,367 [salt.state       :300 ][INFO    ][10838] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-29 13:11:55,367 [salt.state       :1951][INFO    ][10838] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 13:11:55.367886 duration_in_ms=0.939
2019-11-29 13:11:55,370 [salt.state       :1780][INFO    ][10838] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 13:11:55.369952
2019-11-29 13:11:55,370 [salt.state       :1813][INFO    ][10838] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-29 13:11:55,370 [salt.state       :300 ][INFO    ][10838] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-29 13:11:55,370 [salt.state       :1951][INFO    ][10838] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 13:11:55.370915 duration_in_ms=0.963
2019-11-29 13:11:55,371 [salt.state       :1780][INFO    ][10838] Running state [mine.update] at time 13:11:55.371657
2019-11-29 13:11:55,372 [salt.state       :1813][INFO    ][10838] Executing state module.wait for [mine.update]
2019-11-29 13:11:55,372 [salt.state       :300 ][INFO    ][10838] No changes made for mine.update
2019-11-29 13:11:55,372 [salt.state       :1951][INFO    ][10838] Completed state [mine.update] at time 13:11:55.372558 duration_in_ms=0.9
2019-11-29 13:11:55,372 [salt.state       :1780][INFO    ][10838] Running state [ca-certificates] at time 13:11:55.372830
2019-11-29 13:11:55,373 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [ca-certificates]
2019-11-29 13:11:55,381 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:55,381 [salt.state       :1951][INFO    ][10838] Completed state [ca-certificates] at time 13:11:55.381299 duration_in_ms=8.469
2019-11-29 13:11:55,382 [salt.state       :1780][INFO    ][10838] Running state [update-ca-certificates] at time 13:11:55.382030
2019-11-29 13:11:55,382 [salt.state       :1813][INFO    ][10838] Executing state cmd.wait for [update-ca-certificates]
2019-11-29 13:11:55,382 [salt.state       :300 ][INFO    ][10838] No changes made for update-ca-certificates
2019-11-29 13:11:55,382 [salt.state       :1951][INFO    ][10838] Completed state [update-ca-certificates] at time 13:11:55.382890 duration_in_ms=0.86
2019-11-29 13:11:55,383 [salt.state       :1780][INFO    ][10838] Running state [iptables] at time 13:11:55.383137
2019-11-29 13:11:55,383 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [iptables]
2019-11-29 13:11:55,390 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:55,390 [salt.state       :1951][INFO    ][10838] Completed state [iptables] at time 13:11:55.390854 duration_in_ms=7.717
2019-11-29 13:11:55,391 [salt.state       :1780][INFO    ][10838] Running state [iptables-persistent] at time 13:11:55.391100
2019-11-29 13:11:55,391 [salt.state       :1813][INFO    ][10838] Executing state pkg.installed for [iptables-persistent]
2019-11-29 13:11:55,398 [salt.state       :300 ][INFO    ][10838] All specified packages are already installed
2019-11-29 13:11:55,398 [salt.state       :1951][INFO    ][10838] Completed state [iptables-persistent] at time 13:11:55.398681 duration_in_ms=7.581
2019-11-29 13:11:55,399 [salt.state       :1780][INFO    ][10838] Running state [iptables_modules_v4_load] at time 13:11:55.399657
2019-11-29 13:11:55,399 [salt.state       :1813][INFO    ][10838] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-29 13:11:55,400 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'lsmod' in directory '/root'
2019-11-29 13:11:55,424 [salt.state       :300 ][INFO    ][10838] Kernel modules iptable_filter, ip_tables are already present
2019-11-29 13:11:55,424 [salt.state       :1951][INFO    ][10838] Completed state [iptables_modules_v4_load] at time 13:11:55.424658 duration_in_ms=25.001
2019-11-29 13:11:55,425 [salt.state       :1780][INFO    ][10838] Running state [/etc/iptables/rules.v4] at time 13:11:55.425291
2019-11-29 13:11:55,425 [salt.state       :1813][INFO    ][10838] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-29 13:11:55,515 [salt.state       :300 ][INFO    ][10838] File /etc/iptables/rules.v4 is in the correct state
2019-11-29 13:11:55,515 [salt.state       :1951][INFO    ][10838] Completed state [/etc/iptables/rules.v4] at time 13:11:55.515751 duration_in_ms=90.461
2019-11-29 13:11:55,516 [salt.state       :1780][INFO    ][10838] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 13:11:55.516681
2019-11-29 13:11:55,516 [salt.state       :1813][INFO    ][10838] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-29 13:11:55,517 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-29 13:11:55,536 [salt.state       :300 ][INFO    ][10838] onlyif execution failed
2019-11-29 13:11:55,536 [salt.state       :1951][INFO    ][10838] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 13:11:55.536341 duration_in_ms=19.66
2019-11-29 13:11:55,537 [salt.state       :1780][INFO    ][10838] Running state [netfilter-persistent] at time 13:11:55.537207
2019-11-29 13:11:55,537 [salt.state       :1813][INFO    ][10838] Executing state service.running for [netfilter-persistent]
2019-11-29 13:11:55,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-29 13:11:55,557 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-29 13:11:55,574 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-29 13:11:55,593 [salt.state       :300 ][INFO    ][10838] The service netfilter-persistent is already running
2019-11-29 13:11:55,593 [salt.state       :1951][INFO    ][10838] Completed state [netfilter-persistent] at time 13:11:55.593723 duration_in_ms=56.516
2019-11-29 13:11:55,594 [salt.state       :1780][INFO    ][10838] Running state [iptables_extra.remove_stale_tables] at time 13:11:55.594478
2019-11-29 13:11:55,594 [salt.state       :1813][INFO    ][10838] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-29 13:11:55,595 [salt.state       :300 ][INFO    ][10838] No changes made for iptables_extra.remove_stale_tables
2019-11-29 13:11:55,595 [salt.state       :1951][INFO    ][10838] Completed state [iptables_extra.remove_stale_tables] at time 13:11:55.595336 duration_in_ms=0.858
2019-11-29 13:11:55,595 [salt.state       :1780][INFO    ][10838] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 13:11:55.595592
2019-11-29 13:11:55,595 [salt.state       :1813][INFO    ][10838] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-29 13:11:55,596 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10838] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-29 13:11:55,612 [salt.state       :300 ][INFO    ][10838] onlyif execution failed
2019-11-29 13:11:55,612 [salt.state       :1951][INFO    ][10838] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 13:11:55.612607 duration_in_ms=17.015
2019-11-29 13:11:55,613 [salt.state       :1780][INFO    ][10838] Running state [/etc/iptables/rules.v6] at time 13:11:55.613510
2019-11-29 13:11:55,613 [salt.state       :1813][INFO    ][10838] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-29 13:11:55,614 [salt.state       :300 ][INFO    ][10838] File /etc/iptables/rules.v6 is not present
2019-11-29 13:11:55,614 [salt.state       :1951][INFO    ][10838] Completed state [/etc/iptables/rules.v6] at time 13:11:55.614466 duration_in_ms=0.956
2019-11-29 13:11:55,615 [salt.state       :1780][INFO    ][10838] Running state [iptables_extra.flush_all] at time 13:11:55.615102
2019-11-29 13:11:55,615 [salt.state       :1813][INFO    ][10838] Executing state module.wait for [iptables_extra.flush_all]
2019-11-29 13:11:55,615 [salt.state       :300 ][INFO    ][10838] No changes made for iptables_extra.flush_all
2019-11-29 13:11:55,615 [salt.state       :1951][INFO    ][10838] Completed state [iptables_extra.flush_all] at time 13:11:55.615881 duration_in_ms=0.779
2019-11-29 13:11:55,618 [salt.minion      :1711][INFO    ][10838] Returning information for job: 20191129131147762568
2019-11-29 13:11:56,219 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129131156205747
2019-11-29 13:11:56,241 [salt.minion      :1432][INFO    ][10917] Starting a new job with PID 10917
2019-11-29 13:11:57,059 [salt.state       :915 ][INFO    ][10917] Loading fresh modules for state activity
2019-11-29 13:11:57,723 [salt.state       :1780][INFO    ][10917] Running state [maas-rack-controller] at time 13:11:57.723661
2019-11-29 13:11:57,724 [salt.state       :1813][INFO    ][10917] Executing state pkg.installed for [maas-rack-controller]
2019-11-29 13:11:57,724 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10917] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-29 13:11:57,831 [salt.state       :300 ][INFO    ][10917] All specified packages are already installed
2019-11-29 13:11:57,831 [salt.state       :1951][INFO    ][10917] Completed state [maas-rack-controller] at time 13:11:57.831765 duration_in_ms=108.104
2019-11-29 13:11:57,832 [salt.state       :1780][INFO    ][10917] Running state [ipmitool] at time 13:11:57.832180
2019-11-29 13:11:57,832 [salt.state       :1813][INFO    ][10917] Executing state pkg.installed for [ipmitool]
2019-11-29 13:11:57,841 [salt.state       :300 ][INFO    ][10917] All specified packages are already installed
2019-11-29 13:11:57,841 [salt.state       :1951][INFO    ][10917] Completed state [ipmitool] at time 13:11:57.841320 duration_in_ms=9.139
2019-11-29 13:11:57,845 [salt.state       :1780][INFO    ][10917] Running state [/etc/maas/rackd.conf] at time 13:11:57.845091
2019-11-29 13:11:57,845 [salt.state       :1813][INFO    ][10917] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-29 13:11:57,846 [salt.state       :300 ][INFO    ][10917] No changes needed to be made
2019-11-29 13:11:57,847 [salt.state       :1951][INFO    ][10917] Completed state [/etc/maas/rackd.conf] at time 13:11:57.847040 duration_in_ms=1.948
2019-11-29 13:11:57,847 [salt.state       :1780][INFO    ][10917] Running state [/etc/maas/rackd.conf] at time 13:11:57.847325
2019-11-29 13:11:57,847 [salt.state       :1813][INFO    ][10917] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-29 13:11:57,848 [salt.loaded.int.states.file:2298][WARNING ][10917] 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-11-29 13:11:57,848 [salt.state       :300 ][INFO    ][10917] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-29 13:11:57,848 [salt.state       :1951][INFO    ][10917] Completed state [/etc/maas/rackd.conf] at time 13:11:57.848930 duration_in_ms=1.605
2019-11-29 13:11:57,850 [salt.state       :1780][INFO    ][10917] Running state [maas-rackd] at time 13:11:57.850149
2019-11-29 13:11:57,850 [salt.state       :1813][INFO    ][10917] Executing state service.running for [maas-rackd]
2019-11-29 13:11:57,851 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10917] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-29 13:11:57,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10917] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-29 13:11:57,898 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10917] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-29 13:11:57,913 [salt.state       :300 ][INFO    ][10917] The service maas-rackd is already running
2019-11-29 13:11:57,914 [salt.state       :1951][INFO    ][10917] Completed state [maas-rackd] at time 13:11:57.913894 duration_in_ms=63.744
2019-11-29 13:11:57,916 [salt.minion      :1711][INFO    ][10917] Returning information for job: 20191129131156205747
2019-11-29 13:11:58,359 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129131158346433
2019-11-29 13:11:58,375 [salt.minion      :1432][INFO    ][10940] Starting a new job with PID 10940
2019-11-29 13:11:59,044 [salt.state       :915 ][INFO    ][10940] Loading fresh modules for state activity
2019-11-29 13:11:59,705 [salt.state       :1780][INFO    ][10940] Running state [maas-region-controller] at time 13:11:59.705917
2019-11-29 13:11:59,706 [salt.state       :1813][INFO    ][10940] Executing state pkg.installed for [maas-region-controller]
2019-11-29 13:11:59,706 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-29 13:11:59,776 [salt.state       :300 ][INFO    ][10940] All specified packages are already installed
2019-11-29 13:11:59,776 [salt.state       :1951][INFO    ][10940] Completed state [maas-region-controller] at time 13:11:59.776292 duration_in_ms=70.375
2019-11-29 13:11:59,776 [salt.state       :1780][INFO    ][10940] Running state [python-oauth] at time 13:11:59.776548
2019-11-29 13:11:59,776 [salt.state       :1813][INFO    ][10940] Executing state pkg.installed for [python-oauth]
2019-11-29 13:11:59,781 [salt.state       :300 ][INFO    ][10940] All specified packages are already installed
2019-11-29 13:11:59,781 [salt.state       :1951][INFO    ][10940] Completed state [python-oauth] at time 13:11:59.781348 duration_in_ms=4.801
2019-11-29 13:11:59,783 [salt.state       :1780][INFO    ][10940] Running state [/etc/maas/regiond.conf] at time 13:11:59.783594
2019-11-29 13:11:59,783 [salt.state       :1813][INFO    ][10940] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-29 13:11:59,843 [salt.state       :300 ][INFO    ][10940] No changes needed to be made
2019-11-29 13:11:59,844 [salt.state       :1951][INFO    ][10940] Completed state [/etc/maas/regiond.conf] at time 13:11:59.844001 duration_in_ms=60.407
2019-11-29 13:11:59,844 [salt.state       :1780][INFO    ][10940] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 13:11:59.844501
2019-11-29 13:11:59,844 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-29 13:11:59,908 [salt.state       :300 ][INFO    ][10940] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-29 13:11:59,909 [salt.state       :1951][INFO    ][10940] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 13:11:59.909099 duration_in_ms=64.598
2019-11-29 13:11:59,909 [salt.state       :1780][INFO    ][10940] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 13:11:59.909539
2019-11-29 13:11:59,909 [salt.state       :1813][INFO    ][10940] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-29 13:11:59,928 [salt.state       :300 ][INFO    ][10940] No changes needed to be made
2019-11-29 13:11:59,929 [salt.state       :1951][INFO    ][10940] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 13:11:59.929041 duration_in_ms=19.5
2019-11-29 13:11:59,929 [salt.state       :1780][INFO    ][10940] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 13:11:59.929913
2019-11-29 13:11:59,930 [salt.state       :1813][INFO    ][10940] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-29 13:11:59,959 [salt.state       :300 ][INFO    ][10940] No changes needed to be made
2019-11-29 13:11:59,959 [salt.state       :1951][INFO    ][10940] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 13:11:59.959652 duration_in_ms=29.739
2019-11-29 13:11:59,960 [salt.state       :1780][INFO    ][10940] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 13:11:59.960350
2019-11-29 13:11:59,960 [salt.state       :1813][INFO    ][10940] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-29 13:11:59,994 [salt.state       :300 ][INFO    ][10940] No changes needed to be made
2019-11-29 13:11:59,994 [salt.state       :1951][INFO    ][10940] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 13:11:59.994286 duration_in_ms=33.937
2019-11-29 13:11:59,994 [salt.state       :1780][INFO    ][10940] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 13:11:59.994890
2019-11-29 13:11:59,995 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-29 13:12:00,007 [salt.state       :300 ][INFO    ][10940] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-29 13:12:00,007 [salt.state       :1951][INFO    ][10940] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 13:12:00.007415 duration_in_ms=12.526
2019-11-29 13:12:00,008 [salt.state       :1780][INFO    ][10940] Running state [a2enmod headers] at time 13:12:00.008907
2019-11-29 13:12:00,009 [salt.state       :1813][INFO    ][10940] Executing state cmd.run for [a2enmod headers]
2019-11-29 13:12:00,009 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command 'a2enmod headers' in directory '/root'
2019-11-29 13:12:00,079 [salt.state       :300 ][INFO    ][10940] {'pid': 10960, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-29 13:12:00,079 [salt.state       :1951][INFO    ][10940] Completed state [a2enmod headers] at time 13:12:00.079904 duration_in_ms=70.996
2019-11-29 13:12:00,080 [salt.state       :1780][INFO    ][10940] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 13:12:00.080385
2019-11-29 13:12:00,080 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-29 13:12:00,097 [salt.state       :300 ][INFO    ][10940] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-29 13:12:00,097 [salt.state       :1951][INFO    ][10940] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 13:12:00.097778 duration_in_ms=17.392
2019-11-29 13:12:00,098 [salt.state       :1780][INFO    ][10940] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 13:12:00.098498
2019-11-29 13:12:00,098 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-29 13:12:00,166 [salt.state       :300 ][INFO    ][10940] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-29 13:12:00,167 [salt.state       :1951][INFO    ][10940] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 13:12:00.167064 duration_in_ms=68.566
2019-11-29 13:12:00,167 [salt.state       :1780][INFO    ][10940] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 13:12:00.167630
2019-11-29 13:12:00,167 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-29 13:12:00,245 [salt.state       :300 ][INFO    ][10940] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-29 13:12:00,246 [salt.state       :1951][INFO    ][10940] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 13:12:00.245941 duration_in_ms=78.31
2019-11-29 13:12:00,246 [salt.state       :1780][INFO    ][10940] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 13:12:00.246859
2019-11-29 13:12:00,247 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-29 13:12:00,304 [salt.state       :300 ][INFO    ][10940] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-29 13:12:00,304 [salt.state       :1951][INFO    ][10940] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 13:12:00.304387 duration_in_ms=57.528
2019-11-29 13:12:00,304 [salt.state       :1780][INFO    ][10940] Running state [/root/.pgpass] at time 13:12:00.304646
2019-11-29 13:12:00,304 [salt.state       :1813][INFO    ][10940] Executing state file.managed for [/root/.pgpass]
2019-11-29 13:12:00,340 [salt.state       :300 ][INFO    ][10940] File /root/.pgpass is in the correct state
2019-11-29 13:12:00,340 [salt.state       :1951][INFO    ][10940] Completed state [/root/.pgpass] at time 13:12:00.340370 duration_in_ms=35.723
2019-11-29 13:12:00,344 [salt.state       :1780][INFO    ][10940] Running state [maas-region syncdb --noinput] at time 13:12:00.344781
2019-11-29 13:12:00,345 [salt.state       :1813][INFO    ][10940] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-29 13:12:00,345 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-29 13:12:02,180 [salt.state       :300 ][INFO    ][10940] {'pid': 10973, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, auth, maasserver, piston3, contenttypes, sites, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-29 13:12:02,181 [salt.state       :1951][INFO    ][10940] Completed state [maas-region syncdb --noinput] at time 13:12:02.181408 duration_in_ms=1836.625
2019-11-29 13:12:02,181 [salt.state       :2022][WARNING ][10940] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-29 13:12:02,184 [salt.state       :1780][INFO    ][10940] Running state [maas-regiond] at time 13:12:02.184426
2019-11-29 13:12:02,184 [salt.state       :1813][INFO    ][10940] Executing state service.running for [maas-regiond]
2019-11-29 13:12:02,186 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-29 13:12:02,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-29 13:12:02,241 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-29 13:12:02,257 [salt.state       :300 ][INFO    ][10940] The service maas-regiond is already running
2019-11-29 13:12:02,257 [salt.state       :1951][INFO    ][10940] Completed state [maas-regiond] at time 13:12:02.257482 duration_in_ms=73.055
2019-11-29 13:12:02,259 [salt.state       :1780][INFO    ][10940] Running state [bind9] at time 13:12:02.259787
2019-11-29 13:12:02,260 [salt.state       :1813][INFO    ][10940] Executing state service.running for [bind9]
2019-11-29 13:12:02,261 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-29 13:12:02,277 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-29 13:12:02,292 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-29 13:12:02,307 [salt.state       :300 ][INFO    ][10940] The service bind9 is already running
2019-11-29 13:12:02,307 [salt.state       :1951][INFO    ][10940] Completed state [bind9] at time 13:12:02.307788 duration_in_ms=48.0
2019-11-29 13:12:02,309 [salt.state       :1780][INFO    ][10940] Running state [apache2] at time 13:12:02.309817
2019-11-29 13:12:02,310 [salt.state       :1813][INFO    ][10940] Executing state service.running for [apache2]
2019-11-29 13:12:02,311 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-29 13:12:02,327 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-29 13:12:02,341 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-29 13:12:02,361 [salt.state       :300 ][INFO    ][10940] The service apache2 is already running
2019-11-29 13:12:02,361 [salt.state       :1951][INFO    ][10940] Completed state [apache2] at time 13:12:02.361569 duration_in_ms=51.751
2019-11-29 13:12:02,363 [salt.state       :1780][INFO    ][10940] Running state [maasng.wait_for_http_code] at time 13:12:02.363720
2019-11-29 13:12:02,364 [salt.state       :1813][INFO    ][10940] Executing state module.run for [maasng.wait_for_http_code]
2019-11-29 13:12:02,364 [salt.utils.decorators:613 ][WARNING ][10940] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:12:02,506 [salt.state       :300 ][INFO    ][10940] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-29 13:12:02,507 [salt.state       :1951][INFO    ][10940] Completed state [maasng.wait_for_http_code] at time 13:12:02.506943 duration_in_ms=143.223
2019-11-29 13:12:02,508 [salt.state       :1780][INFO    ][10940] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 13:12:02.508361
2019-11-29 13:12:02,508 [salt.state       :1813][INFO    ][10940] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-29 13:12:02,509 [salt.state       :300 ][INFO    ][10940] /var/lib/maas/.setup_admin exists
2019-11-29 13:12:02,510 [salt.state       :1951][INFO    ][10940] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 13:12:02.510004 duration_in_ms=1.643
2019-11-29 13:12:02,511 [salt.state       :1780][INFO    ][10940] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:12:02.511179
2019-11-29 13:12:02,511 [salt.state       :1813][INFO    ][10940] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:12:02,512 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10940] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:12:03,873 [salt.state       :300 ][INFO    ][10940] {'pid': 10994, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:12:03,873 [salt.state       :1951][INFO    ][10940] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:12:03.873429 duration_in_ms=1362.251
2019-11-29 13:12:03,878 [salt.state       :1780][INFO    ][10940] Running state [maas_region_boot_source_resources_mirror] at time 13:12:03.878316
2019-11-29 13:12:03,878 [salt.state       :1813][INFO    ][10940] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-29 13:12:03,982 [salt.state       :300 ][INFO    ][10940] {'changes': {}}
2019-11-29 13:12:03,983 [salt.state       :1951][INFO    ][10940] Completed state [maas_region_boot_source_resources_mirror] at time 13:12:03.983290 duration_in_ms=104.971
2019-11-29 13:12:03,984 [salt.state       :1780][INFO    ][10940] Running state [maasng.boot_resources_import] at time 13:12:03.984402
2019-11-29 13:12:03,984 [salt.state       :1813][INFO    ][10940] Executing state module.run for [maasng.boot_resources_import]
2019-11-29 13:12:03,985 [salt.utils.decorators:613 ][WARNING ][10940] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:12:04,140 [salt.loaded.ext.module.maasng:1600][INFO    ][10940] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-29 13:12:09,194 [salt.loaded.ext.module.maasng:1600][INFO    ][10940] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-29 13:12:13,436 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131213423565
2019-11-29 13:12:13,460 [salt.minion      :1432][INFO    ][11038] Starting a new job with PID 11038
2019-11-29 13:12:13,482 [salt.minion      :1711][INFO    ][11038] Returning information for job: 20191129131213423565
2019-11-29 13:12:14,253 [salt.loaded.ext.module.maasng:1600][INFO    ][10940] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-29 13:12:19,380 [salt.state       :300 ][INFO    ][10940] {'ret': True}
2019-11-29 13:12:19,380 [salt.state       :1951][INFO    ][10940] Completed state [maasng.boot_resources_import] at time 13:12:19.380586 duration_in_ms=15396.183
2019-11-29 13:12:19,381 [salt.state       :1780][INFO    ][10940] Running state [maas_region_boot_sources_selection_xenial] at time 13:12:19.381738
2019-11-29 13:12:19,382 [salt.state       :1813][INFO    ][10940] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-11-29 13:12:19,588 [salt.state       :300 ][INFO    ][10940] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-29 13:12:19,589 [salt.state       :1951][INFO    ][10940] Completed state [maas_region_boot_sources_selection_xenial] at time 13:12:19.589118 duration_in_ms=207.38
2019-11-29 13:12:19,590 [salt.state       :1780][INFO    ][10940] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 13:12:19.590493
2019-11-29 13:12:19,591 [salt.state       :1813][INFO    ][10940] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-29 13:12:19,591 [salt.utils.decorators:613 ][WARNING ][10940] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:12:19,592 [salt.loaded.ext.module.maasng:1771][INFO    ][10940] boot-sources sync initiated for ALL Rack's
2019-11-29 13:12:20,516 [salt.state       :300 ][INFO    ][10940] {'ret': True}
2019-11-29 13:12:20,517 [salt.state       :1951][INFO    ][10940] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 13:12:20.517031 duration_in_ms=926.537
2019-11-29 13:12:20,519 [salt.state       :1780][INFO    ][10940] Running state [maas.process_maas_config] at time 13:12:20.519145
2019-11-29 13:12:20,519 [salt.state       :1813][INFO    ][10940] Executing state module.run for [maas.process_maas_config]
2019-11-29 13:12:20,520 [salt.utils.decorators:613 ][WARNING ][10940] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:12:20,521 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=enable_http_proxy value=True
2019-11-29 13:12:20,584 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=upstream_dns value=8.8.8.8
2019-11-29 13:12:20,649 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=commissioning_distro_series value=xenial
2019-11-29 13:12:20,714 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=default_osystem value=ubuntu
2019-11-29 13:12:23,570 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=active_discovery_interval value=600
2019-11-29 13:12:23,626 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=dnssec_validation value=no
2019-11-29 13:12:23,674 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=maas_name value=mas01
2019-11-29 13:12:23,743 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=network_discovery value=enabled
2019-11-29 13:12:23,860 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=enable_third_party_drivers value=True
2019-11-29 13:12:23,933 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=default_storage_layout value=lvm
2019-11-29 13:12:23,991 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=ntp_external_only value=True
2019-11-29 13:12:24,044 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-29 13:12:24,104 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=default_distro_series value=xenial
2019-11-29 13:12:24,204 [salt.loaded.ext.module.maas:92  ][INFO    ][10940] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-11-29 13:12:24,375 [salt.state       :300 ][INFO    ][10940] {'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-11-29 13:12:24,376 [salt.state       :1951][INFO    ][10940] Completed state [maas.process_maas_config] at time 13:12:24.376285 duration_in_ms=3857.139
2019-11-29 13:12:24,377 [salt.state       :1780][INFO    ][10940] Running state [pxe_admin] at time 13:12:24.377608
2019-11-29 13:12:24,378 [salt.state       :1813][INFO    ][10940] Executing state maasng.fabric_present for [pxe_admin]
2019-11-29 13:12:24,439 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-11-29 13:12:24,511 [salt.loaded.ext.module.maasng:1008][WARNING ][10940] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-29 13:12:24,511 [salt.loaded.ext.module.maasng:1011][WARNING ][10940] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-29 13:12:24,583 [salt.state       :300 ][INFO    ][10940] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-29 13:12:24,583 [salt.state       :1951][INFO    ][10940] Completed state [pxe_admin] at time 13:12:24.583439 duration_in_ms=205.831
2019-11-29 13:12:24,583 [salt.state       :1780][INFO    ][10940] Running state [vlan 0] at time 13:12:24.583860
2019-11-29 13:12:24,584 [salt.state       :1813][INFO    ][10940] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-29 13:12:24,666 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, 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'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, 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'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', 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'wptxe8', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-11-29 13:12:24,805 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-29 13:12:25,087 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, 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'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, 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'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', 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'wptxe8', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-11-29 13:12:25,333 [salt.state       :300 ][INFO    ][10940] {'new': 'Vlan untagged was updated'}
2019-11-29 13:12:25,333 [salt.state       :1951][INFO    ][10940] Completed state [vlan 0] at time 13:12:25.333784 duration_in_ms=749.924
2019-11-29 13:12:25,335 [salt.state       :1780][INFO    ][10940] Running state [192.168.11.0/24] at time 13:12:25.335435
2019-11-29 13:12:25,335 [salt.state       :1813][INFO    ][10940] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-29 13:12:25,529 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wptxe8', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-29 13:12:25,530 [salt.loaded.ext.module.maasng:1235][WARNING ][10940] Ignoring parameter vlan:0
2019-11-29 13:12:25,619 [salt.state       :300 ][INFO    ][10940] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-29 13:12:25,620 [salt.state       :1951][INFO    ][10940] Completed state [192.168.11.0/24] at time 13:12:25.620247 duration_in_ms=284.812
2019-11-29 13:12:25,621 [salt.state       :1780][INFO    ][10940] Running state [maas_create_iprange_1] at time 13:12:25.621499
2019-11-29 13:12:25,621 [salt.state       :1813][INFO    ][10940] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-29 13:12:25,691 [salt.state       :300 ][INFO    ][10940] Iprange maas_create_iprange_1 already exist.
2019-11-29 13:12:25,692 [salt.state       :1951][INFO    ][10940] Completed state [maas_create_iprange_1] at time 13:12:25.691928 duration_in_ms=70.428
2019-11-29 13:12:25,692 [salt.state       :1780][INFO    ][10940] Running state [vlan 0] at time 13:12:25.692442
2019-11-29 13:12:25,692 [salt.state       :1813][INFO    ][10940] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-29 13:12:25,750 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wptxe8', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-29 13:12:25,859 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wptxe8', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-29 13:12:26,087 [salt.loaded.ext.module.maasng:945 ][INFO    ][10940] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wptxe8', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-29 13:12:26,165 [salt.state       :300 ][INFO    ][10940] {'new': 'Vlan untagged was updated'}
2019-11-29 13:12:26,165 [salt.state       :1951][INFO    ][10940] Completed state [vlan 0] at time 13:12:26.165531 duration_in_ms=473.086
2019-11-29 13:12:26,166 [salt.state       :1780][INFO    ][10940] Running state [opnfv] at time 13:12:26.166538
2019-11-29 13:12:26,167 [salt.state       :1813][INFO    ][10940] Executing state maasng.sshkey_present for [opnfv]
2019-11-29 13:12:26,218 [salt.loaded.ext.module.maasng:1903][INFO    ][10940] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-11-29 13:12:26,218 [salt.state       :300 ][INFO    ][10940] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-29 13:12:26,219 [salt.state       :1951][INFO    ][10940] Completed state [opnfv] at time 13:12:26.218970 duration_in_ms=52.432
2019-11-29 13:12:26,223 [salt.minion      :1711][INFO    ][10940] Returning information for job: 20191129131158346433
2019-11-29 13:12:26,802 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129131226787155
2019-11-29 13:12:26,820 [salt.minion      :1432][INFO    ][11397] Starting a new job with PID 11397
2019-11-29 13:12:30,582 [salt.state       :915 ][INFO    ][11397] Loading fresh modules for state activity
2019-11-29 13:12:30,678 [salt.state       :1780][INFO    ][11397] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:12:30.678233
2019-11-29 13:12:30,678 [salt.state       :1813][INFO    ][11397] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:12:30,680 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11397] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:12:32,183 [salt.state       :300 ][INFO    ][11397] {'pid': 11420, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:12:32,184 [salt.state       :1951][INFO    ][11397] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:12:32.183895 duration_in_ms=1505.662
2019-11-29 13:12:32,186 [salt.state       :1780][INFO    ][11397] Running state [maas.process_machines] at time 13:12:32.186421
2019-11-29 13:12:32,186 [salt.state       :1813][INFO    ][11397] Executing state module.run for [maas.process_machines]
2019-11-29 13:12:32,188 [salt.utils.decorators:613 ][WARNING ][11397] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:12:32,937 [salt.loaded.ext.module.maas:412 ][WARNING ][11397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 13:12:32,938 [salt.loaded.ext.module.maas:92  ][INFO    ][11397] 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=qwkryq architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 13:12:34,082 [salt.loaded.ext.module.maas:412 ][WARNING ][11397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 13:12:34,083 [salt.loaded.ext.module.maas:92  ][INFO    ][11397] 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=ar3db6 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 13:12:35,351 [salt.loaded.ext.module.maas:412 ][WARNING ][11397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 13:12:35,352 [salt.loaded.ext.module.maas:92  ][INFO    ][11397] 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=t4mkgg architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 13:12:36,532 [salt.loaded.ext.module.maas:412 ][WARNING ][11397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 13:12:36,533 [salt.loaded.ext.module.maas:92  ][INFO    ][11397] 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=mdnqb3 architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 13:12:37,447 [salt.loaded.ext.module.maas:412 ][WARNING ][11397] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-29 13:12:37,447 [salt.loaded.ext.module.maas:92  ][INFO    ][11397] 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=bh7kpt architecture=amd64/generic power_parameters_power_user=admin
2019-11-29 13:12:38,507 [salt.state       :300 ][INFO    ][11397] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-29 13:12:38,507 [salt.state       :1951][INFO    ][11397] Completed state [maas.process_machines] at time 13:12:38.507443 duration_in_ms=6321.022
2019-11-29 13:12:38,510 [salt.minion      :1711][INFO    ][11397] Returning information for job: 20191129131226787155
2019-11-29 13:13:11,805 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129131311792531
2019-11-29 13:13:11,826 [salt.minion      :1432][INFO    ][11679] Starting a new job with PID 11679
2019-11-29 13:13:15,580 [salt.state       :915 ][INFO    ][11679] Loading fresh modules for state activity
2019-11-29 13:13:15,629 [salt.state       :1780][INFO    ][11679] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:13:15.629864
2019-11-29 13:13:15,630 [salt.state       :1813][INFO    ][11679] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:13:15,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11679] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:13:17,088 [salt.state       :300 ][INFO    ][11679] {'pid': 11686, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:13:17,089 [salt.state       :1951][INFO    ][11679] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:13:17.089388 duration_in_ms=1459.523
2019-11-29 13:13:17,090 [salt.state       :1780][INFO    ][11679] Running state [maas.wait_for_machine_status] at time 13:13:17.090618
2019-11-29 13:13:17,090 [salt.state       :1813][INFO    ][11679] Executing state module.run for [maas.wait_for_machine_status]
2019-11-29 13:13:17,091 [salt.utils.decorators:613 ][WARNING ][11679] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:13:18,949 [salt.loaded.ext.module.maas:993 ][INFO    ][11679] Machine t4mkgg mark broken
2019-11-29 13:13:19,591 [salt.loaded.ext.module.maas:996 ][INFO    ][11679] Machine t4mkgg mark fixed
2019-11-29 13:13:20,722 [salt.loaded.ext.module.maas:684 ][INFO    ][11679] deploymachines hwe_kernel=hwe-16.04 system_id=t4mkgg distro_series=xenial
2019-11-29 13:13:24,686 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.40959215s left)
2019-11-29 13:13:26,879 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131326864353
2019-11-29 13:13:26,902 [salt.minion      :1432][INFO    ][11769] Starting a new job with PID 11769
2019-11-29 13:13:26,928 [salt.minion      :1711][INFO    ][11769] Returning information for job: 20191129131326864353
2019-11-29 13:13:56,934 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131356918797
2019-11-29 13:13:56,955 [salt.minion      :1432][INFO    ][11801] Starting a new job with PID 11801
2019-11-29 13:13:56,980 [salt.minion      :1711][INFO    ][11801] Returning information for job: 20191129131356918797
2019-11-29 13:13:58,077 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1459.01885104s left)
2019-11-29 13:14:27,150 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131427092344
2019-11-29 13:14:27,171 [salt.minion      :1432][INFO    ][11839] Starting a new job with PID 11839
2019-11-29 13:14:27,198 [salt.minion      :1711][INFO    ][11839] Returning information for job: 20191129131427092344
2019-11-29 13:14:31,705 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.39079309s left)
2019-11-29 13:14:57,202 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131457188376
2019-11-29 13:14:57,224 [salt.minion      :1432][INFO    ][11868] Starting a new job with PID 11868
2019-11-29 13:14:57,249 [salt.minion      :1711][INFO    ][11868] Returning information for job: 20191129131457188376
2019-11-29 13:15:04,804 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.29136705s left)
2019-11-29 13:15:27,260 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131527247696
2019-11-29 13:15:27,283 [salt.minion      :1432][INFO    ][11962] Starting a new job with PID 11962
2019-11-29 13:15:27,309 [salt.minion      :1711][INFO    ][11962] Returning information for job: 20191129131527247696
2019-11-29 13:15:37,531 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.56451797s left)
2019-11-29 13:15:57,315 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131557303176
2019-11-29 13:15:57,337 [salt.minion      :1432][INFO    ][12050] Starting a new job with PID 12050
2019-11-29 13:15:57,363 [salt.minion      :1711][INFO    ][12050] Returning information for job: 20191129131557303176
2019-11-29 13:16:11,184 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.91156507s left)
2019-11-29 13:16:27,376 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131627360975
2019-11-29 13:16:27,398 [salt.minion      :1432][INFO    ][12143] Starting a new job with PID 12143
2019-11-29 13:16:27,423 [salt.minion      :1711][INFO    ][12143] Returning information for job: 20191129131627360975
2019-11-29 13:16:44,656 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.43917918s left)
2019-11-29 13:16:57,436 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131657423768
2019-11-29 13:16:57,458 [salt.minion      :1432][INFO    ][12247] Starting a new job with PID 12247
2019-11-29 13:16:57,484 [salt.minion      :1711][INFO    ][12247] Returning information for job: 20191129131657423768
2019-11-29 13:17:18,199 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.89671707s left)
2019-11-29 13:17:27,501 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131727487891
2019-11-29 13:17:27,523 [salt.minion      :1432][INFO    ][12303] Starting a new job with PID 12303
2019-11-29 13:17:27,549 [salt.minion      :1711][INFO    ][12303] Returning information for job: 20191129131727487891
2019-11-29 13:17:51,765 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1225.33092999s left)
2019-11-29 13:17:57,576 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131757562642
2019-11-29 13:17:57,598 [salt.minion      :1432][INFO    ][12366] Starting a new job with PID 12366
2019-11-29 13:17:57,623 [salt.minion      :1711][INFO    ][12366] Returning information for job: 20191129131757562642
2019-11-29 13:18:24,936 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1192.16006398s left)
2019-11-29 13:18:27,650 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131827637665
2019-11-29 13:18:27,672 [salt.minion      :1432][INFO    ][12438] Starting a new job with PID 12438
2019-11-29 13:18:27,697 [salt.minion      :1711][INFO    ][12438] Returning information for job: 20191129131827637665
2019-11-29 13:18:57,728 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131857715040
2019-11-29 13:18:57,750 [salt.minion      :1432][INFO    ][12549] Starting a new job with PID 12549
2019-11-29 13:18:57,775 [salt.minion      :1711][INFO    ][12549] Returning information for job: 20191129131857715040
2019-11-29 13:18:58,623 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1158.47242403s left)
2019-11-29 13:19:27,805 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131927793281
2019-11-29 13:19:27,824 [salt.minion      :1432][INFO    ][12616] Starting a new job with PID 12616
2019-11-29 13:19:27,851 [salt.minion      :1711][INFO    ][12616] Returning information for job: 20191129131927793281
2019-11-29 13:19:31,917 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1125.17866516s left)
2019-11-29 13:19:57,895 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129131957880833
2019-11-29 13:19:57,918 [salt.minion      :1432][INFO    ][12703] Starting a new job with PID 12703
2019-11-29 13:19:57,944 [salt.minion      :1711][INFO    ][12703] Returning information for job: 20191129131957880833
2019-11-29 13:20:05,275 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.82036495s left)
2019-11-29 13:20:27,995 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129132027982116
2019-11-29 13:20:28,018 [salt.minion      :1432][INFO    ][12777] Starting a new job with PID 12777
2019-11-29 13:20:28,043 [salt.minion      :1711][INFO    ][12777] Returning information for job: 20191129132027982116
2019-11-29 13:20:39,077 [salt.loaded.ext.module.maas:1023][INFO    ][11679] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1058.01902008s left)
2019-11-29 13:20:58,062 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command saltutil.find_job with jid 20191129132058048886
2019-11-29 13:20:58,085 [salt.minion      :1432][INFO    ][12825] Starting a new job with PID 12825
2019-11-29 13:20:58,111 [salt.minion      :1711][INFO    ][12825] Returning information for job: 20191129132058048886
2019-11-29 13:21:12,757 [salt.state       :300 ][INFO    ][11679] {'ret': True}
2019-11-29 13:21:12,758 [salt.state       :1951][INFO    ][11679] Completed state [maas.wait_for_machine_status] at time 13:21:12.758321 duration_in_ms=475667.699
2019-11-29 13:21:12,762 [salt.minion      :1711][INFO    ][11679] Returning information for job: 20191129131311792531
2019-11-29 13:21:13,419 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129132113406710
2019-11-29 13:21:13,441 [salt.minion      :1432][INFO    ][12903] Starting a new job with PID 12903
2019-11-29 13:21:17,202 [salt.state       :915 ][INFO    ][12903] Loading fresh modules for state activity
2019-11-29 13:21:17,334 [salt.state       :1780][INFO    ][12903] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:17.334432
2019-11-29 13:21:17,334 [salt.state       :1813][INFO    ][12903] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:21:17,336 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12903] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:21:18,772 [salt.state       :300 ][INFO    ][12903] {'pid': 12914, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:21:18,772 [salt.state       :1951][INFO    ][12903] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:18.772587 duration_in_ms=1438.156
2019-11-29 13:21:18,774 [salt.state       :1780][INFO    ][12903] Running state [maas_machines_storage_cmp002_lvm] at time 13:21:18.773973
2019-11-29 13:21:18,774 [salt.state       :1813][INFO    ][12903] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-29 13:21:19,454 [salt.state       :300 ][INFO    ][12903] Machine cmp002 is not in Ready state.
2019-11-29 13:21:19,454 [salt.state       :1951][INFO    ][12903] Completed state [maas_machines_storage_cmp002_lvm] at time 13:21:19.454627 duration_in_ms=680.652
2019-11-29 13:21:19,455 [salt.state       :1780][INFO    ][12903] Running state [maas_machines_storage_cmp001_lvm] at time 13:21:19.455235
2019-11-29 13:21:19,455 [salt.state       :1813][INFO    ][12903] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-29 13:21:20,152 [salt.state       :300 ][INFO    ][12903] Machine cmp001 is not in Ready state.
2019-11-29 13:21:20,153 [salt.state       :1951][INFO    ][12903] Completed state [maas_machines_storage_cmp001_lvm] at time 13:21:20.152934 duration_in_ms=697.699
2019-11-29 13:21:20,157 [salt.minion      :1711][INFO    ][12903] Returning information for job: 20191129132113406710
2019-11-29 13:21:20,793 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129132120779663
2019-11-29 13:21:20,816 [salt.minion      :1432][INFO    ][12925] Starting a new job with PID 12925
2019-11-29 13:21:21,557 [salt.state       :915 ][INFO    ][12925] Loading fresh modules for state activity
2019-11-29 13:21:21,646 [salt.state       :1780][INFO    ][12925] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:21.646015
2019-11-29 13:21:21,646 [salt.state       :1813][INFO    ][12925] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:21:21,648 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12925] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:21:22,941 [salt.state       :300 ][INFO    ][12925] {'pid': 12932, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:21:22,942 [salt.state       :1951][INFO    ][12925] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:22.942508 duration_in_ms=1296.493
2019-11-29 13:21:22,945 [salt.state       :1780][INFO    ][12925] Running state [maas.deploy_machines] at time 13:21:22.944960
2019-11-29 13:21:22,945 [salt.state       :1813][INFO    ][12925] Executing state module.run for [maas.deploy_machines]
2019-11-29 13:21:22,946 [salt.utils.decorators:613 ][WARNING ][12925] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:21:23,725 [salt.state       :300 ][INFO    ][12925] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-29 13:21:23,725 [salt.state       :1951][INFO    ][12925] Completed state [maas.deploy_machines] at time 13:21:23.725397 duration_in_ms=780.437
2019-11-29 13:21:23,728 [salt.minion      :1711][INFO    ][12925] Returning information for job: 20191129132120779663
2019-11-29 13:21:24,321 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command state.apply with jid 20191129132124306938
2019-11-29 13:21:24,342 [salt.minion      :1432][INFO    ][12941] Starting a new job with PID 12941
2019-11-29 13:21:25,199 [salt.state       :915 ][INFO    ][12941] Loading fresh modules for state activity
2019-11-29 13:21:25,285 [salt.state       :1780][INFO    ][12941] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:25.285518
2019-11-29 13:21:25,285 [salt.state       :1813][INFO    ][12941] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-29 13:21:25,288 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12941] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-29 13:21:26,919 [salt.state       :300 ][INFO    ][12941] {'pid': 12961, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-29 13:21:26,920 [salt.state       :1951][INFO    ][12941] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:21:26.920083 duration_in_ms=1634.564
2019-11-29 13:21:26,923 [salt.state       :1780][INFO    ][12941] Running state [maas.wait_for_machine_status] at time 13:21:26.923483
2019-11-29 13:21:26,924 [salt.state       :1813][INFO    ][12941] Executing state module.run for [maas.wait_for_machine_status]
2019-11-29 13:21:26,924 [salt.utils.decorators:613 ][WARNING ][12941] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-29 13:21:30,411 [salt.state       :300 ][INFO    ][12941] {'ret': True}
2019-11-29 13:21:30,411 [salt.state       :1951][INFO    ][12941] Completed state [maas.wait_for_machine_status] at time 13:21:30.411679 duration_in_ms=3488.195
2019-11-29 13:21:30,415 [salt.minion      :1711][INFO    ][12941] Returning information for job: 20191129132124306938
2019-11-29 13:49:30,145 [salt.utils.schedule:1377][INFO    ][3175] Running scheduled job: __mine_interval
2019-11-29 14:46:24,553 [salt.minion      :1308][INFO    ][3175] User sudo_ubuntu Executing command cp.push_dir with jid 20191129144624541150
2019-11-29 14:46:24,571 [salt.minion      :1432][INFO    ][18960] Starting a new job with PID 18960
