2019-05-24 20:07:25,884 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-24 20:08:15,934 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-24 20:09:05,984 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-24 20:09:56,019 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-24 20:10:46,064 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-24 20:12:54,500 [salt.utils.decorators:613 ][WARNING ][2731] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:12:55,122 [salt.utils.decorators:613 ][WARNING ][2731] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:12:57,151 [salt.loaded.int.states.file:2298][WARNING ][2870] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-24 20:13:02,697 [salt.state       :2022][WARNING ][2980] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-24 20:13:05,292 [salt.utils.decorators:613 ][WARNING ][2980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:13:16,645 [salt.utils.decorators:613 ][WARNING ][2980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:13:50,604 [salt.utils.decorators:613 ][WARNING ][2980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:13:51,497 [salt.utils.decorators:613 ][WARNING ][2980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:13:55,330 [salt.loaded.ext.module.maasng:1008][WARNING ][2980] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-24 20:13:55,330 [salt.loaded.ext.module.maasng:1011][WARNING ][2980] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-24 20:13:56,010 [salt.loaded.ext.module.maasng:1235][WARNING ][2980] Ignoring parameter vlan:0
2019-05-24 20:13:57,048 [salt.utils.decorators:613 ][WARNING ][2980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:13:58,969 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5832] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-24 20:13:58,998 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5832] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-24 20:13:59,017 [salt.utils.parsers:1051][WARNING ][362] Minion received a SIGTERM. Exiting.
2019-05-24 20:14:00,020 [salt.cli.daemons :293 ][INFO    ][5917] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-05-24 20:14:00,108 [salt.cli.daemons :82  ][INFO    ][5917] Starting up the Salt Minion
2019-05-24 20:14:00,108 [salt.utils.event :1017][INFO    ][5917] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-05-24 20:14:00,846 [salt.minion      :976 ][INFO    ][5917] Creating minion process manager
2019-05-24 20:14:02,120 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5917] Executing command ['date', '+%z'] in directory '/root'
2019-05-24 20:14:02,137 [salt.utils.schedule:568 ][INFO    ][5917] Updating job settings for scheduled job: __mine_interval
2019-05-24 20:14:02,139 [salt.minion      :1108][INFO    ][5917] Added mine.update to scheduler
2019-05-24 20:14:02,143 [salt.minion      :1975][INFO    ][5917] Minion is starting as user 'root'
2019-05-24 20:14:02,154 [salt.minion      :2336][INFO    ][5917] Minion is ready to receive requests!
2019-05-24 20:14:02,461 [salt.utils.decorators:613 ][WARNING ][5838] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:14:02,520 [salt.loaded.ext.module.maas:412 ][WARNING ][5838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:14:04,211 [salt.loaded.ext.module.maas:412 ][WARNING ][5838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:14:05,707 [salt.loaded.ext.module.maas:412 ][WARNING ][5838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:14:07,090 [salt.loaded.ext.module.maas:412 ][WARNING ][5838] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:14:39,566 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524201439553964
2019-05-24 20:14:39,589 [salt.minion      :1432][INFO    ][6266] Starting a new job with PID 6266
2019-05-24 20:14:43,277 [salt.state       :915 ][INFO    ][6266] Loading fresh modules for state activity
2019-05-24 20:14:43,305 [salt.fileclient  :1219][INFO    ][6266] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-24 20:14:43,331 [salt.state       :1780][INFO    ][6266] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:14:43.331266
2019-05-24 20:14:43,331 [salt.state       :1813][INFO    ][6266] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:14:43,332 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6266] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:14:44,866 [salt.state       :300 ][INFO    ][6266] {'pid': 6273, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:14:44,867 [salt.state       :1951][INFO    ][6266] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:14:44.867375 duration_in_ms=1536.109
2019-05-24 20:14:44,869 [salt.state       :1780][INFO    ][6266] Running state [maas.wait_for_machine_status] at time 20:14:44.869306
2019-05-24 20:14:44,869 [salt.state       :1813][INFO    ][6266] Executing state module.run for [maas.wait_for_machine_status]
2019-05-24 20:14:44,870 [salt.utils.decorators:613 ][WARNING ][6266] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:14:45,429 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.44892812s left)
2019-05-24 20:14:54,681 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201454667826
2019-05-24 20:14:54,705 [salt.minion      :1432][INFO    ][6285] Starting a new job with PID 6285
2019-05-24 20:14:54,727 [salt.minion      :1711][INFO    ][6285] Returning information for job: 20190524201454667826
2019-05-24 20:15:16,291 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.58663106s left)
2019-05-24 20:15:24,737 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201524721605
2019-05-24 20:15:24,761 [salt.minion      :1432][INFO    ][6337] Starting a new job with PID 6337
2019-05-24 20:15:24,783 [salt.minion      :1711][INFO    ][6337] Returning information for job: 20190524201524721605
2019-05-24 20:15:47,153 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1437.72439909s left)
2019-05-24 20:15:54,825 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201554812500
2019-05-24 20:15:54,846 [salt.minion      :1432][INFO    ][6458] Starting a new job with PID 6458
2019-05-24 20:15:54,868 [salt.minion      :1711][INFO    ][6458] Returning information for job: 20190524201554812500
2019-05-24 20:16:18,157 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1406.72024798s left)
2019-05-24 20:16:24,877 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201624860751
2019-05-24 20:16:24,900 [salt.minion      :1432][INFO    ][6700] Starting a new job with PID 6700
2019-05-24 20:16:24,921 [salt.minion      :1711][INFO    ][6700] Returning information for job: 20190524201624860751
2019-05-24 20:16:49,370 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1375.50741315s left)
2019-05-24 20:16:54,932 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201654919278
2019-05-24 20:16:54,956 [salt.minion      :1432][INFO    ][6830] Starting a new job with PID 6830
2019-05-24 20:16:54,978 [salt.minion      :1711][INFO    ][6830] Returning information for job: 20190524201654919278
2019-05-24 20:17:20,704 [salt.loaded.ext.module.maas:1023][INFO    ][6266] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1344.17401814s left)
2019-05-24 20:17:24,988 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201724974158
2019-05-24 20:17:25,012 [salt.minion      :1432][INFO    ][7234] Starting a new job with PID 7234
2019-05-24 20:17:25,035 [salt.minion      :1711][INFO    ][7234] Returning information for job: 20190524201724974158
2019-05-24 20:17:53,130 [salt.state       :300 ][INFO    ][6266] {'ret': True}
2019-05-24 20:17:53,130 [salt.state       :1951][INFO    ][6266] Completed state [maas.wait_for_machine_status] at time 20:17:53.130567 duration_in_ms=188261.257
2019-05-24 20:17:53,134 [salt.minion      :1711][INFO    ][6266] Returning information for job: 20190524201439553964
2019-05-24 20:17:53,786 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524201753773116
2019-05-24 20:17:53,810 [salt.minion      :1432][INFO    ][7344] Starting a new job with PID 7344
2019-05-24 20:17:57,322 [salt.state       :915 ][INFO    ][7344] Loading fresh modules for state activity
2019-05-24 20:17:57,349 [salt.fileclient  :1219][INFO    ][7344] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-24 20:17:57,400 [salt.state       :1780][INFO    ][7344] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:17:57.400368
2019-05-24 20:17:57,400 [salt.state       :1813][INFO    ][7344] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:17:57,401 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7344] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:17:58,849 [salt.state       :300 ][INFO    ][7344] {'pid': 7351, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:17:58,849 [salt.state       :1951][INFO    ][7344] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:17:58.849700 duration_in_ms=1449.332
2019-05-24 20:17:58,851 [salt.state       :1780][INFO    ][7344] Running state [maas_machines_storage_cmp002_lvm] at time 20:17:58.851045
2019-05-24 20:17:58,851 [salt.state       :1813][INFO    ][7344] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-24 20:18:00,105 [salt.loaded.ext.module.maasng:610 ][INFO    ][7344] mgykgf
2019-05-24 20:18:00,106 [salt.loaded.ext.module.maasng:626 ][INFO    ][7344] sda
2019-05-24 20:18:00,621 [salt.loaded.ext.module.maasng:361 ][INFO    ][7344] mgykgf
2019-05-24 20:18:00,742 [salt.loaded.ext.module.maasng:367 ][INFO    ][7344] [{u'size': 2397998940160, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'mgykgf', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'd247c7ec-676b-4520-be3e-d74909c5b501', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mgykgf', u'filesystem': {u'uuid': u'527fda65-56a0-430d-a4e5-9b006d39c1b4', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/partition/5', u'type': u'partition', u'id': 5, u'device_id': 4}]}, {u'size': 2397988454400, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/9/', u'used_size': 2397988454400, u'id': 9, u'tags': [], u'uuid': u'4e41b068-0f42-4216-8040-1c47c055f025', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'mgykgf', u'partition_table_type': None, u'filesystem': {u'uuid': u'f600f3fc-20a1-4a18-8172-0b040a97b207', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'partitions': []}]
2019-05-24 20:18:00,743 [salt.loaded.ext.module.maasng:632 ][INFO    ][7344] vgroot
2019-05-24 20:18:00,743 [salt.loaded.ext.module.maasng:635 ][INFO    ][7344] lvroot
2019-05-24 20:18:00,744 [salt.loaded.ext.module.maasng:639 ][INFO    ][7344] 107374182400
2019-05-24 20:18:01,420 [salt.loaded.ext.module.maasng:645 ][INFO    ][7344] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'commissioning_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'type': u'physical', u'partitions': [{u'uuid': u'f0506d26-6952-48d3-a237-cefe48376ec2', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mgykgf', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'933cab8b-d12c-411f-b78b-22c37d17d474', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'mgykgf', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/'}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'mgykgf', 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"From 'Testing' to 'Ready'", u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'b238e6e0-6573-4d87-91df-4693a4f68966', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'mgykgf', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ffc3d7dd-ed79-44ba-b6c7-c93e711c7c8a', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 10, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/10/'}], u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'f0506d26-6952-48d3-a237-cefe48376ec2', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mgykgf', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'933cab8b-d12c-411f-b78b-22c37d17d474', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'mgykgf', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/'}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'b238e6e0-6573-4d87-91df-4693a4f68966', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'mgykgf', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ffc3d7dd-ed79-44ba-b6c7-c93e711c7c8a', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'id': 10, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/10/'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'on', u'physicalblockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'f0506d26-6952-48d3-a237-cefe48376ec2', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mgykgf', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'933cab8b-d12c-411f-b78b-22c37d17d474', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'mgykgf', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/blockdevices/4/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'mgykgf', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 29}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'mgykgf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 15, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'mgykgf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/interfaces/15/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 33}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 16, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'mgykgf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/interfaces/16/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 35}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 19, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'mgykgf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/interfaces/19/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'ip_addresses': [u'192.168.11.41'], u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'mode': u'dhcp', u'id': 29}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'mgykgf', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mgykgf/interfaces/5/'}, u'current_commissioning_result_id': 4, u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/mgykgf/'}
2019-05-24 20:18:01,422 [salt.state       :300 ][INFO    ][7344] {'new': {'storage_layout': 'lvm'}}
2019-05-24 20:18:01,423 [salt.state       :1951][INFO    ][7344] Completed state [maas_machines_storage_cmp002_lvm] at time 20:18:01.423284 duration_in_ms=2572.236
2019-05-24 20:18:01,423 [salt.state       :1780][INFO    ][7344] Running state [maas_machines_storage_cmp001_lvm] at time 20:18:01.423902
2019-05-24 20:18:01,424 [salt.state       :1813][INFO    ][7344] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-24 20:18:02,561 [salt.loaded.ext.module.maasng:610 ][INFO    ][7344] aahqhg
2019-05-24 20:18:02,562 [salt.loaded.ext.module.maasng:626 ][INFO    ][7344] sda
2019-05-24 20:18:03,195 [salt.loaded.ext.module.maasng:361 ][INFO    ][7344] aahqhg
2019-05-24 20:18:03,323 [salt.loaded.ext.module.maasng:367 ][INFO    ][7344] [{u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'1bccc324-580d-4c79-90c5-774251652c1f', u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/partition/1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'aahqhg', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'da9bab40-ea7d-4e22-a020-60b0362e46a0', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 1, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'aahqhg', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/5/', u'available_size': 0, u'uuid': u'a5565a61-e9b2-4603-8988-848329c84b86', 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'aahqhg', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'75f66d93-9a9e-4b74-ad5f-7362f3d18370', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 5, u'serial': None, u'size': 2397988454400}]
2019-05-24 20:18:03,323 [salt.loaded.ext.module.maasng:632 ][INFO    ][7344] vgroot
2019-05-24 20:18:03,324 [salt.loaded.ext.module.maasng:635 ][INFO    ][7344] lvroot
2019-05-24 20:18:03,324 [salt.loaded.ext.module.maasng:639 ][INFO    ][7344] 107374182400
2019-05-24 20:18:04,008 [salt.loaded.ext.module.maasng:645 ][INFO    ][7344] {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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 14, 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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 6, 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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'aahqhg', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/interfaces/6/'}, u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'1993d196-d424-4e6b-b0ce-d3f2acb59ecf', u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'aahqhg', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7170f0fc-8a6b-450d-b725-bd5ef7c94f36', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'aahqhg', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/11/', u'available_size': 0, u'uuid': u'dbec30a1-8478-4bfe-b9ed-d3033ac74e28', 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'aahqhg', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'a0de945b-e732-47c9-8888-80c90aa954a5', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'serial': None, u'size': 107374182400}], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/aahqhg/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'aahqhg', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.39'], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'1993d196-d424-4e6b-b0ce-d3f2acb59ecf', u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'aahqhg', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7170f0fc-8a6b-450d-b725-bd5ef7c94f36', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'aahqhg', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'aahqhg', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 6, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 7, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/11/', u'available_size': 0, 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'aahqhg', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'a0de945b-e732-47c9-8888-80c90aa954a5', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'serial': None, u'uuid': u'dbec30a1-8478-4bfe-b9ed-d3033ac74e28'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_disk': {u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'1993d196-d424-4e6b-b0ce-d3f2acb59ecf', u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'aahqhg', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'7170f0fc-8a6b-450d-b725-bd5ef7c94f36', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'aahqhg', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}, 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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 14, 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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 6, 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'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'system_id': u'aahqhg', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/interfaces/6/'}, {u'name': u'enp7s0', u'links': [{u'id': 15, 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'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 8, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'system_id': u'aahqhg', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/interfaces/8/'}, {u'name': u'enp8s0', u'links': [{u'id': 16, 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'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 9, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'system_id': u'aahqhg', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/interfaces/9/'}, {u'name': u'enp9s0', u'links': [{u'id': 17, 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'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'system_id': u'aahqhg', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/aahqhg/interfaces/11/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-05-24 20:18:04,010 [salt.state       :300 ][INFO    ][7344] {'new': {'storage_layout': 'lvm'}}
2019-05-24 20:18:04,010 [salt.state       :1951][INFO    ][7344] Completed state [maas_machines_storage_cmp001_lvm] at time 20:18:04.010529 duration_in_ms=2586.626
2019-05-24 20:18:04,014 [salt.minion      :1711][INFO    ][7344] Returning information for job: 20190524201753773116
2019-05-24 20:18:04,617 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524201804606242
2019-05-24 20:18:04,634 [salt.minion      :1432][INFO    ][7418] Starting a new job with PID 7418
2019-05-24 20:18:05,148 [salt.state       :915 ][INFO    ][7418] Loading fresh modules for state activity
2019-05-24 20:18:05,177 [salt.fileclient  :1219][INFO    ][7418] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-24 20:18:05,201 [salt.state       :1780][INFO    ][7418] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:18:05.201108
2019-05-24 20:18:05,201 [salt.state       :1813][INFO    ][7418] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:18:05,202 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7418] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:18:06,600 [salt.state       :300 ][INFO    ][7418] {'pid': 7441, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:18:06,600 [salt.state       :1951][INFO    ][7418] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:18:06.600657 duration_in_ms=1399.55
2019-05-24 20:18:06,601 [salt.state       :1780][INFO    ][7418] Running state [maas.deploy_machines] at time 20:18:06.601686
2019-05-24 20:18:06,601 [salt.state       :1813][INFO    ][7418] Executing state module.run for [maas.deploy_machines]
2019-05-24 20:18:06,602 [salt.utils.decorators:613 ][WARNING ][7418] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:18:07,234 [salt.loaded.ext.module.maas:684 ][INFO    ][7418] deploymachines hwe_kernel=hwe-16.04 system_id=trfehe distro_series=xenial
2019-05-24 20:18:10,066 [salt.loaded.ext.module.maas:684 ][INFO    ][7418] deploymachines hwe_kernel=hwe-16.04 system_id=mgykgf distro_series=xenial
2019-05-24 20:18:12,790 [salt.loaded.ext.module.maas:684 ][INFO    ][7418] deploymachines hwe_kernel=hwe-16.04 system_id=aahqhg distro_series=xenial
2019-05-24 20:18:15,521 [salt.loaded.ext.module.maas:684 ][INFO    ][7418] deploymachines hwe_kernel=hwe-16.04 system_id=mgkwcg distro_series=xenial
2019-05-24 20:18:18,180 [salt.state       :300 ][INFO    ][7418] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-05-24 20:18:18,181 [salt.state       :1951][INFO    ][7418] Completed state [maas.deploy_machines] at time 20:18:18.180979 duration_in_ms=11579.291
2019-05-24 20:18:18,184 [salt.minion      :1711][INFO    ][7418] Returning information for job: 20190524201804606242
2019-05-24 20:18:18,779 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524201818765915
2019-05-24 20:18:18,802 [salt.minion      :1432][INFO    ][7671] Starting a new job with PID 7671
2019-05-24 20:18:22,232 [salt.state       :915 ][INFO    ][7671] Loading fresh modules for state activity
2019-05-24 20:18:22,285 [salt.fileclient  :1219][INFO    ][7671] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-24 20:18:22,325 [salt.state       :1780][INFO    ][7671] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:18:22.325866
2019-05-24 20:18:22,326 [salt.state       :1813][INFO    ][7671] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:18:22,328 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7671] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:18:23,720 [salt.state       :300 ][INFO    ][7671] {'pid': 7682, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:18:23,720 [salt.state       :1951][INFO    ][7671] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:18:23.720746 duration_in_ms=1394.881
2019-05-24 20:18:23,721 [salt.state       :1780][INFO    ][7671] Running state [maas.wait_for_machine_status] at time 20:18:23.721762
2019-05-24 20:18:23,721 [salt.state       :1813][INFO    ][7671] Executing state module.run for [maas.wait_for_machine_status]
2019-05-24 20:18:23,722 [salt.utils.decorators:613 ][WARNING ][7671] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:18:26,227 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2247.49897099s left)
2019-05-24 20:18:33,854 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201833838058
2019-05-24 20:18:33,877 [salt.minion      :1432][INFO    ][7703] Starting a new job with PID 7703
2019-05-24 20:18:33,899 [salt.minion      :1711][INFO    ][7703] Returning information for job: 20190524201833838058
2019-05-24 20:18:58,696 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2215.02955079s left)
2019-05-24 20:19:03,898 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201903882343
2019-05-24 20:19:03,921 [salt.minion      :1432][INFO    ][7731] Starting a new job with PID 7731
2019-05-24 20:19:03,942 [salt.minion      :1711][INFO    ][7731] Returning information for job: 20190524201903882343
2019-05-24 20:19:31,461 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2182.26496196s left)
2019-05-24 20:19:33,974 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524201933958246
2019-05-24 20:19:33,997 [salt.minion      :1432][INFO    ][7780] Starting a new job with PID 7780
2019-05-24 20:19:34,018 [salt.minion      :1711][INFO    ][7780] Returning information for job: 20190524201933958246
2019-05-24 20:20:03,762 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2149.96409392s left)
2019-05-24 20:20:04,015 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202004003067
2019-05-24 20:20:04,032 [salt.minion      :1432][INFO    ][7910] Starting a new job with PID 7910
2019-05-24 20:20:04,055 [salt.minion      :1711][INFO    ][7910] Returning information for job: 20190524202004003067
2019-05-24 20:20:34,074 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202034061030
2019-05-24 20:20:34,097 [salt.minion      :1432][INFO    ][8103] Starting a new job with PID 8103
2019-05-24 20:20:34,118 [salt.minion      :1711][INFO    ][8103] Returning information for job: 20190524202034061030
2019-05-24 20:20:36,261 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2117.46494699s left)
2019-05-24 20:21:04,123 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202104111072
2019-05-24 20:21:04,147 [salt.minion      :1432][INFO    ][8143] Starting a new job with PID 8143
2019-05-24 20:21:04,170 [salt.minion      :1711][INFO    ][8143] Returning information for job: 20190524202104111072
2019-05-24 20:21:07,798 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2085.92805886s left)
2019-05-24 20:21:34,178 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202134164897
2019-05-24 20:21:34,201 [salt.minion      :1432][INFO    ][8756] Starting a new job with PID 8756
2019-05-24 20:21:34,223 [salt.minion      :1711][INFO    ][8756] Returning information for job: 20190524202134164897
2019-05-24 20:21:40,314 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2053.41216183s left)
2019-05-24 20:22:04,228 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202204215683
2019-05-24 20:22:04,251 [salt.minion      :1432][INFO    ][8786] Starting a new job with PID 8786
2019-05-24 20:22:04,273 [salt.minion      :1711][INFO    ][8786] Returning information for job: 20190524202204215683
2019-05-24 20:22:12,866 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2020.8598628s left)
2019-05-24 20:22:34,287 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202234275037
2019-05-24 20:22:34,311 [salt.minion      :1432][INFO    ][8859] Starting a new job with PID 8859
2019-05-24 20:22:34,332 [salt.minion      :1711][INFO    ][8859] Returning information for job: 20190524202234275037
2019-05-24 20:22:45,087 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1988.63863397s left)
2019-05-24 20:23:04,346 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202304336817
2019-05-24 20:23:04,364 [salt.minion      :1432][INFO    ][8898] Starting a new job with PID 8898
2019-05-24 20:23:04,374 [salt.minion      :1711][INFO    ][8898] Returning information for job: 20190524202304336817
2019-05-24 20:23:17,388 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1956.337569s left)
2019-05-24 20:23:34,395 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202334383340
2019-05-24 20:23:34,418 [salt.minion      :1432][INFO    ][9418] Starting a new job with PID 9418
2019-05-24 20:23:34,438 [salt.minion      :1711][INFO    ][9418] Returning information for job: 20190524202334383340
2019-05-24 20:23:49,889 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1923.83667088s left)
2019-05-24 20:24:04,468 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202404455227
2019-05-24 20:24:04,492 [salt.minion      :1432][INFO    ][9468] Starting a new job with PID 9468
2019-05-24 20:24:04,513 [salt.minion      :1711][INFO    ][9468] Returning information for job: 20190524202404455227
2019-05-24 20:24:22,394 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1891.33231378s left)
2019-05-24 20:24:34,541 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202434528883
2019-05-24 20:24:34,564 [salt.minion      :1432][INFO    ][9731] Starting a new job with PID 9731
2019-05-24 20:24:34,587 [salt.minion      :1711][INFO    ][9731] Returning information for job: 20190524202434528883
2019-05-24 20:24:55,064 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1858.6616559s left)
2019-05-24 20:25:04,631 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202504618026
2019-05-24 20:25:04,652 [salt.minion      :1432][INFO    ][9771] Starting a new job with PID 9771
2019-05-24 20:25:04,676 [salt.minion      :1711][INFO    ][9771] Returning information for job: 20190524202504618026
2019-05-24 20:25:27,463 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1826.26261687s left)
2019-05-24 20:25:34,724 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202534710899
2019-05-24 20:25:34,747 [salt.minion      :1432][INFO    ][9890] Starting a new job with PID 9890
2019-05-24 20:25:34,767 [salt.minion      :1711][INFO    ][9890] Returning information for job: 20190524202534710899
2019-05-24 20:25:59,825 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1793.90042591s left)
2019-05-24 20:26:04,887 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202604878950
2019-05-24 20:26:04,903 [salt.minion      :1432][INFO    ][10031] Starting a new job with PID 10031
2019-05-24 20:26:04,917 [salt.minion      :1711][INFO    ][10031] Returning information for job: 20190524202604878950
2019-05-24 20:26:32,023 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1761.70325994s left)
2019-05-24 20:26:34,968 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202634956220
2019-05-24 20:26:34,991 [salt.minion      :1432][INFO    ][10284] Starting a new job with PID 10284
2019-05-24 20:26:35,012 [salt.minion      :1711][INFO    ][10284] Returning information for job: 20190524202634956220
2019-05-24 20:27:04,221 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1729.50446081s left)
2019-05-24 20:27:05,077 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202705064285
2019-05-24 20:27:05,100 [salt.minion      :1432][INFO    ][10347] Starting a new job with PID 10347
2019-05-24 20:27:05,122 [salt.minion      :1711][INFO    ][10347] Returning information for job: 20190524202705064285
2019-05-24 20:27:35,177 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202735165033
2019-05-24 20:27:35,201 [salt.minion      :1432][INFO    ][10383] Starting a new job with PID 10383
2019-05-24 20:27:35,225 [salt.minion      :1711][INFO    ][10383] Returning information for job: 20190524202735165033
2019-05-24 20:27:36,695 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1697.03081989s left)
2019-05-24 20:28:05,307 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202805295896
2019-05-24 20:28:05,329 [salt.minion      :1432][INFO    ][10432] Starting a new job with PID 10432
2019-05-24 20:28:05,350 [salt.minion      :1711][INFO    ][10432] Returning information for job: 20190524202805295896
2019-05-24 20:28:09,174 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1664.55145383s left)
2019-05-24 20:28:35,437 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202835424831
2019-05-24 20:28:35,460 [salt.minion      :1432][INFO    ][10452] Starting a new job with PID 10452
2019-05-24 20:28:35,482 [salt.minion      :1711][INFO    ][10452] Returning information for job: 20190524202835424831
2019-05-24 20:28:41,689 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1632.03684878s left)
2019-05-24 20:29:05,577 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202905564723
2019-05-24 20:29:05,599 [salt.minion      :1432][INFO    ][10504] Starting a new job with PID 10504
2019-05-24 20:29:05,623 [salt.minion      :1711][INFO    ][10504] Returning information for job: 20190524202905564723
2019-05-24 20:29:14,085 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1599.64100385s left)
2019-05-24 20:29:35,735 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524202935719371
2019-05-24 20:29:35,759 [salt.minion      :1432][INFO    ][10524] Starting a new job with PID 10524
2019-05-24 20:29:35,782 [salt.minion      :1711][INFO    ][10524] Returning information for job: 20190524202935719371
2019-05-24 20:29:46,570 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1567.15601897s left)
2019-05-24 20:30:05,899 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203005886300
2019-05-24 20:30:05,923 [salt.minion      :1432][INFO    ][10583] Starting a new job with PID 10583
2019-05-24 20:30:05,947 [salt.minion      :1711][INFO    ][10583] Returning information for job: 20190524203005886300
2019-05-24 20:30:19,061 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1534.66472888s left)
2019-05-24 20:30:36,077 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203036060964
2019-05-24 20:30:36,100 [salt.minion      :1432][INFO    ][10605] Starting a new job with PID 10605
2019-05-24 20:30:36,122 [salt.minion      :1711][INFO    ][10605] Returning information for job: 20190524203036060964
2019-05-24 20:30:51,588 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1502.13777781s left)
2019-05-24 20:31:06,260 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203106244477
2019-05-24 20:31:06,283 [salt.minion      :1432][INFO    ][10663] Starting a new job with PID 10663
2019-05-24 20:31:06,305 [salt.minion      :1711][INFO    ][10663] Returning information for job: 20190524203106244477
2019-05-24 20:31:23,947 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1469.77850485s left)
2019-05-24 20:31:36,444 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203136435032
2019-05-24 20:31:36,464 [salt.minion      :1432][INFO    ][10683] Starting a new job with PID 10683
2019-05-24 20:31:36,486 [salt.minion      :1711][INFO    ][10683] Returning information for job: 20190524203136435032
2019-05-24 20:31:56,373 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1437.35331297s left)
2019-05-24 20:32:06,635 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203206622825
2019-05-24 20:32:06,658 [salt.minion      :1432][INFO    ][10738] Starting a new job with PID 10738
2019-05-24 20:32:06,680 [salt.minion      :1711][INFO    ][10738] Returning information for job: 20190524203206622825
2019-05-24 20:32:29,020 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1404.70545387s left)
2019-05-24 20:32:36,847 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203236832265
2019-05-24 20:32:36,870 [salt.minion      :1432][INFO    ][10757] Starting a new job with PID 10757
2019-05-24 20:32:36,893 [salt.minion      :1711][INFO    ][10757] Returning information for job: 20190524203236832265
2019-05-24 20:33:01,550 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1372.175946s left)
2019-05-24 20:33:07,064 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203307050858
2019-05-24 20:33:07,087 [salt.minion      :1432][INFO    ][10946] Starting a new job with PID 10946
2019-05-24 20:33:07,110 [salt.minion      :1711][INFO    ][10946] Returning information for job: 20190524203307050858
2019-05-24 20:33:33,844 [salt.loaded.ext.module.maas:1023][INFO    ][7671] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1339.88175893s left)
2019-05-24 20:33:37,084 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203337071646
2019-05-24 20:33:37,108 [salt.minion      :1432][INFO    ][10982] Starting a new job with PID 10982
2019-05-24 20:33:37,131 [salt.minion      :1711][INFO    ][10982] Returning information for job: 20190524203337071646
2019-05-24 20:34:06,023 [salt.loaded.ext.module.maas:993 ][INFO    ][7671] Machine mgkwcg mark broken
2019-05-24 20:34:06,713 [salt.loaded.ext.module.maas:996 ][INFO    ][7671] Machine mgkwcg mark fixed
2019-05-24 20:34:07,112 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203407099570
2019-05-24 20:34:07,135 [salt.minion      :1432][INFO    ][11047] Starting a new job with PID 11047
2019-05-24 20:34:07,157 [salt.minion      :1711][INFO    ][11047] Returning information for job: 20190524203407099570
2019-05-24 20:34:07,814 [salt.loaded.ext.module.maas:684 ][INFO    ][7671] deploymachines hwe_kernel=hwe-16.04 system_id=mgkwcg distro_series=xenial
2019-05-24 20:34:10,621 [salt.loaded.ext.module.maas:160 ][ERROR   ][7671] Failed for object ctl01 reason Unable to change power state to 'cycle' for node ctl01: another action is already in progress for that node.
2019-05-24 20:34:10,623 [salt.state       :302 ][ERROR   ][7671] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['gtw01', 'cmp002', 'cmp001'], 'errors': {'ctl01': "Unable to change power state to 'cycle' for node ctl01: another action is already in progress for that node."}, 'success': []}
2019-05-24 20:34:10,624 [salt.state       :1951][INFO    ][7671] Completed state [maas.wait_for_machine_status] at time 20:34:10.624114 duration_in_ms=946902.345
2019-05-24 20:34:10,633 [salt.minion      :1711][INFO    ][7671] Returning information for job: 20190524201818765915
2019-05-24 20:34:21,410 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command pillar.get with jid 20190524203421399072
2019-05-24 20:34:21,431 [salt.minion      :1432][INFO    ][11109] Starting a new job with PID 11109
2019-05-24 20:34:21,439 [salt.minion      :1711][INFO    ][11109] Returning information for job: 20190524203421399072
2019-05-24 20:34:21,989 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command service.status with jid 20190524203421977530
2019-05-24 20:34:22,009 [salt.minion      :1432][INFO    ][11114] Starting a new job with PID 11114
2019-05-24 20:34:22,338 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11114] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:22,370 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11114] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-24 20:34:22,385 [salt.minion      :1711][INFO    ][11114] Returning information for job: 20190524203421977530
2019-05-24 20:34:22,933 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524203422919648
2019-05-24 20:34:22,955 [salt.minion      :1432][INFO    ][11125] Starting a new job with PID 11125
2019-05-24 20:34:26,624 [salt.state       :915 ][INFO    ][11125] Loading fresh modules for state activity
2019-05-24 20:34:27,020 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'salt-minion --version' in directory '/root'
2019-05-24 20:34:27,315 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'salt-minion --version' in directory '/root'
2019-05-24 20:34:28,136 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'salt-minion --version' in directory '/root'
2019-05-24 20:34:28,497 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'salt-minion --version' in directory '/root'
2019-05-24 20:34:29,999 [salt.state       :1780][INFO    ][11125] Running state [salt-minion] at time 20:34:29.999621
2019-05-24 20:34:29,999 [salt.state       :1813][INFO    ][11125] Executing state pkg.installed for [salt-minion]
2019-05-24 20:34:30,000 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-24 20:34:30,086 [salt.state       :300 ][INFO    ][11125] All specified packages are already installed
2019-05-24 20:34:30,086 [salt.state       :1951][INFO    ][11125] Completed state [salt-minion] at time 20:34:30.086565 duration_in_ms=86.943
2019-05-24 20:34:30,086 [salt.state       :1780][INFO    ][11125] Running state [salt_minion_dependency_packages] at time 20:34:30.086910
2019-05-24 20:34:30,087 [salt.state       :1813][INFO    ][11125] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-24 20:34:30,093 [salt.state       :300 ][INFO    ][11125] All specified packages are already installed
2019-05-24 20:34:30,093 [salt.state       :1951][INFO    ][11125] Completed state [salt_minion_dependency_packages] at time 20:34:30.093915 duration_in_ms=7.005
2019-05-24 20:34:30,097 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/minion.d/minion.conf] at time 20:34:30.096956
2019-05-24 20:34:30,097 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-24 20:34:30,317 [salt.state       :300 ][INFO    ][11125] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-24 20:34:30,317 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/minion.d/minion.conf] at time 20:34:30.317923 duration_in_ms=220.967
2019-05-24 20:34:30,321 [salt.state       :1780][INFO    ][11125] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:34:30.321040
2019-05-24 20:34:30,321 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-24 20:34:30,331 [salt.state       :300 ][INFO    ][11125] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-24 20:34:30,332 [salt.state       :1951][INFO    ][11125] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 20:34:30.332181 duration_in_ms=11.14
2019-05-24 20:34:30,333 [salt.state       :1780][INFO    ][11125] Running state [salt-minion] at time 20:34:30.333145
2019-05-24 20:34:30,333 [salt.state       :1813][INFO    ][11125] Executing state service.running for [salt-minion]
2019-05-24 20:34:30,334 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:30,373 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-24 20:34:30,392 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-24 20:34:30,411 [salt.state       :300 ][INFO    ][11125] The service salt-minion is already running
2019-05-24 20:34:30,411 [salt.state       :1951][INFO    ][11125] Completed state [salt-minion] at time 20:34:30.411751 duration_in_ms=78.604
2019-05-24 20:34:30,414 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains.d] at time 20:34:30.414175
2019-05-24 20:34:30,414 [salt.state       :1813][INFO    ][11125] Executing state file.directory for [/etc/salt/grains.d]
2019-05-24 20:34:30,416 [salt.state       :300 ][INFO    ][11125] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-24 20:34:30,416 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains.d] at time 20:34:30.416532 duration_in_ms=2.356
2019-05-24 20:34:30,417 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains] at time 20:34:30.417571
2019-05-24 20:34:30,418 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/grains]
2019-05-24 20:34:30,418 [salt.state       :300 ][INFO    ][11125] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-24 20:34:30,419 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains] at time 20:34:30.419131 duration_in_ms=1.56
2019-05-24 20:34:30,419 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains.d/placeholder] at time 20:34:30.419809
2019-05-24 20:34:30,420 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-24 20:34:30,421 [salt.state       :300 ][INFO    ][11125] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-24 20:34:30,421 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains.d/placeholder] at time 20:34:30.421288 duration_in_ms=1.479
2019-05-24 20:34:30,422 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains.d/sphinx] at time 20:34:30.421981
2019-05-24 20:34:30,422 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-24 20:34:30,437 [salt.state       :300 ][INFO    ][11125] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-24 20:34:30,438 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains.d/sphinx] at time 20:34:30.437993 duration_in_ms=16.012
2019-05-24 20:34:30,441 [salt.state       :1780][INFO    ][11125] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.441193
2019-05-24 20:34:30,441 [salt.state       :1813][INFO    ][11125] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-24 20:34:30,442 [salt.state       :300 ][INFO    ][11125] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-24 20:34:30,442 [salt.state       :1951][INFO    ][11125] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.442435 duration_in_ms=1.241
2019-05-24 20:34:30,443 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains.d/dns_records] at time 20:34:30.443139
2019-05-24 20:34:30,443 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-24 20:34:30,455 [salt.state       :300 ][INFO    ][11125] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-24 20:34:30,455 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains.d/dns_records] at time 20:34:30.455825 duration_in_ms=12.686
2019-05-24 20:34:30,457 [salt.state       :1780][INFO    ][11125] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.457185
2019-05-24 20:34:30,457 [salt.state       :1813][INFO    ][11125] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-24 20:34:30,458 [salt.state       :300 ][INFO    ][11125] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-24 20:34:30,458 [salt.state       :1951][INFO    ][11125] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.458441 duration_in_ms=1.256
2019-05-24 20:34:30,459 [salt.state       :1780][INFO    ][11125] Running state [/etc/salt/grains.d/salt] at time 20:34:30.459141
2019-05-24 20:34:30,459 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-24 20:34:30,473 [salt.state       :300 ][INFO    ][11125] File /etc/salt/grains.d/salt is in the correct state
2019-05-24 20:34:30,473 [salt.state       :1951][INFO    ][11125] Completed state [/etc/salt/grains.d/salt] at time 20:34:30.473825 duration_in_ms=14.683
2019-05-24 20:34:30,475 [salt.state       :1780][INFO    ][11125] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.475135
2019-05-24 20:34:30,475 [salt.state       :1813][INFO    ][11125] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-24 20:34:30,476 [salt.state       :300 ][INFO    ][11125] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-24 20:34:30,476 [salt.state       :1951][INFO    ][11125] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 20:34:30.476375 duration_in_ms=1.24
2019-05-24 20:34:30,479 [salt.state       :1780][INFO    ][11125] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:34:30.479214
2019-05-24 20:34:30,479 [salt.state       :1813][INFO    ][11125] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-24 20:34:30,480 [salt.state       :300 ][INFO    ][11125] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-24 20:34:30,480 [salt.state       :1951][INFO    ][11125] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 20:34:30.480457 duration_in_ms=1.242
2019-05-24 20:34:30,481 [salt.state       :1780][INFO    ][11125] Running state [mine.update] at time 20:34:30.481460
2019-05-24 20:34:30,481 [salt.state       :1813][INFO    ][11125] Executing state module.wait for [mine.update]
2019-05-24 20:34:30,482 [salt.state       :300 ][INFO    ][11125] No changes made for mine.update
2019-05-24 20:34:30,482 [salt.state       :1951][INFO    ][11125] Completed state [mine.update] at time 20:34:30.482625 duration_in_ms=1.165
2019-05-24 20:34:30,483 [salt.state       :1780][INFO    ][11125] Running state [ca-certificates] at time 20:34:30.482975
2019-05-24 20:34:30,483 [salt.state       :1813][INFO    ][11125] Executing state pkg.installed for [ca-certificates]
2019-05-24 20:34:30,494 [salt.state       :300 ][INFO    ][11125] All specified packages are already installed
2019-05-24 20:34:30,494 [salt.state       :1951][INFO    ][11125] Completed state [ca-certificates] at time 20:34:30.494284 duration_in_ms=11.309
2019-05-24 20:34:30,495 [salt.state       :1780][INFO    ][11125] Running state [update-ca-certificates] at time 20:34:30.495684
2019-05-24 20:34:30,496 [salt.state       :1813][INFO    ][11125] Executing state cmd.wait for [update-ca-certificates]
2019-05-24 20:34:30,496 [salt.state       :300 ][INFO    ][11125] No changes made for update-ca-certificates
2019-05-24 20:34:30,496 [salt.state       :1951][INFO    ][11125] Completed state [update-ca-certificates] at time 20:34:30.496788 duration_in_ms=1.104
2019-05-24 20:34:30,497 [salt.state       :1780][INFO    ][11125] Running state [iptables] at time 20:34:30.497108
2019-05-24 20:34:30,497 [salt.state       :1813][INFO    ][11125] Executing state pkg.installed for [iptables]
2019-05-24 20:34:30,506 [salt.state       :300 ][INFO    ][11125] All specified packages are already installed
2019-05-24 20:34:30,506 [salt.state       :1951][INFO    ][11125] Completed state [iptables] at time 20:34:30.506844 duration_in_ms=9.735
2019-05-24 20:34:30,507 [salt.state       :1780][INFO    ][11125] Running state [iptables-persistent] at time 20:34:30.507165
2019-05-24 20:34:30,507 [salt.state       :1813][INFO    ][11125] Executing state pkg.installed for [iptables-persistent]
2019-05-24 20:34:30,516 [salt.state       :300 ][INFO    ][11125] All specified packages are already installed
2019-05-24 20:34:30,516 [salt.state       :1951][INFO    ][11125] Completed state [iptables-persistent] at time 20:34:30.516619 duration_in_ms=9.453
2019-05-24 20:34:30,517 [salt.state       :1780][INFO    ][11125] Running state [iptables_modules_v4_load] at time 20:34:30.517830
2019-05-24 20:34:30,518 [salt.state       :1813][INFO    ][11125] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-24 20:34:30,518 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'lsmod' in directory '/root'
2019-05-24 20:34:30,542 [salt.state       :300 ][INFO    ][11125] Kernel modules iptable_filter, ip_tables are already present
2019-05-24 20:34:30,543 [salt.state       :1951][INFO    ][11125] Completed state [iptables_modules_v4_load] at time 20:34:30.543143 duration_in_ms=25.313
2019-05-24 20:34:30,543 [salt.state       :1780][INFO    ][11125] Running state [/etc/iptables/rules.v4] at time 20:34:30.543930
2019-05-24 20:34:30,544 [salt.state       :1813][INFO    ][11125] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-24 20:34:30,647 [salt.state       :300 ][INFO    ][11125] File /etc/iptables/rules.v4 is in the correct state
2019-05-24 20:34:30,647 [salt.state       :1951][INFO    ][11125] Completed state [/etc/iptables/rules.v4] at time 20:34:30.647474 duration_in_ms=103.544
2019-05-24 20:34:30,648 [salt.state       :1780][INFO    ][11125] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:34:30.648531
2019-05-24 20:34:30,648 [salt.state       :1813][INFO    ][11125] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-24 20:34:30,649 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-24 20:34:30,671 [salt.state       :300 ][INFO    ][11125] onlyif execution failed
2019-05-24 20:34:30,671 [salt.state       :1951][INFO    ][11125] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 20:34:30.671693 duration_in_ms=23.159
2019-05-24 20:34:30,673 [salt.state       :1780][INFO    ][11125] Running state [netfilter-persistent] at time 20:34:30.673298
2019-05-24 20:34:30,673 [salt.state       :1813][INFO    ][11125] Executing state service.running for [netfilter-persistent]
2019-05-24 20:34:30,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:30,697 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-24 20:34:30,716 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-24 20:34:30,734 [salt.state       :300 ][INFO    ][11125] The service netfilter-persistent is already running
2019-05-24 20:34:30,735 [salt.state       :1951][INFO    ][11125] Completed state [netfilter-persistent] at time 20:34:30.735428 duration_in_ms=62.13
2019-05-24 20:34:30,736 [salt.state       :1780][INFO    ][11125] Running state [iptables_extra.remove_stale_tables] at time 20:34:30.736716
2019-05-24 20:34:30,737 [salt.state       :1813][INFO    ][11125] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-24 20:34:30,737 [salt.state       :300 ][INFO    ][11125] No changes made for iptables_extra.remove_stale_tables
2019-05-24 20:34:30,738 [salt.state       :1951][INFO    ][11125] Completed state [iptables_extra.remove_stale_tables] at time 20:34:30.738073 duration_in_ms=1.358
2019-05-24 20:34:30,738 [salt.state       :1780][INFO    ][11125] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:34:30.738441
2019-05-24 20:34:30,738 [salt.state       :1813][INFO    ][11125] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-24 20:34:30,739 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11125] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-24 20:34:30,755 [salt.state       :300 ][INFO    ][11125] onlyif execution failed
2019-05-24 20:34:30,755 [salt.state       :1951][INFO    ][11125] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 20:34:30.755829 duration_in_ms=17.389
2019-05-24 20:34:30,757 [salt.state       :1780][INFO    ][11125] Running state [/etc/iptables/rules.v6] at time 20:34:30.757195
2019-05-24 20:34:30,757 [salt.state       :1813][INFO    ][11125] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-24 20:34:30,758 [salt.state       :300 ][INFO    ][11125] File /etc/iptables/rules.v6 is not present
2019-05-24 20:34:30,758 [salt.state       :1951][INFO    ][11125] Completed state [/etc/iptables/rules.v6] at time 20:34:30.758655 duration_in_ms=1.46
2019-05-24 20:34:30,759 [salt.state       :1780][INFO    ][11125] Running state [iptables_extra.flush_all] at time 20:34:30.759631
2019-05-24 20:34:30,760 [salt.state       :1813][INFO    ][11125] Executing state module.wait for [iptables_extra.flush_all]
2019-05-24 20:34:30,760 [salt.state       :300 ][INFO    ][11125] No changes made for iptables_extra.flush_all
2019-05-24 20:34:30,760 [salt.state       :1951][INFO    ][11125] Completed state [iptables_extra.flush_all] at time 20:34:30.760759 duration_in_ms=1.129
2019-05-24 20:34:30,796 [salt.minion      :1711][INFO    ][11125] Returning information for job: 20190524203422919648
2019-05-24 20:34:31,440 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524203431426832
2019-05-24 20:34:31,463 [salt.minion      :1432][INFO    ][11214] Starting a new job with PID 11214
2019-05-24 20:34:32,179 [salt.state       :915 ][INFO    ][11214] Loading fresh modules for state activity
2019-05-24 20:34:32,795 [salt.state       :1780][INFO    ][11214] Running state [maas-rack-controller] at time 20:34:32.795689
2019-05-24 20:34:32,796 [salt.state       :1813][INFO    ][11214] Executing state pkg.installed for [maas-rack-controller]
2019-05-24 20:34:32,796 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11214] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-24 20:34:32,891 [salt.state       :300 ][INFO    ][11214] All specified packages are already installed
2019-05-24 20:34:32,891 [salt.state       :1951][INFO    ][11214] Completed state [maas-rack-controller] at time 20:34:32.891499 duration_in_ms=95.809
2019-05-24 20:34:32,891 [salt.state       :1780][INFO    ][11214] Running state [ipmitool] at time 20:34:32.891896
2019-05-24 20:34:32,892 [salt.state       :1813][INFO    ][11214] Executing state pkg.installed for [ipmitool]
2019-05-24 20:34:32,899 [salt.state       :300 ][INFO    ][11214] All specified packages are already installed
2019-05-24 20:34:32,899 [salt.state       :1951][INFO    ][11214] Completed state [ipmitool] at time 20:34:32.899463 duration_in_ms=7.567
2019-05-24 20:34:32,902 [salt.state       :1780][INFO    ][11214] Running state [/etc/maas/rackd.conf] at time 20:34:32.902767
2019-05-24 20:34:32,903 [salt.state       :1813][INFO    ][11214] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-24 20:34:32,904 [salt.state       :300 ][INFO    ][11214] No changes needed to be made
2019-05-24 20:34:32,904 [salt.state       :1951][INFO    ][11214] Completed state [/etc/maas/rackd.conf] at time 20:34:32.904422 duration_in_ms=1.655
2019-05-24 20:34:32,904 [salt.state       :1780][INFO    ][11214] Running state [/etc/maas/rackd.conf] at time 20:34:32.904691
2019-05-24 20:34:32,904 [salt.state       :1813][INFO    ][11214] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-24 20:34:32,905 [salt.loaded.int.states.file:2298][WARNING ][11214] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-24 20:34:32,905 [salt.state       :300 ][INFO    ][11214] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-24 20:34:32,906 [salt.state       :1951][INFO    ][11214] Completed state [/etc/maas/rackd.conf] at time 20:34:32.906042 duration_in_ms=1.351
2019-05-24 20:34:32,907 [salt.state       :1780][INFO    ][11214] Running state [maas-rackd] at time 20:34:32.907048
2019-05-24 20:34:32,907 [salt.state       :1813][INFO    ][11214] Executing state service.running for [maas-rackd]
2019-05-24 20:34:32,908 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11214] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:32,942 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11214] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-24 20:34:32,960 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11214] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-24 20:34:32,976 [salt.state       :300 ][INFO    ][11214] The service maas-rackd is already running
2019-05-24 20:34:32,976 [salt.state       :1951][INFO    ][11214] Completed state [maas-rackd] at time 20:34:32.976526 duration_in_ms=69.478
2019-05-24 20:34:32,978 [salt.minion      :1711][INFO    ][11214] Returning information for job: 20190524203431426832
2019-05-24 20:34:33,611 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524203433601685
2019-05-24 20:34:33,635 [salt.minion      :1432][INFO    ][11237] Starting a new job with PID 11237
2019-05-24 20:34:34,346 [salt.state       :915 ][INFO    ][11237] Loading fresh modules for state activity
2019-05-24 20:34:35,019 [salt.state       :1780][INFO    ][11237] Running state [maas-region-controller] at time 20:34:35.019606
2019-05-24 20:34:35,019 [salt.state       :1813][INFO    ][11237] Executing state pkg.installed for [maas-region-controller]
2019-05-24 20:34:35,020 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-24 20:34:35,103 [salt.state       :300 ][INFO    ][11237] All specified packages are already installed
2019-05-24 20:34:35,103 [salt.state       :1951][INFO    ][11237] Completed state [maas-region-controller] at time 20:34:35.103857 duration_in_ms=84.25
2019-05-24 20:34:35,104 [salt.state       :1780][INFO    ][11237] Running state [python-oauth] at time 20:34:35.104160
2019-05-24 20:34:35,104 [salt.state       :1813][INFO    ][11237] Executing state pkg.installed for [python-oauth]
2019-05-24 20:34:35,110 [salt.state       :300 ][INFO    ][11237] All specified packages are already installed
2019-05-24 20:34:35,110 [salt.state       :1951][INFO    ][11237] Completed state [python-oauth] at time 20:34:35.110382 duration_in_ms=6.222
2019-05-24 20:34:35,113 [salt.state       :1780][INFO    ][11237] Running state [/etc/maas/regiond.conf] at time 20:34:35.113196
2019-05-24 20:34:35,113 [salt.state       :1813][INFO    ][11237] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-24 20:34:35,186 [salt.state       :300 ][INFO    ][11237] No changes needed to be made
2019-05-24 20:34:35,186 [salt.state       :1951][INFO    ][11237] Completed state [/etc/maas/regiond.conf] at time 20:34:35.186936 duration_in_ms=73.74
2019-05-24 20:34:35,187 [salt.state       :1780][INFO    ][11237] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:34:35.187305
2019-05-24 20:34:35,187 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-24 20:34:35,248 [salt.state       :300 ][INFO    ][11237] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-24 20:34:35,248 [salt.state       :1951][INFO    ][11237] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:34:35.248700 duration_in_ms=61.395
2019-05-24 20:34:35,249 [salt.state       :1780][INFO    ][11237] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:34:35.249109
2019-05-24 20:34:35,249 [salt.state       :1813][INFO    ][11237] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-24 20:34:35,261 [salt.state       :300 ][INFO    ][11237] No changes needed to be made
2019-05-24 20:34:35,261 [salt.state       :1951][INFO    ][11237] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:34:35.261713 duration_in_ms=12.604
2019-05-24 20:34:35,262 [salt.state       :1780][INFO    ][11237] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:34:35.262087
2019-05-24 20:34:35,262 [salt.state       :1813][INFO    ][11237] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-24 20:34:35,285 [salt.state       :300 ][INFO    ][11237] No changes needed to be made
2019-05-24 20:34:35,285 [salt.state       :1951][INFO    ][11237] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:34:35.285509 duration_in_ms=23.422
2019-05-24 20:34:35,285 [salt.state       :1780][INFO    ][11237] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:34:35.285900
2019-05-24 20:34:35,286 [salt.state       :1813][INFO    ][11237] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-24 20:34:35,304 [salt.state       :300 ][INFO    ][11237] No changes needed to be made
2019-05-24 20:34:35,304 [salt.state       :1951][INFO    ][11237] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:34:35.304857 duration_in_ms=18.957
2019-05-24 20:34:35,305 [salt.state       :1780][INFO    ][11237] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:34:35.305217
2019-05-24 20:34:35,305 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-24 20:34:35,316 [salt.state       :300 ][INFO    ][11237] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-24 20:34:35,316 [salt.state       :1951][INFO    ][11237] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:34:35.316476 duration_in_ms=11.259
2019-05-24 20:34:35,317 [salt.state       :1780][INFO    ][11237] Running state [a2enmod headers] at time 20:34:35.317492
2019-05-24 20:34:35,317 [salt.state       :1813][INFO    ][11237] Executing state cmd.run for [a2enmod headers]
2019-05-24 20:34:35,318 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command 'a2enmod headers' in directory '/root'
2019-05-24 20:34:35,389 [salt.state       :300 ][INFO    ][11237] {'pid': 11260, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-24 20:34:35,389 [salt.state       :1951][INFO    ][11237] Completed state [a2enmod headers] at time 20:34:35.389720 duration_in_ms=72.226
2019-05-24 20:34:35,390 [salt.state       :1780][INFO    ][11237] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:34:35.390212
2019-05-24 20:34:35,390 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-24 20:34:35,408 [salt.state       :300 ][INFO    ][11237] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-24 20:34:35,408 [salt.state       :1951][INFO    ][11237] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:34:35.408715 duration_in_ms=18.503
2019-05-24 20:34:35,409 [salt.state       :1780][INFO    ][11237] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:34:35.409441
2019-05-24 20:34:35,409 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-24 20:34:35,488 [salt.state       :300 ][INFO    ][11237] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-24 20:34:35,489 [salt.state       :1951][INFO    ][11237] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:34:35.489233 duration_in_ms=79.791
2019-05-24 20:34:35,490 [salt.state       :1780][INFO    ][11237] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:34:35.490078
2019-05-24 20:34:35,490 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-24 20:34:35,572 [salt.state       :300 ][INFO    ][11237] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-24 20:34:35,573 [salt.state       :1951][INFO    ][11237] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:34:35.573126 duration_in_ms=83.049
2019-05-24 20:34:35,573 [salt.state       :1780][INFO    ][11237] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:34:35.573880
2019-05-24 20:34:35,574 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-24 20:34:35,644 [salt.state       :300 ][INFO    ][11237] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-24 20:34:35,644 [salt.state       :1951][INFO    ][11237] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:34:35.644381 duration_in_ms=70.5
2019-05-24 20:34:35,644 [salt.state       :1780][INFO    ][11237] Running state [/root/.pgpass] at time 20:34:35.644702
2019-05-24 20:34:35,645 [salt.state       :1813][INFO    ][11237] Executing state file.managed for [/root/.pgpass]
2019-05-24 20:34:35,692 [salt.state       :300 ][INFO    ][11237] File /root/.pgpass is in the correct state
2019-05-24 20:34:35,692 [salt.state       :1951][INFO    ][11237] Completed state [/root/.pgpass] at time 20:34:35.692241 duration_in_ms=47.54
2019-05-24 20:34:35,697 [salt.state       :1780][INFO    ][11237] Running state [maas-region syncdb --noinput] at time 20:34:35.697368
2019-05-24 20:34:35,697 [salt.state       :1813][INFO    ][11237] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-24 20:34:35,698 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-24 20:34:37,934 [salt.state       :300 ][INFO    ][11237] {'pid': 11273, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: piston3, sessions, sites, contenttypes, metadataserver, maasserver, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-24 20:34:37,935 [salt.state       :1951][INFO    ][11237] Completed state [maas-region syncdb --noinput] at time 20:34:37.935007 duration_in_ms=2237.638
2019-05-24 20:34:37,935 [salt.state       :2022][WARNING ][11237] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-24 20:34:37,938 [salt.state       :1780][INFO    ][11237] Running state [maas-regiond] at time 20:34:37.938366
2019-05-24 20:34:37,938 [salt.state       :1813][INFO    ][11237] Executing state service.running for [maas-regiond]
2019-05-24 20:34:37,940 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:37,979 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-24 20:34:37,997 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-24 20:34:38,016 [salt.state       :300 ][INFO    ][11237] The service maas-regiond is already running
2019-05-24 20:34:38,016 [salt.state       :1951][INFO    ][11237] Completed state [maas-regiond] at time 20:34:38.016430 duration_in_ms=78.064
2019-05-24 20:34:38,018 [salt.state       :1780][INFO    ][11237] Running state [bind9] at time 20:34:38.018829
2019-05-24 20:34:38,019 [salt.state       :1813][INFO    ][11237] Executing state service.running for [bind9]
2019-05-24 20:34:38,020 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:38,039 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-24 20:34:38,056 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-24 20:34:38,073 [salt.state       :300 ][INFO    ][11237] The service bind9 is already running
2019-05-24 20:34:38,074 [salt.state       :1951][INFO    ][11237] Completed state [bind9] at time 20:34:38.074064 duration_in_ms=55.234
2019-05-24 20:34:38,076 [salt.state       :1780][INFO    ][11237] Running state [apache2] at time 20:34:38.076274
2019-05-24 20:34:38,076 [salt.state       :1813][INFO    ][11237] Executing state service.running for [apache2]
2019-05-24 20:34:38,077 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-24 20:34:38,096 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-24 20:34:38,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-24 20:34:38,131 [salt.state       :300 ][INFO    ][11237] The service apache2 is already running
2019-05-24 20:34:38,132 [salt.state       :1951][INFO    ][11237] Completed state [apache2] at time 20:34:38.132239 duration_in_ms=55.966
2019-05-24 20:34:38,134 [salt.state       :1780][INFO    ][11237] Running state [maasng.wait_for_http_code] at time 20:34:38.134372
2019-05-24 20:34:38,134 [salt.state       :1813][INFO    ][11237] Executing state module.run for [maasng.wait_for_http_code]
2019-05-24 20:34:38,135 [salt.utils.decorators:613 ][WARNING ][11237] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:34:38,264 [salt.state       :300 ][INFO    ][11237] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-24 20:34:38,265 [salt.state       :1951][INFO    ][11237] Completed state [maasng.wait_for_http_code] at time 20:34:38.265343 duration_in_ms=130.97
2019-05-24 20:34:38,266 [salt.state       :1780][INFO    ][11237] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:34:38.266534
2019-05-24 20:34:38,266 [salt.state       :1813][INFO    ][11237] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-24 20:34:38,267 [salt.state       :300 ][INFO    ][11237] /var/lib/maas/.setup_admin exists
2019-05-24 20:34:38,267 [salt.state       :1951][INFO    ][11237] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:34:38.267808 duration_in_ms=1.273
2019-05-24 20:34:38,268 [salt.state       :1780][INFO    ][11237] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:34:38.268677
2019-05-24 20:34:38,269 [salt.state       :1813][INFO    ][11237] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:34:38,269 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11237] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:34:39,818 [salt.state       :300 ][INFO    ][11237] {'pid': 11294, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:34:39,819 [salt.state       :1951][INFO    ][11237] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:34:39.819402 duration_in_ms=1550.724
2019-05-24 20:34:39,827 [salt.state       :1780][INFO    ][11237] Running state [maas_region_boot_source_resources_mirror] at time 20:34:39.827841
2019-05-24 20:34:39,828 [salt.state       :1813][INFO    ][11237] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-24 20:34:39,925 [salt.state       :300 ][INFO    ][11237] {'changes': {}}
2019-05-24 20:34:39,925 [salt.state       :1951][INFO    ][11237] Completed state [maas_region_boot_source_resources_mirror] at time 20:34:39.925448 duration_in_ms=97.607
2019-05-24 20:34:39,926 [salt.state       :1780][INFO    ][11237] Running state [maasng.boot_resources_import] at time 20:34:39.926740
2019-05-24 20:34:39,927 [salt.state       :1813][INFO    ][11237] Executing state module.run for [maasng.boot_resources_import]
2019-05-24 20:34:39,927 [salt.utils.decorators:613 ][WARNING ][11237] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:34:40,045 [salt.loaded.ext.module.maasng:1600][INFO    ][11237] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-24 20:34:45,111 [salt.loaded.ext.module.maasng:1600][INFO    ][11237] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-24 20:34:48,729 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203448716336
2019-05-24 20:34:48,750 [salt.minion      :1432][INFO    ][11320] Starting a new job with PID 11320
2019-05-24 20:34:48,771 [salt.minion      :1711][INFO    ][11320] Returning information for job: 20190524203448716336
2019-05-24 20:34:50,165 [salt.loaded.ext.module.maasng:1600][INFO    ][11237] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-24 20:34:55,278 [salt.state       :300 ][INFO    ][11237] {'ret': True}
2019-05-24 20:34:55,279 [salt.state       :1951][INFO    ][11237] Completed state [maasng.boot_resources_import] at time 20:34:55.279317 duration_in_ms=15352.576
2019-05-24 20:34:55,280 [salt.state       :1780][INFO    ][11237] Running state [maas_region_boot_sources_selection_xenial] at time 20:34:55.280550
2019-05-24 20:34:55,281 [salt.state       :1813][INFO    ][11237] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-24 20:34:55,481 [salt.state       :300 ][INFO    ][11237] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-24 20:34:55,482 [salt.state       :1951][INFO    ][11237] Completed state [maas_region_boot_sources_selection_xenial] at time 20:34:55.482192 duration_in_ms=201.642
2019-05-24 20:34:55,483 [salt.state       :1780][INFO    ][11237] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:34:55.483429
2019-05-24 20:34:55,483 [salt.state       :1813][INFO    ][11237] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-24 20:34:55,484 [salt.utils.decorators:613 ][WARNING ][11237] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:34:55,485 [salt.loaded.ext.module.maasng:1771][INFO    ][11237] boot-sources sync initiated for ALL Rack's
2019-05-24 20:34:56,613 [salt.state       :300 ][INFO    ][11237] {'ret': True}
2019-05-24 20:34:56,614 [salt.state       :1951][INFO    ][11237] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:34:56.614101 duration_in_ms=1130.671
2019-05-24 20:34:56,616 [salt.state       :1780][INFO    ][11237] Running state [maas.process_maas_config] at time 20:34:56.616246
2019-05-24 20:34:56,616 [salt.state       :1813][INFO    ][11237] Executing state module.run for [maas.process_maas_config]
2019-05-24 20:34:56,617 [salt.utils.decorators:613 ][WARNING ][11237] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:34:56,618 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=enable_http_proxy value=True
2019-05-24 20:34:56,678 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=upstream_dns value=8.8.8.8
2019-05-24 20:34:56,740 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=commissioning_distro_series value=xenial
2019-05-24 20:34:56,805 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=default_osystem value=ubuntu
2019-05-24 20:34:56,865 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=active_discovery_interval value=600
2019-05-24 20:34:56,925 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=dnssec_validation value=no
2019-05-24 20:34:56,979 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=maas_name value=mas01
2019-05-24 20:34:57,033 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=network_discovery value=enabled
2019-05-24 20:34:57,153 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=enable_third_party_drivers value=True
2019-05-24 20:34:57,221 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=default_storage_layout value=lvm
2019-05-24 20:34:57,281 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=ntp_external_only value=True
2019-05-24 20:34:59,578 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-24 20:34:59,640 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=default_distro_series value=xenial
2019-05-24 20:34:59,722 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-24 20:34:59,818 [salt.state       :300 ][INFO    ][11237] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-24 20:34:59,818 [salt.state       :1951][INFO    ][11237] Completed state [maas.process_maas_config] at time 20:34:59.818508 duration_in_ms=3202.262
2019-05-24 20:34:59,819 [salt.state       :1780][INFO    ][11237] Running state [pxe_admin] at time 20:34:59.819442
2019-05-24 20:34:59,819 [salt.state       :1813][INFO    ][11237] Executing state maasng.fabric_present for [pxe_admin]
2019-05-24 20:34:59,877 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-24 20:34:59,968 [salt.loaded.ext.module.maasng:1008][WARNING ][11237] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-24 20:34:59,969 [salt.loaded.ext.module.maasng:1011][WARNING ][11237] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-24 20:35:00,052 [salt.state       :300 ][INFO    ][11237] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-24 20:35:00,053 [salt.state       :1951][INFO    ][11237] Completed state [pxe_admin] at time 20:35:00.052985 duration_in_ms=233.542
2019-05-24 20:35:00,053 [salt.state       :1780][INFO    ][11237] Running state [vlan 0] at time 20:35:00.053359
2019-05-24 20:35:00,053 [salt.state       :1813][INFO    ][11237] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-24 20:35:00,130 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-24 20:35:00,244 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4afd78', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-24 20:35:00,543 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-24 20:35:00,644 [salt.state       :300 ][INFO    ][11237] {'new': 'Vlan untagged was updated'}
2019-05-24 20:35:00,644 [salt.state       :1951][INFO    ][11237] Completed state [vlan 0] at time 20:35:00.644830 duration_in_ms=591.47
2019-05-24 20:35:00,646 [salt.state       :1780][INFO    ][11237] Running state [192.168.11.0/24] at time 20:35:00.646513
2019-05-24 20:35:00,647 [salt.state       :1813][INFO    ][11237] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-24 20:35:00,862 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-24 20:35:00,863 [salt.loaded.ext.module.maasng:1235][WARNING ][11237] Ignoring parameter vlan:0
2019-05-24 20:35:00,944 [salt.state       :300 ][INFO    ][11237] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-24 20:35:00,945 [salt.state       :1951][INFO    ][11237] Completed state [192.168.11.0/24] at time 20:35:00.945082 duration_in_ms=298.569
2019-05-24 20:35:00,946 [salt.state       :1780][INFO    ][11237] Running state [maas_create_iprange_1] at time 20:35:00.946398
2019-05-24 20:35:00,946 [salt.state       :1813][INFO    ][11237] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-24 20:35:01,000 [salt.state       :300 ][INFO    ][11237] Iprange maas_create_iprange_1 already exist.
2019-05-24 20:35:01,000 [salt.state       :1951][INFO    ][11237] Completed state [maas_create_iprange_1] at time 20:35:01.000561 duration_in_ms=54.162
2019-05-24 20:35:01,001 [salt.state       :1780][INFO    ][11237] Running state [vlan 0] at time 20:35:01.001165
2019-05-24 20:35:01,001 [salt.state       :1813][INFO    ][11237] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-24 20:35:01,059 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'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'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'4afd78', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-24 20:35:01,203 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'4afd78', 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-05-24 20:35:01,477 [salt.loaded.ext.module.maasng:945 ][INFO    ][11237] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4afd78', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-24 20:35:01,567 [salt.state       :300 ][INFO    ][11237] {'new': 'Vlan untagged was updated'}
2019-05-24 20:35:01,567 [salt.state       :1951][INFO    ][11237] Completed state [vlan 0] at time 20:35:01.567791 duration_in_ms=566.626
2019-05-24 20:35:01,568 [salt.state       :1780][INFO    ][11237] Running state [opnfv] at time 20:35:01.568689
2019-05-24 20:35:01,569 [salt.state       :1813][INFO    ][11237] Executing state maasng.sshkey_present for [opnfv]
2019-05-24 20:35:01,608 [salt.loaded.ext.module.maasng:1903][INFO    ][11237] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-24 20:35:01,608 [salt.state       :300 ][INFO    ][11237] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-24 20:35:01,609 [salt.state       :1951][INFO    ][11237] Completed state [opnfv] at time 20:35:01.609185 duration_in_ms=40.496
2019-05-24 20:35:01,610 [salt.state       :1780][INFO    ][11237] Running state [maas.process_tags] at time 20:35:01.609975
2019-05-24 20:35:01,610 [salt.state       :1813][INFO    ][11237] Executing state module.run for [maas.process_tags]
2019-05-24 20:35:01,610 [salt.utils.decorators:613 ][WARNING ][11237] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:35:01,662 [salt.loaded.ext.module.maas:92  ][INFO    ][11237] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-24 20:35:01,716 [salt.state       :300 ][INFO    ][11237] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-24 20:35:01,717 [salt.state       :1951][INFO    ][11237] Completed state [maas.process_tags] at time 20:35:01.717356 duration_in_ms=107.38
2019-05-24 20:35:01,721 [salt.minion      :1711][INFO    ][11237] Returning information for job: 20190524203433601685
2019-05-24 20:35:02,219 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524203502203261
2019-05-24 20:35:02,238 [salt.minion      :1432][INFO    ][11692] Starting a new job with PID 11692
2019-05-24 20:35:06,042 [salt.state       :915 ][INFO    ][11692] Loading fresh modules for state activity
2019-05-24 20:35:06,134 [salt.state       :1780][INFO    ][11692] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:35:06.134256
2019-05-24 20:35:06,134 [salt.state       :1813][INFO    ][11692] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:35:06,136 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11692] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:35:07,585 [salt.state       :300 ][INFO    ][11692] {'pid': 11745, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:35:07,585 [salt.state       :1951][INFO    ][11692] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:35:07.585631 duration_in_ms=1451.376
2019-05-24 20:35:07,586 [salt.state       :1780][INFO    ][11692] Running state [maas.process_machines] at time 20:35:07.586767
2019-05-24 20:35:07,587 [salt.state       :1813][INFO    ][11692] Executing state module.run for [maas.process_machines]
2019-05-24 20:35:07,587 [salt.utils.decorators:613 ][WARNING ][11692] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:35:08,172 [salt.loaded.ext.module.maas:412 ][WARNING ][11692] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:35:08,173 [salt.loaded.ext.module.maas:92  ][INFO    ][11692] machine hostname=gtw01 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=trfehe architecture=amd64/generic power_parameters_power_user=admin
2019-05-24 20:35:09,310 [salt.loaded.ext.module.maas:412 ][WARNING ][11692] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:35:09,311 [salt.loaded.ext.module.maas:92  ][INFO    ][11692] 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=mgykgf architecture=amd64/generic power_parameters_power_user=admin
2019-05-24 20:35:10,385 [salt.loaded.ext.module.maas:412 ][WARNING ][11692] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:35:10,386 [salt.loaded.ext.module.maas:92  ][INFO    ][11692] 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=aahqhg architecture=amd64/generic power_parameters_power_user=admin
2019-05-24 20:35:11,614 [salt.loaded.ext.module.maas:412 ][WARNING ][11692] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-24 20:35:11,615 [salt.loaded.ext.module.maas:92  ][INFO    ][11692] machine hostname=ctl01 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=mgkwcg architecture=amd64/generic power_parameters_power_user=admin
2019-05-24 20:35:12,883 [salt.state       :300 ][INFO    ][11692] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-05-24 20:35:12,883 [salt.state       :1951][INFO    ][11692] Completed state [maas.process_machines] at time 20:35:12.883738 duration_in_ms=5296.968
2019-05-24 20:35:12,887 [salt.minion      :1711][INFO    ][11692] Returning information for job: 20190524203502203261
2019-05-24 20:35:45,673 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524203545660208
2019-05-24 20:35:45,697 [salt.minion      :1432][INFO    ][11930] Starting a new job with PID 11930
2019-05-24 20:35:49,257 [salt.state       :915 ][INFO    ][11930] Loading fresh modules for state activity
2019-05-24 20:35:49,307 [salt.state       :1780][INFO    ][11930] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:35:49.307153
2019-05-24 20:35:49,307 [salt.state       :1813][INFO    ][11930] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:35:49,308 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11930] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:35:50,909 [salt.state       :300 ][INFO    ][11930] {'pid': 11938, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:35:50,910 [salt.state       :1951][INFO    ][11930] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:35:50.910472 duration_in_ms=1603.318
2019-05-24 20:35:50,913 [salt.state       :1780][INFO    ][11930] Running state [maas.wait_for_machine_status] at time 20:35:50.913276
2019-05-24 20:35:50,913 [salt.state       :1813][INFO    ][11930] Executing state module.run for [maas.wait_for_machine_status]
2019-05-24 20:35:50,914 [salt.utils.decorators:613 ][WARNING ][11930] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:35:52,799 [salt.loaded.ext.module.maas:993 ][INFO    ][11930] Machine mgkwcg mark broken
2019-05-24 20:35:53,103 [salt.loaded.ext.module.maas:996 ][INFO    ][11930] Machine mgkwcg mark fixed
2019-05-24 20:35:53,972 [salt.loaded.ext.module.maas:684 ][INFO    ][11930] deploymachines hwe_kernel=hwe-16.04 system_id=mgkwcg distro_series=xenial
2019-05-24 20:35:56,075 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1494.84704208s left)
2019-05-24 20:36:00,727 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203600677708
2019-05-24 20:36:00,751 [salt.minion      :1432][INFO    ][12026] Starting a new job with PID 12026
2019-05-24 20:36:00,777 [salt.minion      :1711][INFO    ][12026] Returning information for job: 20190524203600677708
2019-05-24 20:36:28,530 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1462.392313s left)
2019-05-24 20:36:30,780 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203630767539
2019-05-24 20:36:30,803 [salt.minion      :1432][INFO    ][12073] Starting a new job with PID 12073
2019-05-24 20:36:30,827 [salt.minion      :1711][INFO    ][12073] Returning information for job: 20190524203630767539
2019-05-24 20:37:00,797 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1430.12508702s left)
2019-05-24 20:37:00,825 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203700812530
2019-05-24 20:37:00,849 [salt.minion      :1432][INFO    ][12101] Starting a new job with PID 12101
2019-05-24 20:37:00,876 [salt.minion      :1711][INFO    ][12101] Returning information for job: 20190524203700812530
2019-05-24 20:37:30,875 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203730862410
2019-05-24 20:37:30,897 [salt.minion      :1432][INFO    ][12146] Starting a new job with PID 12146
2019-05-24 20:37:30,923 [salt.minion      :1711][INFO    ][12146] Returning information for job: 20190524203730862410
2019-05-24 20:37:33,138 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1397.78424001s left)
2019-05-24 20:38:00,919 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203800906090
2019-05-24 20:38:00,936 [salt.minion      :1432][INFO    ][12230] Starting a new job with PID 12230
2019-05-24 20:38:00,948 [salt.minion      :1711][INFO    ][12230] Returning information for job: 20190524203800906090
2019-05-24 20:38:05,272 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1365.65037799s left)
2019-05-24 20:38:30,952 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203830939701
2019-05-24 20:38:30,976 [salt.minion      :1432][INFO    ][12333] Starting a new job with PID 12333
2019-05-24 20:38:31,000 [salt.minion      :1711][INFO    ][12333] Returning information for job: 20190524203830939701
2019-05-24 20:38:37,763 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1333.15943813s left)
2019-05-24 20:39:01,008 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203900995784
2019-05-24 20:39:01,032 [salt.minion      :1432][INFO    ][12363] Starting a new job with PID 12363
2019-05-24 20:39:01,058 [salt.minion      :1711][INFO    ][12363] Returning information for job: 20190524203900995784
2019-05-24 20:39:10,304 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1300.61817694s left)
2019-05-24 20:39:31,076 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524203931062020
2019-05-24 20:39:31,100 [salt.minion      :1432][INFO    ][12502] Starting a new job with PID 12502
2019-05-24 20:39:31,126 [salt.minion      :1711][INFO    ][12502] Returning information for job: 20190524203931062020
2019-05-24 20:39:42,866 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1268.05621004s left)
2019-05-24 20:40:01,144 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204001131577
2019-05-24 20:40:01,167 [salt.minion      :1432][INFO    ][12531] Starting a new job with PID 12531
2019-05-24 20:40:01,193 [salt.minion      :1711][INFO    ][12531] Returning information for job: 20190524204001131577
2019-05-24 20:40:15,234 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1235.68805504s left)
2019-05-24 20:40:31,211 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204031198671
2019-05-24 20:40:31,235 [salt.minion      :1432][INFO    ][12612] Starting a new job with PID 12612
2019-05-24 20:40:31,260 [salt.minion      :1711][INFO    ][12612] Returning information for job: 20190524204031198671
2019-05-24 20:40:47,510 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1203.41247892s left)
2019-05-24 20:41:01,286 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204101274249
2019-05-24 20:41:01,310 [salt.minion      :1432][INFO    ][12639] Starting a new job with PID 12639
2019-05-24 20:41:01,335 [salt.minion      :1711][INFO    ][12639] Returning information for job: 20190524204101274249
2019-05-24 20:41:19,799 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1171.12393713s left)
2019-05-24 20:41:31,360 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204131347685
2019-05-24 20:41:31,384 [salt.minion      :1432][INFO    ][12771] Starting a new job with PID 12771
2019-05-24 20:41:31,408 [salt.minion      :1711][INFO    ][12771] Returning information for job: 20190524204131347685
2019-05-24 20:41:52,194 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1138.72820711s left)
2019-05-24 20:42:01,440 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204201427469
2019-05-24 20:42:01,464 [salt.minion      :1432][INFO    ][12799] Starting a new job with PID 12799
2019-05-24 20:42:01,491 [salt.minion      :1711][INFO    ][12799] Returning information for job: 20190524204201427469
2019-05-24 20:42:24,719 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1106.20375896s left)
2019-05-24 20:42:31,529 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204231516607
2019-05-24 20:42:31,553 [salt.minion      :1432][INFO    ][12911] Starting a new job with PID 12911
2019-05-24 20:42:31,579 [salt.minion      :1711][INFO    ][12911] Returning information for job: 20190524204231516607
2019-05-24 20:42:57,299 [salt.loaded.ext.module.maas:1023][INFO    ][11930] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1073.62333512s left)
2019-05-24 20:43:01,625 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command saltutil.find_job with jid 20190524204301611590
2019-05-24 20:43:01,648 [salt.minion      :1432][INFO    ][12949] Starting a new job with PID 12949
2019-05-24 20:43:01,675 [salt.minion      :1711][INFO    ][12949] Returning information for job: 20190524204301611590
2019-05-24 20:43:29,783 [salt.state       :300 ][INFO    ][11930] {'ret': True}
2019-05-24 20:43:29,784 [salt.state       :1951][INFO    ][11930] Completed state [maas.wait_for_machine_status] at time 20:43:29.784275 duration_in_ms=458870.997
2019-05-24 20:43:29,825 [salt.minion      :1711][INFO    ][11930] Returning information for job: 20190524203545660208
2019-05-24 20:43:30,518 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524204330504863
2019-05-24 20:43:30,542 [salt.minion      :1432][INFO    ][13058] Starting a new job with PID 13058
2019-05-24 20:43:34,098 [salt.state       :915 ][INFO    ][13058] Loading fresh modules for state activity
2019-05-24 20:43:34,241 [salt.state       :1780][INFO    ][13058] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:34.241190
2019-05-24 20:43:34,241 [salt.state       :1813][INFO    ][13058] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:43:34,242 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13058] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:43:35,795 [salt.state       :300 ][INFO    ][13058] {'pid': 13065, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:43:35,795 [salt.state       :1951][INFO    ][13058] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:35.795434 duration_in_ms=1554.245
2019-05-24 20:43:35,796 [salt.state       :1780][INFO    ][13058] Running state [maas_machines_storage_cmp002_lvm] at time 20:43:35.796795
2019-05-24 20:43:35,797 [salt.state       :1813][INFO    ][13058] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-24 20:43:36,513 [salt.state       :300 ][INFO    ][13058] Machine cmp002 is not in Ready state.
2019-05-24 20:43:36,514 [salt.state       :1951][INFO    ][13058] Completed state [maas_machines_storage_cmp002_lvm] at time 20:43:36.513997 duration_in_ms=717.2
2019-05-24 20:43:36,514 [salt.state       :1780][INFO    ][13058] Running state [maas_machines_storage_cmp001_lvm] at time 20:43:36.514606
2019-05-24 20:43:36,515 [salt.state       :1813][INFO    ][13058] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-24 20:43:37,101 [salt.state       :300 ][INFO    ][13058] Machine cmp001 is not in Ready state.
2019-05-24 20:43:37,101 [salt.state       :1951][INFO    ][13058] Completed state [maas_machines_storage_cmp001_lvm] at time 20:43:37.101804 duration_in_ms=587.196
2019-05-24 20:43:37,106 [salt.minion      :1711][INFO    ][13058] Returning information for job: 20190524204330504863
2019-05-24 20:43:37,738 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524204337726130
2019-05-24 20:43:37,760 [salt.minion      :1432][INFO    ][13076] Starting a new job with PID 13076
2019-05-24 20:43:38,506 [salt.state       :915 ][INFO    ][13076] Loading fresh modules for state activity
2019-05-24 20:43:38,593 [salt.state       :1780][INFO    ][13076] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:38.593626
2019-05-24 20:43:38,594 [salt.state       :1813][INFO    ][13076] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:43:38,596 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13076] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:43:40,132 [salt.state       :300 ][INFO    ][13076] {'pid': 13083, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:43:40,133 [salt.state       :1951][INFO    ][13076] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:40.133544 duration_in_ms=1539.917
2019-05-24 20:43:40,136 [salt.state       :1780][INFO    ][13076] Running state [maas.deploy_machines] at time 20:43:40.136095
2019-05-24 20:43:40,136 [salt.state       :1813][INFO    ][13076] Executing state module.run for [maas.deploy_machines]
2019-05-24 20:43:40,137 [salt.utils.decorators:613 ][WARNING ][13076] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:43:40,732 [salt.state       :300 ][INFO    ][13076] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-05-24 20:43:40,733 [salt.state       :1951][INFO    ][13076] Completed state [maas.deploy_machines] at time 20:43:40.733307 duration_in_ms=597.212
2019-05-24 20:43:40,736 [salt.minion      :1711][INFO    ][13076] Returning information for job: 20190524204337726130
2019-05-24 20:43:41,385 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command state.apply with jid 20190524204341370044
2019-05-24 20:43:41,409 [salt.minion      :1432][INFO    ][13106] Starting a new job with PID 13106
2019-05-24 20:43:42,077 [salt.state       :915 ][INFO    ][13106] Loading fresh modules for state activity
2019-05-24 20:43:42,123 [salt.state       :1780][INFO    ][13106] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:42.123740
2019-05-24 20:43:42,124 [salt.state       :1813][INFO    ][13106] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-24 20:43:42,125 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13106] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-24 20:43:43,498 [salt.state       :300 ][INFO    ][13106] {'pid': 13113, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-24 20:43:43,499 [salt.state       :1951][INFO    ][13106] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:43:43.498997 duration_in_ms=1375.257
2019-05-24 20:43:43,500 [salt.state       :1780][INFO    ][13106] Running state [maas.wait_for_machine_status] at time 20:43:43.500147
2019-05-24 20:43:43,500 [salt.state       :1813][INFO    ][13106] Executing state module.run for [maas.wait_for_machine_status]
2019-05-24 20:43:43,500 [salt.utils.decorators:613 ][WARNING ][13106] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-24 20:43:45,931 [salt.state       :300 ][INFO    ][13106] {'ret': True}
2019-05-24 20:43:45,931 [salt.state       :1951][INFO    ][13106] Completed state [maas.wait_for_machine_status] at time 20:43:45.931577 duration_in_ms=2431.427
2019-05-24 20:43:45,935 [salt.minion      :1711][INFO    ][13106] Returning information for job: 20190524204341370044
2019-05-24 21:14:03,155 [salt.utils.schedule:1377][INFO    ][5917] Running scheduled job: __mine_interval
2019-05-24 21:32:01,028 [salt.minion      :1308][INFO    ][5917] User sudo_ubuntu Executing command cp.push_dir with jid 20190524213201015410
2019-05-24 21:32:01,050 [salt.minion      :1432][INFO    ][16743] Starting a new job with PID 16743
