2019-10-26 05:11:33,920 [salt.utils.decorators:613 ][WARNING ][2184] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:11:34,405 [salt.utils.decorators:613 ][WARNING ][2184] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:11:36,527 [salt.loaded.int.states.file:2298][WARNING ][2416] 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-10-26 05:11:55,655 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2993] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-10-26 05:11:55,681 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2993] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-10-26 05:11:55,696 [salt.utils.parsers:1051][WARNING ][322] Minion received a SIGTERM. Exiting.
2019-10-26 05:11:56,702 [salt.cli.daemons :293 ][INFO    ][3111] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-10-26 05:11:56,796 [salt.cli.daemons :82  ][INFO    ][3111] Starting up the Salt Minion
2019-10-26 05:11:56,797 [salt.utils.event :1017][INFO    ][3111] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-10-26 05:11:57,610 [salt.minion      :976 ][INFO    ][3111] Creating minion process manager
2019-10-26 05:11:58,740 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3111] Executing command ['date', '+%z'] in directory '/root'
2019-10-26 05:11:58,759 [salt.utils.schedule:568 ][INFO    ][3111] Updating job settings for scheduled job: __mine_interval
2019-10-26 05:11:58,760 [salt.minion      :1108][INFO    ][3111] Added mine.update to scheduler
2019-10-26 05:11:58,763 [salt.minion      :1975][INFO    ][3111] Minion is starting as user 'root'
2019-10-26 05:11:58,773 [salt.minion      :2336][INFO    ][3111] Minion is ready to receive requests!
2019-10-26 05:12:02,321 [salt.state       :2022][WARNING ][2990] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-10-26 05:12:04,835 [salt.utils.decorators:613 ][WARNING ][2990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:12:09,193 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051209181775
2019-10-26 05:12:09,214 [salt.minion      :1432][INFO    ][3581] Starting a new job with PID 3581
2019-10-26 05:12:09,237 [salt.minion      :1711][INFO    ][3581] Returning information for job: 20191026051209181775
2019-10-26 05:12:39,250 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051239233990
2019-10-26 05:12:39,274 [salt.minion      :1432][INFO    ][3861] Starting a new job with PID 3861
2019-10-26 05:12:39,296 [salt.minion      :1711][INFO    ][3861] Returning information for job: 20191026051239233990
2019-10-26 05:12:43,470 [salt.utils.decorators:613 ][WARNING ][2990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:13:09,345 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051309331976
2019-10-26 05:13:09,368 [salt.minion      :1432][INFO    ][4127] Starting a new job with PID 4127
2019-10-26 05:13:09,389 [salt.minion      :1711][INFO    ][4127] Returning information for job: 20191026051309331976
2019-10-26 05:13:39,408 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051339395885
2019-10-26 05:13:39,431 [salt.minion      :1432][INFO    ][4227] Starting a new job with PID 4227
2019-10-26 05:13:39,451 [salt.minion      :1711][INFO    ][4227] Returning information for job: 20191026051339395885
2019-10-26 05:13:54,475 [salt.utils.decorators:613 ][WARNING ][2990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:14:09,463 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051409451171
2019-10-26 05:14:09,483 [salt.minion      :1432][INFO    ][4315] Starting a new job with PID 4315
2019-10-26 05:14:09,503 [salt.minion      :1711][INFO    ][4315] Returning information for job: 20191026051409451171
2019-10-26 05:14:11,746 [salt.utils.decorators:613 ][WARNING ][2990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:14:15,480 [salt.loaded.ext.module.maasng:1008][WARNING ][2990] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-10-26 05:14:15,480 [salt.loaded.ext.module.maasng:1011][WARNING ][2990] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-10-26 05:14:16,360 [salt.loaded.ext.module.maasng:1235][WARNING ][2990] Ignoring parameter vlan:0
2019-10-26 05:14:17,472 [salt.utils.decorators:613 ][WARNING ][2990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:14:18,168 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026051418161395
2019-10-26 05:14:18,187 [salt.minion      :1432][INFO    ][4501] Starting a new job with PID 4501
2019-10-26 05:14:22,134 [salt.state       :915 ][INFO    ][4501] Loading fresh modules for state activity
2019-10-26 05:14:22,194 [salt.fileclient  :1219][INFO    ][4501] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-10-26 05:14:22,237 [salt.state       :1780][INFO    ][4501] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:22.237314
2019-10-26 05:14:22,237 [salt.state       :1813][INFO    ][4501] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:14:22,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4501] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:14:23,710 [salt.state       :300 ][INFO    ][4501] {'pid': 4530, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:14:23,711 [salt.state       :1951][INFO    ][4501] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:23.711625 duration_in_ms=1474.31
2019-10-26 05:14:23,714 [salt.state       :1780][INFO    ][4501] Running state [maas.process_machines] at time 05:14:23.714089
2019-10-26 05:14:23,714 [salt.state       :1813][INFO    ][4501] Executing state module.run for [maas.process_machines]
2019-10-26 05:14:23,715 [salt.utils.decorators:613 ][WARNING ][4501] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:14:23,792 [salt.loaded.ext.module.maas:412 ][WARNING ][4501] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:14:23,793 [salt.loaded.ext.module.maas:92  ][INFO    ][4501] 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-10-26 05:14:25,381 [salt.loaded.ext.module.maas:412 ][WARNING ][4501] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:14:25,382 [salt.loaded.ext.module.maas:92  ][INFO    ][4501] 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-10-26 05:14:26,681 [salt.loaded.ext.module.maas:412 ][WARNING ][4501] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:14:26,681 [salt.loaded.ext.module.maas:92  ][INFO    ][4501] 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-10-26 05:14:28,071 [salt.loaded.ext.module.maas:412 ][WARNING ][4501] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:14:28,071 [salt.loaded.ext.module.maas:92  ][INFO    ][4501] 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-10-26 05:14:29,417 [salt.loaded.ext.module.maas:412 ][WARNING ][4501] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:14:29,417 [salt.loaded.ext.module.maas:92  ][INFO    ][4501] 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-10-26 05:14:30,849 [salt.state       :300 ][INFO    ][4501] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-10-26 05:14:30,849 [salt.state       :1951][INFO    ][4501] Completed state [maas.process_machines] at time 05:14:30.849746 duration_in_ms=7135.656
2019-10-26 05:14:30,853 [salt.minion      :1711][INFO    ][4501] Returning information for job: 20191026051418161395
2019-10-26 05:15:02,018 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026051502001898
2019-10-26 05:15:02,043 [salt.minion      :1432][INFO    ][4843] Starting a new job with PID 4843
2019-10-26 05:15:05,818 [salt.state       :915 ][INFO    ][4843] Loading fresh modules for state activity
2019-10-26 05:15:05,859 [salt.fileclient  :1219][INFO    ][4843] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-10-26 05:15:05,893 [salt.state       :1780][INFO    ][4843] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:05.893221
2019-10-26 05:15:05,893 [salt.state       :1813][INFO    ][4843] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:15:05,895 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4843] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:15:07,369 [salt.state       :300 ][INFO    ][4843] {'pid': 4859, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:15:07,370 [salt.state       :1951][INFO    ][4843] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:15:07.370279 duration_in_ms=1477.059
2019-10-26 05:15:07,371 [salt.state       :1780][INFO    ][4843] Running state [maas.wait_for_machine_status] at time 05:15:07.371422
2019-10-26 05:15:07,371 [salt.state       :1813][INFO    ][4843] Executing state module.run for [maas.wait_for_machine_status]
2019-10-26 05:15:07,371 [salt.utils.decorators:613 ][WARNING ][4843] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:15:08,328 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.04744911s left)
2019-10-26 05:15:17,101 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051517088114
2019-10-26 05:15:17,126 [salt.minion      :1432][INFO    ][4889] Starting a new job with PID 4889
2019-10-26 05:15:17,148 [salt.minion      :1711][INFO    ][4889] Returning information for job: 20191026051517088114
2019-10-26 05:15:39,301 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.07452917s left)
2019-10-26 05:15:47,153 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051547141008
2019-10-26 05:15:47,178 [salt.minion      :1432][INFO    ][4912] Starting a new job with PID 4912
2019-10-26 05:15:47,198 [salt.minion      :1711][INFO    ][4912] Returning information for job: 20191026051547141008
2019-10-26 05:16:10,657 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.71908712s left)
2019-10-26 05:16:17,185 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051617177707
2019-10-26 05:16:17,206 [salt.minion      :1432][INFO    ][5077] Starting a new job with PID 5077
2019-10-26 05:16:17,227 [salt.minion      :1711][INFO    ][5077] Returning information for job: 20191026051617177707
2019-10-26 05:16:41,972 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.40371108s left)
2019-10-26 05:16:47,233 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051647219074
2019-10-26 05:16:47,257 [salt.minion      :1432][INFO    ][5265] Starting a new job with PID 5265
2019-10-26 05:16:47,278 [salt.minion      :1711][INFO    ][5265] Returning information for job: 20191026051647219074
2019-10-26 05:17:13,607 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.76890922s left)
2019-10-26 05:17:17,295 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051717284121
2019-10-26 05:17:17,319 [salt.minion      :1432][INFO    ][5810] Starting a new job with PID 5810
2019-10-26 05:17:17,339 [salt.minion      :1711][INFO    ][5810] Returning information for job: 20191026051717284121
2019-10-26 05:17:45,450 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.92593718s left)
2019-10-26 05:17:47,350 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051747333688
2019-10-26 05:17:47,375 [salt.minion      :1432][INFO    ][5989] Starting a new job with PID 5989
2019-10-26 05:17:47,398 [salt.minion      :1711][INFO    ][5989] Returning information for job: 20191026051747333688
2019-10-26 05:18:17,419 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051817402680
2019-10-26 05:18:17,444 [salt.minion      :1432][INFO    ][6189] Starting a new job with PID 6189
2019-10-26 05:18:17,466 [salt.minion      :1711][INFO    ][6189] Returning information for job: 20191026051817402680
2019-10-26 05:18:18,784 [salt.loaded.ext.module.maas:1023][INFO    ][4843] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1308.59219408s left)
2019-10-26 05:18:47,491 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051847473927
2019-10-26 05:18:47,516 [salt.minion      :1432][INFO    ][6264] Starting a new job with PID 6264
2019-10-26 05:18:47,540 [salt.minion      :1711][INFO    ][6264] Returning information for job: 20191026051847473927
2019-10-26 05:18:51,848 [salt.state       :300 ][INFO    ][4843] {'ret': True}
2019-10-26 05:18:51,849 [salt.state       :1951][INFO    ][4843] Completed state [maas.wait_for_machine_status] at time 05:18:51.848902 duration_in_ms=224477.476
2019-10-26 05:18:51,853 [salt.minion      :1711][INFO    ][4843] Returning information for job: 20191026051502001898
2019-10-26 05:18:52,471 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026051852460846
2019-10-26 05:18:52,496 [salt.minion      :1432][INFO    ][6319] Starting a new job with PID 6319
2019-10-26 05:18:56,245 [salt.state       :915 ][INFO    ][6319] Loading fresh modules for state activity
2019-10-26 05:18:56,285 [salt.fileclient  :1219][INFO    ][6319] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-10-26 05:18:56,350 [salt.state       :1780][INFO    ][6319] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:56.350474
2019-10-26 05:18:56,350 [salt.state       :1813][INFO    ][6319] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:18:56,352 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6319] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:18:57,732 [salt.state       :300 ][INFO    ][6319] {'pid': 6339, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:18:57,733 [salt.state       :1951][INFO    ][6319] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:18:57.733382 duration_in_ms=1382.908
2019-10-26 05:18:57,734 [salt.state       :1780][INFO    ][6319] Running state [maas_machines_storage_cmp002_lvm] at time 05:18:57.734733
2019-10-26 05:18:57,734 [salt.state       :1813][INFO    ][6319] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-10-26 05:18:59,207 [salt.loaded.ext.module.maasng:610 ][INFO    ][6319] cnfykf
2019-10-26 05:18:59,207 [salt.loaded.ext.module.maasng:626 ][INFO    ][6319] sda
2019-10-26 05:19:00,027 [salt.loaded.ext.module.maasng:361 ][INFO    ][6319] cnfykf
2019-10-26 05:19:00,141 [salt.loaded.ext.module.maasng:367 ][INFO    ][6319] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'bbb12b41-99a3-4448-9bb2-83f05ad62501', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cnfykf', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'368b2471-f715-45c7-8e73-174b7a44698c', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/partition/4'}], u'filesystem': None, u'name': u'sda', u'system_id': u'cnfykf', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/'}, {u'size': 2397988454400, u'model': None, u'uuid': u'a9b502be-c652-4bdb-a4df-d00ad783dd82', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ed715640-9e69-4cf1-94e5-f06a0ac8f670', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'cnfykf', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/9/'}]
2019-10-26 05:19:00,142 [salt.loaded.ext.module.maasng:632 ][INFO    ][6319] vgroot
2019-10-26 05:19:00,142 [salt.loaded.ext.module.maasng:635 ][INFO    ][6319] lvroot
2019-10-26 05:19:00,143 [salt.loaded.ext.module.maasng:639 ][INFO    ][6319] 107374182400
2019-10-26 05:19:00,815 [salt.loaded.ext.module.maasng:645 ][INFO    ][6319] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 30, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'id': 4, u'system_id': u'cnfykf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/interfaces/4/'}, u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'58e085b6-9341-4c5f-ba25-f42f477da6a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cnfykf', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ba3cbddb-30a0-4b00-8bf6-47d0cef1339d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}], u'uuid': None, u'id': 4, u'system_id': u'cnfykf', 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'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/'}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'58e085b6-9341-4c5f-ba25-f42f477da6a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cnfykf', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ba3cbddb-30a0-4b00-8bf6-47d0cef1339d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cnfykf', 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'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/'}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'uuid': u'fb91480c-eb17-484e-81f8-7bdbe79f7685', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cnfykf', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'dfe04029-7bc6-4bbf-9aec-bd2b34190699'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/11/'}], 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/cnfykf/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'cnfykf', 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'physicalblockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'58e085b6-9341-4c5f-ba25-f42f477da6a9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cnfykf', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ba3cbddb-30a0-4b00-8bf6-47d0cef1339d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'device_id': 4}], u'uuid': None, u'id': 4, u'system_id': u'cnfykf', 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'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/4/'}], u'min_hwe_kernel': u'ga-18.04', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'commissioning_status': 2, u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cnfykf', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 30, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'id': 4, u'system_id': u'cnfykf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 31, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'effective_mtu': 1500, u'id': 18, u'system_id': u'cnfykf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/interfaces/18/'}, {u'name': u'enp8s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'effective_mtu': 1500, u'id': 19, u'system_id': u'cnfykf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/interfaces/19/'}, {u'name': u'enp7s0', u'links': [{u'id': 33, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'effective_mtu': 1500, u'id': 20, u'system_id': u'cnfykf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'uuid': u'fb91480c-eb17-484e-81f8-7bdbe79f7685', u'id': 11, u'system_id': u'cnfykf', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'dfe04029-7bc6-4bbf-9aec-bd2b34190699'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cnfykf/blockdevices/11/'}], u'ip_addresses': [u'192.168.11.42'], u'architecture': u'amd64/generic', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-10-26 05:19:00,817 [salt.state       :300 ][INFO    ][6319] {'new': {'storage_layout': 'lvm'}}
2019-10-26 05:19:00,818 [salt.state       :1951][INFO    ][6319] Completed state [maas_machines_storage_cmp002_lvm] at time 05:19:00.817926 duration_in_ms=3083.191
2019-10-26 05:19:00,818 [salt.state       :1780][INFO    ][6319] Running state [maas_machines_storage_cmp001_lvm] at time 05:19:00.818476
2019-10-26 05:19:00,818 [salt.state       :1813][INFO    ][6319] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-10-26 05:19:02,334 [salt.loaded.ext.module.maasng:610 ][INFO    ][6319] yst6bt
2019-10-26 05:19:02,335 [salt.loaded.ext.module.maasng:626 ][INFO    ][6319] sda
2019-10-26 05:19:03,059 [salt.loaded.ext.module.maasng:361 ][INFO    ][6319] yst6bt
2019-10-26 05:19:03,191 [salt.loaded.ext.module.maasng:367 ][INFO    ][6319] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yst6bt', 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'partitions': [{u'uuid': u'2c9b2f70-f920-4bda-abfa-3bd5701e1814', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/partition/3', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yst6bt', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'88dd6766-0b4f-4bfe-b32b-f36ce5471720'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 3, u'size': 2397992648704}], u'type': u'physical', u'id': 3, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/8/', u'used_size': 2397988454400, u'tags': [], u'uuid': u'573bef06-dc94-48eb-9f4b-8f1fac898c60', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'yst6bt', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'9f886d5d-9758-48df-9148-fd9241f1f6ff'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 8, u'size': 2397988454400}]
2019-10-26 05:19:03,191 [salt.loaded.ext.module.maasng:632 ][INFO    ][6319] vgroot
2019-10-26 05:19:03,192 [salt.loaded.ext.module.maasng:635 ][INFO    ][6319] lvroot
2019-10-26 05:19:03,192 [salt.loaded.ext.module.maasng:639 ][INFO    ][6319] 107374182400
2019-10-26 05:19:03,933 [salt.loaded.ext.module.maasng:645 ][INFO    ][6319] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'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'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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 25}], 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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'yst6bt', 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/yst6bt/interfaces/5/'}, u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'yst6bt', 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'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yst6bt', 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'partitions': [{u'uuid': u'bdf4ec12-4e8c-4bdb-aa92-aada025bcdc7', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yst6bt', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'68300202-744f-473f-9e89-f4245015275f'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 3, u'size': 2397998940160}], u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yst6bt', 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'partitions': [{u'uuid': u'bdf4ec12-4e8c-4bdb-aa92-aada025bcdc7', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yst6bt', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'68300202-744f-473f-9e89-f4245015275f'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 3, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'uuid': u'68077398-d127-432d-9070-bfd69250e6e3', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'yst6bt', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'4e29f76a-85d4-48a8-9016-175cce367310'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'size': 107374182400}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'owner_data': {}, u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'yst6bt', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'yst6bt', 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'partitions': [{u'uuid': u'bdf4ec12-4e8c-4bdb-aa92-aada025bcdc7', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/3/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yst6bt', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'68300202-744f-473f-9e89-f4245015275f'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'type': u'physical', u'id': 3, u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/blockdevices/12/', u'used_size': 107374182400, u'tags': [], u'uuid': u'68077398-d127-432d-9070-bfd69250e6e3', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'yst6bt', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'4e29f76a-85d4-48a8-9016-175cce367310'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 12, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 25}], 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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'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'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'yst6bt', 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/yst6bt/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 26}], 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'yst6bt', u'mac_address': u'00:25:b5:a0:00:5d', u'id': 15, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/interfaces/15/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 27}], 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'yst6bt', u'mac_address': u'00:25:b5:a0:00:5c', u'id': 16, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/interfaces/16/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 28}], 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'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'yst6bt', u'mac_address': u'00:25:b5:a0:00:5b', u'id': 17, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yst6bt/interfaces/17/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/yst6bt/'}
2019-10-26 05:19:03,935 [salt.state       :300 ][INFO    ][6319] {'new': {'storage_layout': 'lvm'}}
2019-10-26 05:19:03,936 [salt.state       :1951][INFO    ][6319] Completed state [maas_machines_storage_cmp001_lvm] at time 05:19:03.936241 duration_in_ms=3117.765
2019-10-26 05:19:03,940 [salt.minion      :1711][INFO    ][6319] Returning information for job: 20191026051852460846
2019-10-26 05:19:04,531 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026051904519324
2019-10-26 05:19:04,550 [salt.minion      :1432][INFO    ][6381] Starting a new job with PID 6381
2019-10-26 05:19:05,264 [salt.state       :915 ][INFO    ][6381] Loading fresh modules for state activity
2019-10-26 05:19:05,317 [salt.fileclient  :1219][INFO    ][6381] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-10-26 05:19:05,357 [salt.state       :1780][INFO    ][6381] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:05.357677
2019-10-26 05:19:05,358 [salt.state       :1813][INFO    ][6381] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:19:05,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6381] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:19:06,796 [salt.state       :300 ][INFO    ][6381] {'pid': 6407, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:19:06,797 [salt.state       :1951][INFO    ][6381] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:06.797012 duration_in_ms=1439.335
2019-10-26 05:19:06,799 [salt.state       :1780][INFO    ][6381] Running state [maas.deploy_machines] at time 05:19:06.799522
2019-10-26 05:19:06,800 [salt.state       :1813][INFO    ][6381] Executing state module.run for [maas.deploy_machines]
2019-10-26 05:19:06,801 [salt.utils.decorators:613 ][WARNING ][6381] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:19:07,484 [salt.loaded.ext.module.maas:684 ][INFO    ][6381] deploymachines hwe_kernel=ga-18.04 system_id=cnfykf distro_series=bionic
2019-10-26 05:19:10,168 [salt.loaded.ext.module.maas:684 ][INFO    ][6381] deploymachines hwe_kernel=ga-18.04 system_id=yst6bt distro_series=bionic
2019-10-26 05:19:12,289 [salt.loaded.ext.module.maas:684 ][INFO    ][6381] deploymachines hwe_kernel=ga-18.04 system_id=mp4k8p distro_series=bionic
2019-10-26 05:19:15,027 [salt.loaded.ext.module.maas:684 ][INFO    ][6381] deploymachines hwe_kernel=ga-18.04 system_id=pmk7xb distro_series=bionic
2019-10-26 05:19:17,531 [salt.loaded.ext.module.maas:684 ][INFO    ][6381] deploymachines hwe_kernel=ga-18.04 system_id=dxkad6 distro_series=bionic
2019-10-26 05:19:19,653 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051919640678
2019-10-26 05:19:19,678 [salt.minion      :1432][INFO    ][6683] Starting a new job with PID 6683
2019-10-26 05:19:19,698 [salt.minion      :1711][INFO    ][6683] Returning information for job: 20191026051919640678
2019-10-26 05:19:20,190 [salt.state       :300 ][INFO    ][6381] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-10-26 05:19:20,191 [salt.state       :1951][INFO    ][6381] Completed state [maas.deploy_machines] at time 05:19:20.190898 duration_in_ms=13391.374
2019-10-26 05:19:20,195 [salt.minion      :1711][INFO    ][6381] Returning information for job: 20191026051904519324
2019-10-26 05:19:20,836 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026051920826671
2019-10-26 05:19:20,858 [salt.minion      :1432][INFO    ][6698] Starting a new job with PID 6698
2019-10-26 05:19:24,554 [salt.state       :915 ][INFO    ][6698] Loading fresh modules for state activity
2019-10-26 05:19:24,595 [salt.fileclient  :1219][INFO    ][6698] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-10-26 05:19:24,629 [salt.state       :1780][INFO    ][6698] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:24.629437
2019-10-26 05:19:24,629 [salt.state       :1813][INFO    ][6698] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:19:24,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6698] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:19:25,830 [salt.state       :300 ][INFO    ][6698] {'pid': 6715, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:19:25,831 [salt.state       :1951][INFO    ][6698] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:19:25.830999 duration_in_ms=1201.56
2019-10-26 05:19:25,834 [salt.state       :1780][INFO    ][6698] Running state [maas.wait_for_machine_status] at time 05:19:25.834267
2019-10-26 05:19:25,834 [salt.state       :1813][INFO    ][6698] Executing state module.run for [maas.wait_for_machine_status]
2019-10-26 05:19:25,835 [salt.utils.decorators:613 ][WARNING ][6698] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:19:28,852 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.99240494s left)
2019-10-26 05:19:35,957 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026051935941230
2019-10-26 05:19:35,982 [salt.minion      :1432][INFO    ][6734] Starting a new job with PID 6734
2019-10-26 05:19:36,005 [salt.minion      :1711][INFO    ][6734] Returning information for job: 20191026051935941230
2019-10-26 05:20:02,586 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.25886893s left)
2019-10-26 05:20:06,016 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052006002237
2019-10-26 05:20:06,041 [salt.minion      :1432][INFO    ][6770] Starting a new job with PID 6770
2019-10-26 05:20:06,061 [salt.minion      :1711][INFO    ][6770] Returning information for job: 20191026052006002237
2019-10-26 05:20:35,695 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.14946485s left)
2019-10-26 05:20:36,108 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052036096031
2019-10-26 05:20:36,133 [salt.minion      :1432][INFO    ][6808] Starting a new job with PID 6808
2019-10-26 05:20:36,155 [salt.minion      :1711][INFO    ][6808] Returning information for job: 20191026052036096031
2019-10-26 05:21:06,155 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052106143353
2019-10-26 05:21:06,177 [salt.minion      :1432][INFO    ][6934] Starting a new job with PID 6934
2019-10-26 05:21:06,194 [salt.minion      :1711][INFO    ][6934] Returning information for job: 20191026052106143353
2019-10-26 05:21:08,417 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.428092s left)
2019-10-26 05:21:36,203 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052136191287
2019-10-26 05:21:36,226 [salt.minion      :1432][INFO    ][7250] Starting a new job with PID 7250
2019-10-26 05:21:36,246 [salt.minion      :1711][INFO    ][7250] Returning information for job: 20191026052136191287
2019-10-26 05:21:41,905 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.93985391s left)
2019-10-26 05:22:06,248 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052206234849
2019-10-26 05:22:06,269 [salt.minion      :1432][INFO    ][7465] Starting a new job with PID 7465
2019-10-26 05:22:06,287 [salt.minion      :1711][INFO    ][7465] Returning information for job: 20191026052206234849
2019-10-26 05:22:15,317 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.52787685s left)
2019-10-26 05:22:36,307 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052236293328
2019-10-26 05:22:36,331 [salt.minion      :1432][INFO    ][7960] Starting a new job with PID 7960
2019-10-26 05:22:36,351 [salt.minion      :1711][INFO    ][7960] Returning information for job: 20191026052236293328
2019-10-26 05:22:48,775 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.069803s left)
2019-10-26 05:23:06,361 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052306348736
2019-10-26 05:23:06,386 [salt.minion      :1432][INFO    ][8022] Starting a new job with PID 8022
2019-10-26 05:23:06,409 [salt.minion      :1711][INFO    ][8022] Returning information for job: 20191026052306348736
2019-10-26 05:23:22,224 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.62104297s left)
2019-10-26 05:23:36,430 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052336417109
2019-10-26 05:23:36,455 [salt.minion      :1432][INFO    ][8103] Starting a new job with PID 8103
2019-10-26 05:23:36,475 [salt.minion      :1711][INFO    ][8103] Returning information for job: 20191026052336417109
2019-10-26 05:23:55,684 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.16118193s left)
2019-10-26 05:24:06,499 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052406486024
2019-10-26 05:24:06,523 [salt.minion      :1432][INFO    ][8258] Starting a new job with PID 8258
2019-10-26 05:24:06,546 [salt.minion      :1711][INFO    ][8258] Returning information for job: 20191026052406486024
2019-10-26 05:24:28,954 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.89093995s left)
2019-10-26 05:24:36,574 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052436562088
2019-10-26 05:24:36,598 [salt.minion      :1432][INFO    ][8413] Starting a new job with PID 8413
2019-10-26 05:24:36,620 [salt.minion      :1711][INFO    ][8413] Returning information for job: 20191026052436562088
2019-10-26 05:25:02,715 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.12958193s left)
2019-10-26 05:25:06,651 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052506637939
2019-10-26 05:25:06,677 [salt.minion      :1432][INFO    ][8649] Starting a new job with PID 8649
2019-10-26 05:25:06,703 [salt.minion      :1711][INFO    ][8649] Returning information for job: 20191026052506637939
2019-10-26 05:25:35,923 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.92216802s left)
2019-10-26 05:25:36,747 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052536730343
2019-10-26 05:25:36,772 [salt.minion      :1432][INFO    ][8940] Starting a new job with PID 8940
2019-10-26 05:25:36,794 [salt.minion      :1711][INFO    ][8940] Returning information for job: 20191026052536730343
2019-10-26 05:26:06,826 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052606818638
2019-10-26 05:26:06,850 [salt.minion      :1432][INFO    ][8973] Starting a new job with PID 8973
2019-10-26 05:26:06,872 [salt.minion      :1711][INFO    ][8973] Returning information for job: 20191026052606818638
2019-10-26 05:26:09,390 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.45507383s left)
2019-10-26 05:26:36,927 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052636911284
2019-10-26 05:26:36,952 [salt.minion      :1432][INFO    ][9124] Starting a new job with PID 9124
2019-10-26 05:26:36,974 [salt.minion      :1711][INFO    ][9124] Returning information for job: 20191026052636911284
2019-10-26 05:26:43,091 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['cmp002', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.75396085s left)
2019-10-26 05:27:06,981 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052706968301
2019-10-26 05:27:07,005 [salt.minion      :1432][INFO    ][9375] Starting a new job with PID 9375
2019-10-26 05:27:07,027 [salt.minion      :1711][INFO    ][9375] Returning information for job: 20191026052706968301
2019-10-26 05:27:16,018 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1779.82696295s left)
2019-10-26 05:27:37,089 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052737076288
2019-10-26 05:27:37,112 [salt.minion      :1432][INFO    ][9598] Starting a new job with PID 9598
2019-10-26 05:27:37,133 [salt.minion      :1711][INFO    ][9598] Returning information for job: 20191026052737076288
2019-10-26 05:27:49,614 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1746.23115087s left)
2019-10-26 05:28:07,203 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052807189890
2019-10-26 05:28:07,227 [salt.minion      :1432][INFO    ][9776] Starting a new job with PID 9776
2019-10-26 05:28:07,247 [salt.minion      :1711][INFO    ][9776] Returning information for job: 20191026052807189890
2019-10-26 05:28:23,194 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1712.65117097s left)
2019-10-26 05:28:37,320 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052837306740
2019-10-26 05:28:37,345 [salt.minion      :1432][INFO    ][9849] Starting a new job with PID 9849
2019-10-26 05:28:37,367 [salt.minion      :1711][INFO    ][9849] Returning information for job: 20191026052837306740
2019-10-26 05:28:56,735 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1679.10983801s left)
2019-10-26 05:29:07,444 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052907432363
2019-10-26 05:29:07,465 [salt.minion      :1432][INFO    ][9886] Starting a new job with PID 9886
2019-10-26 05:29:07,485 [salt.minion      :1711][INFO    ][9886] Returning information for job: 20191026052907432363
2019-10-26 05:29:30,156 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1645.68850803s left)
2019-10-26 05:29:37,572 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026052937559784
2019-10-26 05:29:37,597 [salt.minion      :1432][INFO    ][9927] Starting a new job with PID 9927
2019-10-26 05:29:37,618 [salt.minion      :1711][INFO    ][9927] Returning information for job: 20191026052937559784
2019-10-26 05:30:03,694 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1612.15032387s left)
2019-10-26 05:30:07,716 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053007702873
2019-10-26 05:30:07,741 [salt.minion      :1432][INFO    ][9964] Starting a new job with PID 9964
2019-10-26 05:30:07,764 [salt.minion      :1711][INFO    ][9964] Returning information for job: 20191026053007702873
2019-10-26 05:30:37,252 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.59315491s left)
2019-10-26 05:30:37,871 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053037858439
2019-10-26 05:30:37,896 [salt.minion      :1432][INFO    ][10009] Starting a new job with PID 10009
2019-10-26 05:30:37,917 [salt.minion      :1711][INFO    ][10009] Returning information for job: 20191026053037858439
2019-10-26 05:31:08,035 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053108019307
2019-10-26 05:31:08,058 [salt.minion      :1432][INFO    ][10046] Starting a new job with PID 10046
2019-10-26 05:31:08,079 [salt.minion      :1711][INFO    ][10046] Returning information for job: 20191026053108019307
2019-10-26 05:31:10,785 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1545.05961394s left)
2019-10-26 05:31:38,203 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053138191426
2019-10-26 05:31:38,227 [salt.minion      :1432][INFO    ][10087] Starting a new job with PID 10087
2019-10-26 05:31:38,251 [salt.minion      :1711][INFO    ][10087] Returning information for job: 20191026053138191426
2019-10-26 05:31:44,463 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1511.38223696s left)
2019-10-26 05:32:08,390 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053208377455
2019-10-26 05:32:08,414 [salt.minion      :1432][INFO    ][10223] Starting a new job with PID 10223
2019-10-26 05:32:08,436 [salt.minion      :1711][INFO    ][10223] Returning information for job: 20191026053208377455
2019-10-26 05:32:17,671 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1478.17384005s left)
2019-10-26 05:32:38,582 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053238569424
2019-10-26 05:32:38,606 [salt.minion      :1432][INFO    ][10271] Starting a new job with PID 10271
2019-10-26 05:32:38,629 [salt.minion      :1711][INFO    ][10271] Returning information for job: 20191026053238569424
2019-10-26 05:32:51,211 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1444.63375998s left)
2019-10-26 05:33:08,788 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053308775330
2019-10-26 05:33:08,813 [salt.minion      :1432][INFO    ][10310] Starting a new job with PID 10310
2019-10-26 05:33:08,833 [salt.minion      :1711][INFO    ][10310] Returning information for job: 20191026053308775330
2019-10-26 05:33:24,332 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1411.51291585s left)
2019-10-26 05:33:39,001 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053338987916
2019-10-26 05:33:39,026 [salt.minion      :1432][INFO    ][10350] Starting a new job with PID 10350
2019-10-26 05:33:39,049 [salt.minion      :1711][INFO    ][10350] Returning information for job: 20191026053338987916
2019-10-26 05:33:57,869 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1377.97562504s left)
2019-10-26 05:34:09,226 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053409213769
2019-10-26 05:34:09,251 [salt.minion      :1432][INFO    ][10389] Starting a new job with PID 10389
2019-10-26 05:34:09,271 [salt.minion      :1711][INFO    ][10389] Returning information for job: 20191026053409213769
2019-10-26 05:34:31,321 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1344.523983s left)
2019-10-26 05:34:39,244 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053439231424
2019-10-26 05:34:39,270 [salt.minion      :1432][INFO    ][10427] Starting a new job with PID 10427
2019-10-26 05:34:39,293 [salt.minion      :1711][INFO    ][10427] Returning information for job: 20191026053439231424
2019-10-26 05:35:04,968 [salt.loaded.ext.module.maas:1023][INFO    ][6698] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1310.87722087s left)
2019-10-26 05:35:09,280 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053509267738
2019-10-26 05:35:09,304 [salt.minion      :1432][INFO    ][10466] Starting a new job with PID 10466
2019-10-26 05:35:09,324 [salt.minion      :1711][INFO    ][10466] Returning information for job: 20191026053509267738
2019-10-26 05:35:37,302 [salt.loaded.ext.module.maas:993 ][INFO    ][6698] Machine pmk7xb mark broken
2019-10-26 05:35:37,942 [salt.loaded.ext.module.maas:996 ][INFO    ][6698] Machine pmk7xb mark fixed
2019-10-26 05:35:39,143 [salt.loaded.ext.module.maas:684 ][INFO    ][6698] deploymachines hwe_kernel=ga-18.04 system_id=pmk7xb distro_series=bionic
2019-10-26 05:35:39,324 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053539310848
2019-10-26 05:35:39,348 [salt.minion      :1432][INFO    ][10524] Starting a new job with PID 10524
2019-10-26 05:35:39,371 [salt.minion      :1711][INFO    ][10524] Returning information for job: 20191026053539310848
2019-10-26 05:35:41,620 [salt.loaded.ext.module.maas:160 ][ERROR   ][6698] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-10-26 05:35:41,622 [salt.state       :302 ][ERROR   ][6698] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-10-26 05:35:41,622 [salt.state       :1951][INFO    ][6698] Completed state [maas.wait_for_machine_status] at time 05:35:41.622741 duration_in_ms=975788.469
2019-10-26 05:35:41,629 [salt.minion      :1711][INFO    ][6698] Returning information for job: 20191026051920826671
2019-10-26 05:35:52,428 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command pillar.get with jid 20191026053552415302
2019-10-26 05:35:52,453 [salt.minion      :1432][INFO    ][10588] Starting a new job with PID 10588
2019-10-26 05:35:52,462 [salt.minion      :1711][INFO    ][10588] Returning information for job: 20191026053552415302
2019-10-26 05:35:52,971 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command service.status with jid 20191026053552958231
2019-10-26 05:35:52,994 [salt.minion      :1432][INFO    ][10593] Starting a new job with PID 10593
2019-10-26 05:35:53,431 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10593] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-10-26 05:35:53,463 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][10593] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-10-26 05:35:53,478 [salt.minion      :1711][INFO    ][10593] Returning information for job: 20191026053552958231
2019-10-26 05:35:54,027 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026053554014402
2019-10-26 05:35:54,051 [salt.minion      :1432][INFO    ][10604] Starting a new job with PID 10604
2019-10-26 05:35:57,826 [salt.state       :915 ][INFO    ][10604] Loading fresh modules for state activity
2019-10-26 05:35:58,245 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'salt-minion --version' in directory '/root'
2019-10-26 05:35:58,603 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'salt-minion --version' in directory '/root'
2019-10-26 05:35:59,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'salt-minion --version' in directory '/root'
2019-10-26 05:35:59,824 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'salt-minion --version' in directory '/root'
2019-10-26 05:36:01,174 [salt.state       :1780][INFO    ][10604] Running state [salt-minion] at time 05:36:01.174655
2019-10-26 05:36:01,175 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [salt-minion]
2019-10-26 05:36:01,175 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-10-26 05:36:01,256 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,256 [salt.state       :1951][INFO    ][10604] Completed state [salt-minion] at time 05:36:01.256312 duration_in_ms=81.658
2019-10-26 05:36:01,256 [salt.state       :1780][INFO    ][10604] Running state [salt_minion_dependency_packages] at time 05:36:01.256607
2019-10-26 05:36:01,256 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-10-26 05:36:01,262 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,262 [salt.state       :1951][INFO    ][10604] Completed state [salt_minion_dependency_packages] at time 05:36:01.262340 duration_in_ms=5.733
2019-10-26 05:36:01,265 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/minion.d/minion.conf] at time 05:36:01.265001
2019-10-26 05:36:01,265 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-10-26 05:36:01,457 [salt.state       :300 ][INFO    ][10604] File /etc/salt/minion.d/minion.conf is in the correct state
2019-10-26 05:36:01,457 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/minion.d/minion.conf] at time 05:36:01.457867 duration_in_ms=192.865
2019-10-26 05:36:01,458 [salt.state       :1780][INFO    ][10604] Running state [python-netaddr] at time 05:36:01.458065
2019-10-26 05:36:01,458 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [python-netaddr]
2019-10-26 05:36:01,463 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,463 [salt.state       :1951][INFO    ][10604] Completed state [python-netaddr] at time 05:36:01.463316 duration_in_ms=5.251
2019-10-26 05:36:01,465 [salt.state       :1780][INFO    ][10604] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:36:01.465628
2019-10-26 05:36:01,465 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-10-26 05:36:01,476 [salt.state       :300 ][INFO    ][10604] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-10-26 05:36:01,476 [salt.state       :1951][INFO    ][10604] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:36:01.476368 duration_in_ms=10.74
2019-10-26 05:36:01,477 [salt.state       :1780][INFO    ][10604] Running state [salt-minion] at time 05:36:01.477117
2019-10-26 05:36:01,477 [salt.state       :1813][INFO    ][10604] Executing state service.running for [salt-minion]
2019-10-26 05:36:01,477 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:01,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-10-26 05:36:01,529 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-10-26 05:36:01,545 [salt.state       :300 ][INFO    ][10604] The service salt-minion is already running
2019-10-26 05:36:01,546 [salt.state       :1951][INFO    ][10604] Completed state [salt-minion] at time 05:36:01.546139 duration_in_ms=69.021
2019-10-26 05:36:01,547 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains.d] at time 05:36:01.547376
2019-10-26 05:36:01,547 [salt.state       :1813][INFO    ][10604] Executing state file.directory for [/etc/salt/grains.d]
2019-10-26 05:36:01,548 [salt.state       :300 ][INFO    ][10604] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-10-26 05:36:01,548 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains.d] at time 05:36:01.548690 duration_in_ms=1.314
2019-10-26 05:36:01,549 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains] at time 05:36:01.549233
2019-10-26 05:36:01,549 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/grains]
2019-10-26 05:36:01,549 [salt.state       :300 ][INFO    ][10604] File /etc/salt/grains exists with proper permissions. No changes made.
2019-10-26 05:36:01,550 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains] at time 05:36:01.550140 duration_in_ms=0.907
2019-10-26 05:36:01,550 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains.d/placeholder] at time 05:36:01.550527
2019-10-26 05:36:01,550 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-10-26 05:36:01,551 [salt.state       :300 ][INFO    ][10604] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-10-26 05:36:01,551 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains.d/placeholder] at time 05:36:01.551389 duration_in_ms=0.862
2019-10-26 05:36:01,551 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains.d/sphinx] at time 05:36:01.551781
2019-10-26 05:36:01,552 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-10-26 05:36:01,565 [salt.state       :300 ][INFO    ][10604] File /etc/salt/grains.d/sphinx is in the correct state
2019-10-26 05:36:01,565 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains.d/sphinx] at time 05:36:01.565435 duration_in_ms=13.653
2019-10-26 05:36:01,567 [salt.state       :1780][INFO    ][10604] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.567271
2019-10-26 05:36:01,567 [salt.state       :1813][INFO    ][10604] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-10-26 05:36:01,567 [salt.state       :300 ][INFO    ][10604] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-10-26 05:36:01,568 [salt.state       :1951][INFO    ][10604] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.568010 duration_in_ms=0.739
2019-10-26 05:36:01,568 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains.d/dns_records] at time 05:36:01.568391
2019-10-26 05:36:01,568 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-10-26 05:36:01,583 [salt.state       :300 ][INFO    ][10604] File /etc/salt/grains.d/dns_records is in the correct state
2019-10-26 05:36:01,583 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains.d/dns_records] at time 05:36:01.583412 duration_in_ms=15.022
2019-10-26 05:36:01,584 [salt.state       :1780][INFO    ][10604] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.584178
2019-10-26 05:36:01,584 [salt.state       :1813][INFO    ][10604] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-10-26 05:36:01,584 [salt.state       :300 ][INFO    ][10604] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-10-26 05:36:01,584 [salt.state       :1951][INFO    ][10604] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.584925 duration_in_ms=0.747
2019-10-26 05:36:01,585 [salt.state       :1780][INFO    ][10604] Running state [/etc/salt/grains.d/salt] at time 05:36:01.585322
2019-10-26 05:36:01,585 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-10-26 05:36:01,601 [salt.state       :300 ][INFO    ][10604] File /etc/salt/grains.d/salt is in the correct state
2019-10-26 05:36:01,601 [salt.state       :1951][INFO    ][10604] Completed state [/etc/salt/grains.d/salt] at time 05:36:01.601412 duration_in_ms=16.09
2019-10-26 05:36:01,602 [salt.state       :1780][INFO    ][10604] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.602166
2019-10-26 05:36:01,602 [salt.state       :1813][INFO    ][10604] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-10-26 05:36:01,602 [salt.state       :300 ][INFO    ][10604] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-10-26 05:36:01,602 [salt.state       :1951][INFO    ][10604] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:36:01.602939 duration_in_ms=0.773
2019-10-26 05:36:01,604 [salt.state       :1780][INFO    ][10604] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:36:01.604470
2019-10-26 05:36:01,604 [salt.state       :1813][INFO    ][10604] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-10-26 05:36:01,605 [salt.state       :300 ][INFO    ][10604] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-10-26 05:36:01,605 [salt.state       :1951][INFO    ][10604] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:36:01.605234 duration_in_ms=0.764
2019-10-26 05:36:01,605 [salt.state       :1780][INFO    ][10604] Running state [mine.update] at time 05:36:01.605809
2019-10-26 05:36:01,606 [salt.state       :1813][INFO    ][10604] Executing state module.wait for [mine.update]
2019-10-26 05:36:01,606 [salt.state       :300 ][INFO    ][10604] No changes made for mine.update
2019-10-26 05:36:01,606 [salt.state       :1951][INFO    ][10604] Completed state [mine.update] at time 05:36:01.606534 duration_in_ms=0.725
2019-10-26 05:36:01,606 [salt.state       :1780][INFO    ][10604] Running state [ca-certificates] at time 05:36:01.606758
2019-10-26 05:36:01,607 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [ca-certificates]
2019-10-26 05:36:01,613 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,613 [salt.state       :1951][INFO    ][10604] Completed state [ca-certificates] at time 05:36:01.613176 duration_in_ms=6.418
2019-10-26 05:36:01,613 [salt.state       :1780][INFO    ][10604] Running state [update-ca-certificates] at time 05:36:01.613756
2019-10-26 05:36:01,614 [salt.state       :1813][INFO    ][10604] Executing state cmd.wait for [update-ca-certificates]
2019-10-26 05:36:01,614 [salt.state       :300 ][INFO    ][10604] No changes made for update-ca-certificates
2019-10-26 05:36:01,614 [salt.state       :1951][INFO    ][10604] Completed state [update-ca-certificates] at time 05:36:01.614497 duration_in_ms=0.741
2019-10-26 05:36:01,614 [salt.state       :1780][INFO    ][10604] Running state [iptables] at time 05:36:01.614717
2019-10-26 05:36:01,614 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [iptables]
2019-10-26 05:36:01,620 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,620 [salt.state       :1951][INFO    ][10604] Completed state [iptables] at time 05:36:01.620471 duration_in_ms=5.754
2019-10-26 05:36:01,620 [salt.state       :1780][INFO    ][10604] Running state [iptables-persistent] at time 05:36:01.620708
2019-10-26 05:36:01,620 [salt.state       :1813][INFO    ][10604] Executing state pkg.installed for [iptables-persistent]
2019-10-26 05:36:01,626 [salt.state       :300 ][INFO    ][10604] All specified packages are already installed
2019-10-26 05:36:01,626 [salt.state       :1951][INFO    ][10604] Completed state [iptables-persistent] at time 05:36:01.626382 duration_in_ms=5.674
2019-10-26 05:36:01,627 [salt.state       :1780][INFO    ][10604] Running state [iptables_modules_v4_load] at time 05:36:01.627207
2019-10-26 05:36:01,627 [salt.state       :1813][INFO    ][10604] Executing state kmod.present for [iptables_modules_v4_load]
2019-10-26 05:36:01,627 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'lsmod' in directory '/root'
2019-10-26 05:36:01,650 [salt.state       :300 ][INFO    ][10604] Kernel modules iptable_filter, ip_tables are already present
2019-10-26 05:36:01,650 [salt.state       :1951][INFO    ][10604] Completed state [iptables_modules_v4_load] at time 05:36:01.650514 duration_in_ms=23.307
2019-10-26 05:36:01,651 [salt.state       :1780][INFO    ][10604] Running state [/etc/iptables/rules.v4] at time 05:36:01.651040
2019-10-26 05:36:01,651 [salt.state       :1813][INFO    ][10604] Executing state file.managed for [/etc/iptables/rules.v4]
2019-10-26 05:36:01,727 [salt.state       :300 ][INFO    ][10604] File /etc/iptables/rules.v4 is in the correct state
2019-10-26 05:36:01,727 [salt.state       :1951][INFO    ][10604] Completed state [/etc/iptables/rules.v4] at time 05:36:01.727455 duration_in_ms=76.415
2019-10-26 05:36:01,728 [salt.state       :1780][INFO    ][10604] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:36:01.728212
2019-10-26 05:36:01,728 [salt.state       :1813][INFO    ][10604] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-10-26 05:36:01,728 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-10-26 05:36:01,746 [salt.state       :300 ][INFO    ][10604] onlyif execution failed
2019-10-26 05:36:01,746 [salt.state       :1951][INFO    ][10604] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:36:01.746468 duration_in_ms=18.256
2019-10-26 05:36:01,747 [salt.state       :1780][INFO    ][10604] Running state [netfilter-persistent] at time 05:36:01.747222
2019-10-26 05:36:01,747 [salt.state       :1813][INFO    ][10604] Executing state service.running for [netfilter-persistent]
2019-10-26 05:36:01,748 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:01,766 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-10-26 05:36:01,783 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-10-26 05:36:01,801 [salt.state       :300 ][INFO    ][10604] The service netfilter-persistent is already running
2019-10-26 05:36:01,802 [salt.state       :1951][INFO    ][10604] Completed state [netfilter-persistent] at time 05:36:01.802287 duration_in_ms=55.065
2019-10-26 05:36:01,803 [salt.state       :1780][INFO    ][10604] Running state [iptables_extra.remove_stale_tables] at time 05:36:01.803294
2019-10-26 05:36:01,803 [salt.state       :1813][INFO    ][10604] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-10-26 05:36:01,804 [salt.state       :300 ][INFO    ][10604] No changes made for iptables_extra.remove_stale_tables
2019-10-26 05:36:01,804 [salt.state       :1951][INFO    ][10604] Completed state [iptables_extra.remove_stale_tables] at time 05:36:01.804375 duration_in_ms=1.08
2019-10-26 05:36:01,804 [salt.state       :1780][INFO    ][10604] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:36:01.804697
2019-10-26 05:36:01,805 [salt.state       :1813][INFO    ][10604] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-10-26 05:36:01,805 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10604] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-10-26 05:36:01,822 [salt.state       :300 ][INFO    ][10604] onlyif execution failed
2019-10-26 05:36:01,823 [salt.state       :1951][INFO    ][10604] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:36:01.823264 duration_in_ms=18.567
2019-10-26 05:36:01,824 [salt.state       :1780][INFO    ][10604] Running state [/etc/iptables/rules.v6] at time 05:36:01.824396
2019-10-26 05:36:01,824 [salt.state       :1813][INFO    ][10604] Executing state file.absent for [/etc/iptables/rules.v6]
2019-10-26 05:36:01,825 [salt.state       :300 ][INFO    ][10604] File /etc/iptables/rules.v6 is not present
2019-10-26 05:36:01,825 [salt.state       :1951][INFO    ][10604] Completed state [/etc/iptables/rules.v6] at time 05:36:01.825602 duration_in_ms=1.206
2019-10-26 05:36:01,826 [salt.state       :1780][INFO    ][10604] Running state [iptables_extra.flush_all] at time 05:36:01.826394
2019-10-26 05:36:01,826 [salt.state       :1813][INFO    ][10604] Executing state module.wait for [iptables_extra.flush_all]
2019-10-26 05:36:01,827 [salt.state       :300 ][INFO    ][10604] No changes made for iptables_extra.flush_all
2019-10-26 05:36:01,827 [salt.state       :1951][INFO    ][10604] Completed state [iptables_extra.flush_all] at time 05:36:01.827343 duration_in_ms=0.949
2019-10-26 05:36:01,830 [salt.minion      :1711][INFO    ][10604] Returning information for job: 20191026053554014402
2019-10-26 05:36:02,455 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026053602445866
2019-10-26 05:36:02,480 [salt.minion      :1432][INFO    ][10692] Starting a new job with PID 10692
2019-10-26 05:36:03,251 [salt.state       :915 ][INFO    ][10692] Loading fresh modules for state activity
2019-10-26 05:36:03,941 [salt.state       :1780][INFO    ][10692] Running state [maas-rack-controller] at time 05:36:03.941348
2019-10-26 05:36:03,941 [salt.state       :1813][INFO    ][10692] Executing state pkg.installed for [maas-rack-controller]
2019-10-26 05:36:03,942 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10692] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-10-26 05:36:04,036 [salt.state       :300 ][INFO    ][10692] All specified packages are already installed
2019-10-26 05:36:04,036 [salt.state       :1951][INFO    ][10692] Completed state [maas-rack-controller] at time 05:36:04.036765 duration_in_ms=95.416
2019-10-26 05:36:04,037 [salt.state       :1780][INFO    ][10692] Running state [ipmitool] at time 05:36:04.037157
2019-10-26 05:36:04,037 [salt.state       :1813][INFO    ][10692] Executing state pkg.installed for [ipmitool]
2019-10-26 05:36:04,045 [salt.state       :300 ][INFO    ][10692] All specified packages are already installed
2019-10-26 05:36:04,045 [salt.state       :1951][INFO    ][10692] Completed state [ipmitool] at time 05:36:04.045540 duration_in_ms=8.383
2019-10-26 05:36:04,049 [salt.state       :1780][INFO    ][10692] Running state [/etc/maas/rackd.conf] at time 05:36:04.049160
2019-10-26 05:36:04,049 [salt.state       :1813][INFO    ][10692] Executing state file.line for [/etc/maas/rackd.conf]
2019-10-26 05:36:04,050 [salt.state       :300 ][INFO    ][10692] No changes needed to be made
2019-10-26 05:36:04,050 [salt.state       :1951][INFO    ][10692] Completed state [/etc/maas/rackd.conf] at time 05:36:04.050751 duration_in_ms=1.591
2019-10-26 05:36:04,051 [salt.state       :1780][INFO    ][10692] Running state [/etc/maas/rackd.conf] at time 05:36:04.051015
2019-10-26 05:36:04,051 [salt.state       :1813][INFO    ][10692] Executing state file.managed for [/etc/maas/rackd.conf]
2019-10-26 05:36:04,051 [salt.loaded.int.states.file:2298][WARNING ][10692] 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-10-26 05:36:04,052 [salt.state       :300 ][INFO    ][10692] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-10-26 05:36:04,052 [salt.state       :1951][INFO    ][10692] Completed state [/etc/maas/rackd.conf] at time 05:36:04.052510 duration_in_ms=1.495
2019-10-26 05:36:04,053 [salt.state       :1780][INFO    ][10692] Running state [maas-rackd] at time 05:36:04.053603
2019-10-26 05:36:04,053 [salt.state       :1813][INFO    ][10692] Executing state service.running for [maas-rackd]
2019-10-26 05:36:04,054 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10692] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:04,092 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10692] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-10-26 05:36:04,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10692] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-10-26 05:36:04,131 [salt.state       :300 ][INFO    ][10692] The service maas-rackd is already running
2019-10-26 05:36:04,131 [salt.state       :1951][INFO    ][10692] Completed state [maas-rackd] at time 05:36:04.131877 duration_in_ms=78.273
2019-10-26 05:36:04,133 [salt.minion      :1711][INFO    ][10692] Returning information for job: 20191026053602445866
2019-10-26 05:36:04,697 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026053604684398
2019-10-26 05:36:04,720 [salt.minion      :1432][INFO    ][10726] Starting a new job with PID 10726
2019-10-26 05:36:05,524 [salt.state       :915 ][INFO    ][10726] Loading fresh modules for state activity
2019-10-26 05:36:06,229 [salt.state       :1780][INFO    ][10726] Running state [maas-region-controller] at time 05:36:06.229773
2019-10-26 05:36:06,230 [salt.state       :1813][INFO    ][10726] Executing state pkg.installed for [maas-region-controller]
2019-10-26 05:36:06,230 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-10-26 05:36:06,325 [salt.state       :300 ][INFO    ][10726] All specified packages are already installed
2019-10-26 05:36:06,326 [salt.state       :1951][INFO    ][10726] Completed state [maas-region-controller] at time 05:36:06.326188 duration_in_ms=96.414
2019-10-26 05:36:06,326 [salt.state       :1780][INFO    ][10726] Running state [python-oauth] at time 05:36:06.326581
2019-10-26 05:36:06,326 [salt.state       :1813][INFO    ][10726] Executing state pkg.installed for [python-oauth]
2019-10-26 05:36:06,334 [salt.state       :300 ][INFO    ][10726] All specified packages are already installed
2019-10-26 05:36:06,335 [salt.state       :1951][INFO    ][10726] Completed state [python-oauth] at time 05:36:06.335065 duration_in_ms=8.484
2019-10-26 05:36:06,338 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/regiond.conf] at time 05:36:06.338741
2019-10-26 05:36:06,339 [salt.state       :1813][INFO    ][10726] Executing state file.replace for [/etc/maas/regiond.conf]
2019-10-26 05:36:06,392 [salt.state       :300 ][INFO    ][10726] No changes needed to be made
2019-10-26 05:36:06,393 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/regiond.conf] at time 05:36:06.393232 duration_in_ms=54.491
2019-10-26 05:36:06,393 [salt.state       :1780][INFO    ][10726] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:36:06.393850
2019-10-26 05:36:06,394 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-10-26 05:36:06,463 [salt.state       :300 ][INFO    ][10726] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-10-26 05:36:06,464 [salt.state       :1951][INFO    ][10726] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:36:06.464201 duration_in_ms=70.35
2019-10-26 05:36:06,464 [salt.state       :1780][INFO    ][10726] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:06.464754
2019-10-26 05:36:06,465 [salt.state       :1813][INFO    ][10726] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-10-26 05:36:06,477 [salt.state       :300 ][INFO    ][10726] No changes needed to be made
2019-10-26 05:36:06,477 [salt.state       :1951][INFO    ][10726] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:06.477693 duration_in_ms=12.938
2019-10-26 05:36:06,478 [salt.state       :1780][INFO    ][10726] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:06.478228
2019-10-26 05:36:06,478 [salt.state       :1813][INFO    ][10726] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-10-26 05:36:06,501 [salt.state       :300 ][INFO    ][10726] No changes needed to be made
2019-10-26 05:36:06,501 [salt.state       :1951][INFO    ][10726] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:36:06.501682 duration_in_ms=23.455
2019-10-26 05:36:06,502 [salt.state       :1780][INFO    ][10726] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:36:06.502210
2019-10-26 05:36:06,502 [salt.state       :1813][INFO    ][10726] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-10-26 05:36:06,531 [salt.state       :300 ][INFO    ][10726] No changes needed to be made
2019-10-26 05:36:06,532 [salt.state       :1951][INFO    ][10726] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:36:06.531958 duration_in_ms=29.74
2019-10-26 05:36:06,532 [salt.state       :1780][INFO    ][10726] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:36:06.532843
2019-10-26 05:36:06,533 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-10-26 05:36:06,547 [salt.state       :300 ][INFO    ][10726] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-10-26 05:36:06,547 [salt.state       :1951][INFO    ][10726] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:36:06.547675 duration_in_ms=14.832
2019-10-26 05:36:06,550 [salt.state       :1780][INFO    ][10726] Running state [a2enmod headers] at time 05:36:06.550412
2019-10-26 05:36:06,550 [salt.state       :1813][INFO    ][10726] Executing state cmd.run for [a2enmod headers]
2019-10-26 05:36:06,551 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command 'a2enmod headers' in directory '/root'
2019-10-26 05:36:06,626 [salt.state       :300 ][INFO    ][10726] {'pid': 10745, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-10-26 05:36:06,627 [salt.state       :1951][INFO    ][10726] Completed state [a2enmod headers] at time 05:36:06.627459 duration_in_ms=77.046
2019-10-26 05:36:06,628 [salt.state       :1780][INFO    ][10726] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:36:06.628081
2019-10-26 05:36:06,628 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-10-26 05:36:06,648 [salt.state       :300 ][INFO    ][10726] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-10-26 05:36:06,648 [salt.state       :1951][INFO    ][10726] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:36:06.648782 duration_in_ms=20.701
2019-10-26 05:36:06,649 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:36:06.649707
2019-10-26 05:36:06,650 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-10-26 05:36:06,733 [salt.state       :300 ][INFO    ][10726] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-10-26 05:36:06,734 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:36:06.734223 duration_in_ms=84.516
2019-10-26 05:36:06,734 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:36:06.734900
2019-10-26 05:36:06,735 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-10-26 05:36:06,799 [salt.state       :300 ][INFO    ][10726] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-10-26 05:36:06,799 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:36:06.799920 duration_in_ms=65.021
2019-10-26 05:36:06,800 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:36:06.800501
2019-10-26 05:36:06,800 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-10-26 05:36:06,865 [salt.state       :300 ][INFO    ][10726] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-10-26 05:36:06,865 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:36:06.865729 duration_in_ms=65.228
2019-10-26 05:36:06,866 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:36:06.866278
2019-10-26 05:36:06,866 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-10-26 05:36:06,925 [salt.state       :300 ][INFO    ][10726] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-10-26 05:36:06,925 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 05:36:06.925618 duration_in_ms=59.34
2019-10-26 05:36:06,926 [salt.state       :1780][INFO    ][10726] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:36:06.926116
2019-10-26 05:36:06,926 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-10-26 05:36:06,979 [salt.state       :300 ][INFO    ][10726] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-10-26 05:36:06,979 [salt.state       :1951][INFO    ][10726] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 05:36:06.979423 duration_in_ms=53.308
2019-10-26 05:36:06,979 [salt.state       :1780][INFO    ][10726] Running state [/root/.pgpass] at time 05:36:06.979721
2019-10-26 05:36:06,980 [salt.state       :1813][INFO    ][10726] Executing state file.managed for [/root/.pgpass]
2019-10-26 05:36:07,027 [salt.state       :300 ][INFO    ][10726] File /root/.pgpass is in the correct state
2019-10-26 05:36:07,027 [salt.state       :1951][INFO    ][10726] Completed state [/root/.pgpass] at time 05:36:07.027294 duration_in_ms=47.573
2019-10-26 05:36:07,033 [salt.state       :1780][INFO    ][10726] Running state [maas-region syncdb --noinput] at time 05:36:07.032970
2019-10-26 05:36:07,033 [salt.state       :1813][INFO    ][10726] Executing state cmd.run for [maas-region syncdb --noinput]
2019-10-26 05:36:07,034 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-10-26 05:36:09,011 [salt.state       :300 ][INFO    ][10726] {'pid': 10762, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sites, piston3, contenttypes, metadataserver, maasserver, auth, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-10-26 05:36:09,012 [salt.state       :1951][INFO    ][10726] Completed state [maas-region syncdb --noinput] at time 05:36:09.012246 duration_in_ms=1979.276
2019-10-26 05:36:09,012 [salt.state       :2022][WARNING ][10726] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-10-26 05:36:09,013 [salt.state       :1780][INFO    ][10726] Running state [maas-regiond] at time 05:36:09.013472
2019-10-26 05:36:09,013 [salt.state       :1813][INFO    ][10726] Executing state service.running for [maas-regiond]
2019-10-26 05:36:09,014 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:09,047 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-10-26 05:36:09,063 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-10-26 05:36:09,078 [salt.state       :300 ][INFO    ][10726] The service maas-regiond is already running
2019-10-26 05:36:09,078 [salt.state       :1951][INFO    ][10726] Completed state [maas-regiond] at time 05:36:09.078802 duration_in_ms=65.33
2019-10-26 05:36:09,079 [salt.state       :1780][INFO    ][10726] Running state [bind9] at time 05:36:09.079834
2019-10-26 05:36:09,080 [salt.state       :1813][INFO    ][10726] Executing state service.running for [bind9]
2019-10-26 05:36:09,080 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:09,096 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-10-26 05:36:09,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-10-26 05:36:09,127 [salt.state       :300 ][INFO    ][10726] The service bind9 is already running
2019-10-26 05:36:09,127 [salt.state       :1951][INFO    ][10726] Completed state [bind9] at time 05:36:09.127270 duration_in_ms=47.436
2019-10-26 05:36:09,128 [salt.state       :1780][INFO    ][10726] Running state [apache2] at time 05:36:09.128296
2019-10-26 05:36:09,128 [salt.state       :1813][INFO    ][10726] Executing state service.running for [apache2]
2019-10-26 05:36:09,128 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-10-26 05:36:09,145 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-10-26 05:36:09,162 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-10-26 05:36:09,184 [salt.state       :300 ][INFO    ][10726] The service apache2 is already running
2019-10-26 05:36:09,185 [salt.state       :1951][INFO    ][10726] Completed state [apache2] at time 05:36:09.185026 duration_in_ms=56.73
2019-10-26 05:36:09,186 [salt.state       :1780][INFO    ][10726] Running state [maasng.wait_for_http_code] at time 05:36:09.186096
2019-10-26 05:36:09,186 [salt.state       :1813][INFO    ][10726] Executing state module.run for [maasng.wait_for_http_code]
2019-10-26 05:36:09,186 [salt.utils.decorators:613 ][WARNING ][10726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:09,291 [salt.state       :300 ][INFO    ][10726] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-10-26 05:36:09,292 [salt.state       :1951][INFO    ][10726] Completed state [maasng.wait_for_http_code] at time 05:36:09.292433 duration_in_ms=106.333
2019-10-26 05:36:09,294 [salt.state       :1780][INFO    ][10726] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:36:09.293954
2019-10-26 05:36:09,294 [salt.state       :1813][INFO    ][10726] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-10-26 05:36:09,295 [salt.state       :300 ][INFO    ][10726] /var/lib/maas/.setup_admin exists
2019-10-26 05:36:09,295 [salt.state       :1951][INFO    ][10726] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:36:09.295609 duration_in_ms=1.655
2019-10-26 05:36:09,296 [salt.state       :1780][INFO    ][10726] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:09.296778
2019-10-26 05:36:09,297 [salt.state       :1813][INFO    ][10726] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:36:09,298 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10726] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:36:10,688 [salt.state       :300 ][INFO    ][10726] {'pid': 10784, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:36:10,689 [salt.state       :1951][INFO    ][10726] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:10.689667 duration_in_ms=1392.888
2019-10-26 05:36:10,697 [salt.state       :1780][INFO    ][10726] Running state [maas_region_boot_source_resources_mirror] at time 05:36:10.697802
2019-10-26 05:36:10,698 [salt.state       :1813][INFO    ][10726] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-10-26 05:36:10,792 [salt.state       :300 ][INFO    ][10726] {'changes': {}}
2019-10-26 05:36:10,793 [salt.state       :1951][INFO    ][10726] Completed state [maas_region_boot_source_resources_mirror] at time 05:36:10.792950 duration_in_ms=95.147
2019-10-26 05:36:10,794 [salt.state       :1780][INFO    ][10726] Running state [maasng.boot_resources_import] at time 05:36:10.794444
2019-10-26 05:36:10,794 [salt.state       :1813][INFO    ][10726] Executing state module.run for [maasng.boot_resources_import]
2019-10-26 05:36:10,795 [salt.utils.decorators:613 ][WARNING ][10726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:10,901 [salt.loaded.ext.module.maasng:1600][INFO    ][10726] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-10-26 05:36:15,959 [salt.loaded.ext.module.maasng:1600][INFO    ][10726] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-10-26 05:36:19,796 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053619783982
2019-10-26 05:36:19,821 [salt.minion      :1432][INFO    ][10825] Starting a new job with PID 10825
2019-10-26 05:36:19,844 [salt.minion      :1711][INFO    ][10825] Returning information for job: 20191026053619783982
2019-10-26 05:36:21,019 [salt.loaded.ext.module.maasng:1600][INFO    ][10726] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-10-26 05:36:26,145 [salt.state       :300 ][INFO    ][10726] {'ret': True}
2019-10-26 05:36:26,146 [salt.state       :1951][INFO    ][10726] Completed state [maasng.boot_resources_import] at time 05:36:26.146013 duration_in_ms=15351.568
2019-10-26 05:36:26,147 [salt.state       :1780][INFO    ][10726] Running state [maas_region_boot_sources_selection_bionic] at time 05:36:26.147245
2019-10-26 05:36:26,147 [salt.state       :1813][INFO    ][10726] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-10-26 05:36:26,355 [salt.state       :300 ][INFO    ][10726] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-10-26 05:36:26,355 [salt.state       :1951][INFO    ][10726] Completed state [maas_region_boot_sources_selection_bionic] at time 05:36:26.355520 duration_in_ms=208.274
2019-10-26 05:36:26,357 [salt.state       :1780][INFO    ][10726] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:36:26.357010
2019-10-26 05:36:26,357 [salt.state       :1813][INFO    ][10726] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-10-26 05:36:26,358 [salt.utils.decorators:613 ][WARNING ][10726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:26,358 [salt.loaded.ext.module.maasng:1771][INFO    ][10726] boot-sources sync initiated for ALL Rack's
2019-10-26 05:36:27,277 [salt.state       :300 ][INFO    ][10726] {'ret': True}
2019-10-26 05:36:27,277 [salt.state       :1951][INFO    ][10726] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:36:27.277573 duration_in_ms=920.562
2019-10-26 05:36:27,279 [salt.state       :1780][INFO    ][10726] Running state [maas.process_maas_config] at time 05:36:27.279809
2019-10-26 05:36:27,280 [salt.state       :1813][INFO    ][10726] Executing state module.run for [maas.process_maas_config]
2019-10-26 05:36:27,280 [salt.utils.decorators:613 ][WARNING ][10726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:27,281 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=enable_http_proxy value=True
2019-10-26 05:36:27,339 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=upstream_dns value=8.8.8.8
2019-10-26 05:36:27,403 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=commissioning_distro_series value=bionic
2019-10-26 05:36:27,475 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=default_osystem value=ubuntu
2019-10-26 05:36:27,540 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=active_discovery_interval value=600
2019-10-26 05:36:30,342 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=dnssec_validation value=no
2019-10-26 05:36:30,408 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=maas_name value=mas01
2019-10-26 05:36:30,466 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=network_discovery value=enabled
2019-10-26 05:36:30,601 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=enable_third_party_drivers value=True
2019-10-26 05:36:30,658 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=default_storage_layout value=lvm
2019-10-26 05:36:30,708 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=ntp_external_only value=True
2019-10-26 05:36:30,762 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=disk_erase_with_secure_erase value=False
2019-10-26 05:36:30,822 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=default_distro_series value=bionic
2019-10-26 05:36:30,908 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-10-26 05:36:31,034 [salt.state       :300 ][INFO    ][10726] {'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-10-26 05:36:31,034 [salt.state       :1951][INFO    ][10726] Completed state [maas.process_maas_config] at time 05:36:31.034845 duration_in_ms=3755.034
2019-10-26 05:36:31,036 [salt.state       :1780][INFO    ][10726] Running state [pxe_admin] at time 05:36:31.036028
2019-10-26 05:36:31,036 [salt.state       :1813][INFO    ][10726] Executing state maasng.fabric_present for [pxe_admin]
2019-10-26 05:36:31,097 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-10-26 05:36:31,178 [salt.loaded.ext.module.maasng:1008][WARNING ][10726] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-10-26 05:36:31,178 [salt.loaded.ext.module.maasng:1011][WARNING ][10726] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-10-26 05:36:31,251 [salt.state       :300 ][INFO    ][10726] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-10-26 05:36:31,251 [salt.state       :1951][INFO    ][10726] Completed state [pxe_admin] at time 05:36:31.251831 duration_in_ms=215.803
2019-10-26 05:36:31,252 [salt.state       :1780][INFO    ][10726] Running state [vlan 0] at time 05:36:31.252264
2019-10-26 05:36:31,252 [salt.state       :1813][INFO    ][10726] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-10-26 05:36:31,316 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-10-26 05:36:31,471 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-10-26 05:36:31,768 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-10-26 05:36:31,877 [salt.state       :300 ][INFO    ][10726] {'new': 'Vlan untagged was updated'}
2019-10-26 05:36:31,877 [salt.state       :1951][INFO    ][10726] Completed state [vlan 0] at time 05:36:31.877898 duration_in_ms=625.632
2019-10-26 05:36:31,879 [salt.state       :1780][INFO    ][10726] Running state [192.168.11.0/24] at time 05:36:31.879563
2019-10-26 05:36:31,880 [salt.state       :1813][INFO    ][10726] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-10-26 05:36:32,099 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-10-26 05:36:32,100 [salt.loaded.ext.module.maasng:1235][WARNING ][10726] Ignoring parameter vlan:0
2019-10-26 05:36:32,167 [salt.state       :300 ][INFO    ][10726] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-10-26 05:36:32,167 [salt.state       :1951][INFO    ][10726] Completed state [192.168.11.0/24] at time 05:36:32.167760 duration_in_ms=288.196
2019-10-26 05:36:32,169 [salt.state       :1780][INFO    ][10726] Running state [maas_create_iprange_1] at time 05:36:32.169043
2019-10-26 05:36:32,169 [salt.state       :1813][INFO    ][10726] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-10-26 05:36:32,232 [salt.state       :300 ][INFO    ][10726] Iprange maas_create_iprange_1 already exist.
2019-10-26 05:36:32,233 [salt.state       :1951][INFO    ][10726] Completed state [maas_create_iprange_1] at time 05:36:32.233267 duration_in_ms=64.224
2019-10-26 05:36:32,233 [salt.state       :1780][INFO    ][10726] Running state [vlan 0] at time 05:36:32.233714
2019-10-26 05:36:32,234 [salt.state       :1813][INFO    ][10726] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-10-26 05:36:32,305 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-10-26 05:36:32,424 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-10-26 05:36:32,673 [salt.loaded.ext.module.maasng:945 ][INFO    ][10726] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'yhcswt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-10-26 05:36:32,783 [salt.state       :300 ][INFO    ][10726] {'new': 'Vlan untagged was updated'}
2019-10-26 05:36:32,783 [salt.state       :1951][INFO    ][10726] Completed state [vlan 0] at time 05:36:32.783400 duration_in_ms=549.685
2019-10-26 05:36:32,784 [salt.state       :1780][INFO    ][10726] Running state [opnfv] at time 05:36:32.784407
2019-10-26 05:36:32,784 [salt.state       :1813][INFO    ][10726] Executing state maasng.sshkey_present for [opnfv]
2019-10-26 05:36:32,840 [salt.loaded.ext.module.maasng:1903][INFO    ][10726] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-10-26 05:36:32,840 [salt.state       :300 ][INFO    ][10726] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-10-26 05:36:32,841 [salt.state       :1951][INFO    ][10726] Completed state [opnfv] at time 05:36:32.841229 duration_in_ms=56.822
2019-10-26 05:36:32,842 [salt.state       :1780][INFO    ][10726] Running state [maas.process_tags] at time 05:36:32.842146
2019-10-26 05:36:32,842 [salt.state       :1813][INFO    ][10726] Executing state module.run for [maas.process_tags]
2019-10-26 05:36:32,843 [salt.utils.decorators:613 ][WARNING ][10726] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:32,888 [salt.loaded.ext.module.maas:92  ][INFO    ][10726] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-10-26 05:36:32,942 [salt.state       :300 ][INFO    ][10726] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-10-26 05:36:32,942 [salt.state       :1951][INFO    ][10726] Completed state [maas.process_tags] at time 05:36:32.942900 duration_in_ms=100.754
2019-10-26 05:36:32,948 [salt.minion      :1711][INFO    ][10726] Returning information for job: 20191026053604684398
2019-10-26 05:36:33,452 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026053633442984
2019-10-26 05:36:33,470 [salt.minion      :1432][INFO    ][11092] Starting a new job with PID 11092
2019-10-26 05:36:37,159 [salt.state       :915 ][INFO    ][11092] Loading fresh modules for state activity
2019-10-26 05:36:37,240 [salt.state       :1780][INFO    ][11092] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:37.240705
2019-10-26 05:36:37,241 [salt.state       :1813][INFO    ][11092] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:36:37,242 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11092] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:36:38,648 [salt.state       :300 ][INFO    ][11092] {'pid': 11122, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:36:38,649 [salt.state       :1951][INFO    ][11092] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:36:38.649650 duration_in_ms=1408.942
2019-10-26 05:36:38,652 [salt.state       :1780][INFO    ][11092] Running state [maas.process_machines] at time 05:36:38.652284
2019-10-26 05:36:38,652 [salt.state       :1813][INFO    ][11092] Executing state module.run for [maas.process_machines]
2019-10-26 05:36:38,653 [salt.utils.decorators:613 ][WARNING ][11092] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:36:39,355 [salt.loaded.ext.module.maas:412 ][WARNING ][11092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:36:39,356 [salt.loaded.ext.module.maas:92  ][INFO    ][11092] 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=cnfykf architecture=amd64/generic power_parameters_power_user=admin
2019-10-26 05:36:40,587 [salt.loaded.ext.module.maas:412 ][WARNING ][11092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:36:40,588 [salt.loaded.ext.module.maas:92  ][INFO    ][11092] 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=yst6bt architecture=amd64/generic power_parameters_power_user=admin
2019-10-26 05:36:41,808 [salt.loaded.ext.module.maas:412 ][WARNING ][11092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:36:41,809 [salt.loaded.ext.module.maas:92  ][INFO    ][11092] 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=mp4k8p architecture=amd64/generic power_parameters_power_user=admin
2019-10-26 05:36:43,216 [salt.loaded.ext.module.maas:412 ][WARNING ][11092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:36:43,217 [salt.loaded.ext.module.maas:92  ][INFO    ][11092] 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=pmk7xb architecture=amd64/generic power_parameters_power_user=admin
2019-10-26 05:36:44,450 [salt.loaded.ext.module.maas:412 ][WARNING ][11092] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-10-26 05:36:44,452 [salt.loaded.ext.module.maas:92  ][INFO    ][11092] 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=dxkad6 architecture=amd64/generic power_parameters_power_user=admin
2019-10-26 05:36:45,666 [salt.state       :300 ][INFO    ][11092] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-10-26 05:36:45,666 [salt.state       :1951][INFO    ][11092] Completed state [maas.process_machines] at time 05:36:45.666566 duration_in_ms=7014.279
2019-10-26 05:36:45,670 [salt.minion      :1711][INFO    ][11092] Returning information for job: 20191026053633442984
2019-10-26 05:37:18,994 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026053718981334
2019-10-26 05:37:19,018 [salt.minion      :1432][INFO    ][11383] Starting a new job with PID 11383
2019-10-26 05:37:22,930 [salt.state       :915 ][INFO    ][11383] Loading fresh modules for state activity
2019-10-26 05:37:23,018 [salt.state       :1780][INFO    ][11383] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:23.018645
2019-10-26 05:37:23,019 [salt.state       :1813][INFO    ][11383] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:37:23,021 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11383] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:37:24,549 [salt.state       :300 ][INFO    ][11383] {'pid': 11390, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:37:24,550 [salt.state       :1951][INFO    ][11383] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:37:24.550452 duration_in_ms=1531.807
2019-10-26 05:37:24,553 [salt.state       :1780][INFO    ][11383] Running state [maas.wait_for_machine_status] at time 05:37:24.553048
2019-10-26 05:37:24,553 [salt.state       :1813][INFO    ][11383] Executing state module.run for [maas.wait_for_machine_status]
2019-10-26 05:37:24,554 [salt.utils.decorators:613 ][WARNING ][11383] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:37:26,874 [salt.loaded.ext.module.maas:993 ][INFO    ][11383] Machine pmk7xb mark broken
2019-10-26 05:37:27,227 [salt.loaded.ext.module.maas:996 ][INFO    ][11383] Machine pmk7xb mark fixed
2019-10-26 05:37:28,336 [salt.loaded.ext.module.maas:684 ][INFO    ][11383] deploymachines hwe_kernel=ga-18.04 system_id=pmk7xb distro_series=bionic
2019-10-26 05:37:31,598 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.97035599s left)
2019-10-26 05:37:34,108 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053734094980
2019-10-26 05:37:34,132 [salt.minion      :1432][INFO    ][11466] Starting a new job with PID 11466
2019-10-26 05:37:34,156 [salt.minion      :1711][INFO    ][11466] Returning information for job: 20191026053734094980
2019-10-26 05:38:04,353 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053804300299
2019-10-26 05:38:04,373 [salt.minion      :1432][INFO    ][11503] Starting a new job with PID 11503
2019-10-26 05:38:04,397 [salt.minion      :1711][INFO    ][11503] Returning information for job: 20191026053804300299
2019-10-26 05:38:04,980 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.58855987s left)
2019-10-26 05:38:34,397 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053834384656
2019-10-26 05:38:34,422 [salt.minion      :1432][INFO    ][11545] Starting a new job with PID 11545
2019-10-26 05:38:34,444 [salt.minion      :1711][INFO    ][11545] Returning information for job: 20191026053834384656
2019-10-26 05:38:38,379 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1426.18917298s left)
2019-10-26 05:39:04,444 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053904430266
2019-10-26 05:39:04,469 [salt.minion      :1432][INFO    ][11579] Starting a new job with PID 11579
2019-10-26 05:39:04,492 [salt.minion      :1711][INFO    ][11579] Returning information for job: 20191026053904430266
2019-10-26 05:39:11,529 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1393.03975296s left)
2019-10-26 05:39:34,501 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026053934488360
2019-10-26 05:39:34,526 [salt.minion      :1432][INFO    ][11690] Starting a new job with PID 11690
2019-10-26 05:39:34,548 [salt.minion      :1711][INFO    ][11690] Returning information for job: 20191026053934488360
2019-10-26 05:39:45,198 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.37046409s left)
2019-10-26 05:40:04,556 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054004544981
2019-10-26 05:40:04,578 [salt.minion      :1432][INFO    ][11750] Starting a new job with PID 11750
2019-10-26 05:40:04,601 [salt.minion      :1711][INFO    ][11750] Returning information for job: 20191026054004544981
2019-10-26 05:40:18,578 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.99068308s left)
2019-10-26 05:40:34,615 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054034604858
2019-10-26 05:40:34,638 [salt.minion      :1432][INFO    ][11910] Starting a new job with PID 11910
2019-10-26 05:40:34,655 [salt.minion      :1711][INFO    ][11910] Returning information for job: 20191026054034604858
2019-10-26 05:40:51,670 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1292.89849496s left)
2019-10-26 05:41:04,673 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054104660710
2019-10-26 05:41:04,697 [salt.minion      :1432][INFO    ][11972] Starting a new job with PID 11972
2019-10-26 05:41:04,720 [salt.minion      :1711][INFO    ][11972] Returning information for job: 20191026054104660710
2019-10-26 05:41:25,038 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1259.53059196s left)
2019-10-26 05:41:34,738 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054134726034
2019-10-26 05:41:34,763 [salt.minion      :1432][INFO    ][12010] Starting a new job with PID 12010
2019-10-26 05:41:34,786 [salt.minion      :1711][INFO    ][12010] Returning information for job: 20191026054134726034
2019-10-26 05:41:58,284 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1226.28485799s left)
2019-10-26 05:42:04,810 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054204797944
2019-10-26 05:42:04,834 [salt.minion      :1432][INFO    ][12084] Starting a new job with PID 12084
2019-10-26 05:42:04,857 [salt.minion      :1711][INFO    ][12084] Returning information for job: 20191026054204797944
2019-10-26 05:42:31,670 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1192.89842606s left)
2019-10-26 05:42:34,886 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054234873275
2019-10-26 05:42:34,910 [salt.minion      :1432][INFO    ][12144] Starting a new job with PID 12144
2019-10-26 05:42:34,932 [salt.minion      :1711][INFO    ][12144] Returning information for job: 20191026054234873275
2019-10-26 05:43:04,970 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054304960996
2019-10-26 05:43:04,990 [salt.minion      :1432][INFO    ][12230] Starting a new job with PID 12230
2019-10-26 05:43:05,009 [salt.minion      :1711][INFO    ][12230] Returning information for job: 20191026054304960996
2019-10-26 05:43:05,207 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1159.36173606s left)
2019-10-26 05:43:35,043 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054335030577
2019-10-26 05:43:35,066 [salt.minion      :1432][INFO    ][12322] Starting a new job with PID 12322
2019-10-26 05:43:35,090 [salt.minion      :1711][INFO    ][12322] Returning information for job: 20191026054335030577
2019-10-26 05:43:38,835 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1125.733778s left)
2019-10-26 05:44:05,132 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054405118934
2019-10-26 05:44:05,154 [salt.minion      :1432][INFO    ][12361] Starting a new job with PID 12361
2019-10-26 05:44:05,179 [salt.minion      :1711][INFO    ][12361] Returning information for job: 20191026054405118934
2019-10-26 05:44:12,401 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1092.16724205s left)
2019-10-26 05:44:35,226 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054435212979
2019-10-26 05:44:35,251 [salt.minion      :1432][INFO    ][12405] Starting a new job with PID 12405
2019-10-26 05:44:35,277 [salt.minion      :1711][INFO    ][12405] Returning information for job: 20191026054435212979
2019-10-26 05:44:45,989 [salt.loaded.ext.module.maas:1023][INFO    ][11383] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1058.5792079s left)
2019-10-26 05:45:05,337 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command saltutil.find_job with jid 20191026054505322141
2019-10-26 05:45:05,365 [salt.minion      :1432][INFO    ][12500] Starting a new job with PID 12500
2019-10-26 05:45:05,395 [salt.minion      :1711][INFO    ][12500] Returning information for job: 20191026054505322141
2019-10-26 05:45:19,632 [salt.state       :300 ][INFO    ][11383] {'ret': True}
2019-10-26 05:45:19,633 [salt.state       :1951][INFO    ][11383] Completed state [maas.wait_for_machine_status] at time 05:45:19.633161 duration_in_ms=475080.112
2019-10-26 05:45:19,637 [salt.minion      :1711][INFO    ][11383] Returning information for job: 20191026053718981334
2019-10-26 05:45:20,279 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026054520266374
2019-10-26 05:45:20,304 [salt.minion      :1432][INFO    ][12551] Starting a new job with PID 12551
2019-10-26 05:45:24,060 [salt.state       :915 ][INFO    ][12551] Loading fresh modules for state activity
2019-10-26 05:45:24,200 [salt.state       :1780][INFO    ][12551] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:24.200298
2019-10-26 05:45:24,200 [salt.state       :1813][INFO    ][12551] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:45:24,202 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12551] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:45:25,779 [salt.state       :300 ][INFO    ][12551] {'pid': 12558, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:45:25,780 [salt.state       :1951][INFO    ][12551] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:25.780164 duration_in_ms=1579.865
2019-10-26 05:45:25,783 [salt.state       :1780][INFO    ][12551] Running state [maas_machines_storage_cmp002_lvm] at time 05:45:25.783470
2019-10-26 05:45:25,784 [salt.state       :1813][INFO    ][12551] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-10-26 05:45:26,491 [salt.state       :300 ][INFO    ][12551] Machine cmp002 is not in Ready state.
2019-10-26 05:45:26,492 [salt.state       :1951][INFO    ][12551] Completed state [maas_machines_storage_cmp002_lvm] at time 05:45:26.492116 duration_in_ms=708.645
2019-10-26 05:45:26,492 [salt.state       :1780][INFO    ][12551] Running state [maas_machines_storage_cmp001_lvm] at time 05:45:26.492692
2019-10-26 05:45:26,493 [salt.state       :1813][INFO    ][12551] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-10-26 05:45:27,183 [salt.state       :300 ][INFO    ][12551] Machine cmp001 is not in Ready state.
2019-10-26 05:45:27,183 [salt.state       :1951][INFO    ][12551] Completed state [maas_machines_storage_cmp001_lvm] at time 05:45:27.183795 duration_in_ms=691.103
2019-10-26 05:45:27,188 [salt.minion      :1711][INFO    ][12551] Returning information for job: 20191026054520266374
2019-10-26 05:45:27,778 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026054527766037
2019-10-26 05:45:27,802 [salt.minion      :1432][INFO    ][12572] Starting a new job with PID 12572
2019-10-26 05:45:28,607 [salt.state       :915 ][INFO    ][12572] Loading fresh modules for state activity
2019-10-26 05:45:28,692 [salt.state       :1780][INFO    ][12572] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:28.692788
2019-10-26 05:45:28,693 [salt.state       :1813][INFO    ][12572] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:45:28,695 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12572] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:45:30,050 [salt.state       :300 ][INFO    ][12572] {'pid': 12583, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:45:30,051 [salt.state       :1951][INFO    ][12572] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:30.051239 duration_in_ms=1358.452
2019-10-26 05:45:30,052 [salt.state       :1780][INFO    ][12572] Running state [maas.deploy_machines] at time 05:45:30.052310
2019-10-26 05:45:30,052 [salt.state       :1813][INFO    ][12572] Executing state module.run for [maas.deploy_machines]
2019-10-26 05:45:30,053 [salt.utils.decorators:613 ][WARNING ][12572] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:45:30,760 [salt.state       :300 ][INFO    ][12572] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-10-26 05:45:30,760 [salt.state       :1951][INFO    ][12572] Completed state [maas.deploy_machines] at time 05:45:30.760854 duration_in_ms=708.543
2019-10-26 05:45:30,764 [salt.minion      :1711][INFO    ][12572] Returning information for job: 20191026054527766037
2019-10-26 05:45:31,387 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command state.apply with jid 20191026054531373404
2019-10-26 05:45:31,411 [salt.minion      :1432][INFO    ][12595] Starting a new job with PID 12595
2019-10-26 05:45:32,272 [salt.state       :915 ][INFO    ][12595] Loading fresh modules for state activity
2019-10-26 05:45:32,361 [salt.state       :1780][INFO    ][12595] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:32.360949
2019-10-26 05:45:32,361 [salt.state       :1813][INFO    ][12595] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-10-26 05:45:32,363 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12595] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-10-26 05:45:33,814 [salt.state       :300 ][INFO    ][12595] {'pid': 12602, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-10-26 05:45:33,815 [salt.state       :1951][INFO    ][12595] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:45:33.815180 duration_in_ms=1454.233
2019-10-26 05:45:33,816 [salt.state       :1780][INFO    ][12595] Running state [maas.wait_for_machine_status] at time 05:45:33.816736
2019-10-26 05:45:33,816 [salt.state       :1813][INFO    ][12595] Executing state module.run for [maas.wait_for_machine_status]
2019-10-26 05:45:33,817 [salt.utils.decorators:613 ][WARNING ][12595] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-10-26 05:45:37,092 [salt.state       :300 ][INFO    ][12595] {'ret': True}
2019-10-26 05:45:37,093 [salt.state       :1951][INFO    ][12595] Completed state [maas.wait_for_machine_status] at time 05:45:37.093345 duration_in_ms=3276.606
2019-10-26 05:45:37,097 [salt.minion      :1711][INFO    ][12595] Returning information for job: 20191026054531373404
2019-10-26 06:11:59,774 [salt.utils.schedule:1377][INFO    ][3111] Running scheduled job: __mine_interval
2019-10-26 07:11:59,774 [salt.utils.schedule:1377][INFO    ][3111] Running scheduled job: __mine_interval
2019-10-26 07:18:16,078 [salt.minion      :1308][INFO    ][3111] User sudo_ubuntu Executing command cp.push_dir with jid 20191026071816066121
2019-10-26 07:18:16,097 [salt.minion      :1432][INFO    ][19155] Starting a new job with PID 19155
