2019-11-23 07:36:04,785 [salt.utils.decorators:613 ][WARNING ][2139] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:36:05,325 [salt.utils.decorators:613 ][WARNING ][2139] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:36:07,500 [salt.loaded.int.states.file:2298][WARNING ][2370] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-11-23 07:36:31,909 [salt.state       :2022][WARNING ][2929] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-23 07:36:34,341 [salt.utils.decorators:613 ][WARNING ][2929] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:38:37,503 [salt.utils.decorators:613 ][WARNING ][2929] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:40:46,007 [salt.utils.decorators:613 ][WARNING ][2929] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:40:57,855 [salt.utils.decorators:613 ][WARNING ][2929] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:41:02,080 [salt.loaded.ext.module.maasng:1008][WARNING ][2929] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-11-23 07:41:02,081 [salt.loaded.ext.module.maasng:1011][WARNING ][2929] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-11-23 07:41:02,786 [salt.loaded.ext.module.maasng:1235][WARNING ][2929] Ignoring parameter vlan:0
2019-11-23 07:41:09,522 [salt.utils.decorators:613 ][WARNING ][11567] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:41:09,578 [salt.loaded.ext.module.maas:412 ][WARNING ][11567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 07:41:10,888 [salt.loaded.ext.module.maas:412 ][WARNING ][11567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 07:41:12,282 [salt.loaded.ext.module.maas:412 ][WARNING ][11567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 07:41:13,514 [salt.loaded.ext.module.maas:412 ][WARNING ][11567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 07:41:14,760 [salt.loaded.ext.module.maas:412 ][WARNING ][11567] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 07:41:19,270 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12181] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-23 07:41:19,301 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12181] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-23 07:41:19,322 [salt.utils.parsers:1051][WARNING ][368] Minion received a SIGTERM. Exiting.
2019-11-23 07:41:20,348 [salt.cli.daemons :293 ][INFO    ][12234] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-11-23 07:41:20,430 [salt.cli.daemons :82  ][INFO    ][12234] Starting up the Salt Minion
2019-11-23 07:41:20,431 [salt.utils.event :1017][INFO    ][12234] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-11-23 07:41:21,286 [salt.minion      :976 ][INFO    ][12234] Creating minion process manager
2019-11-23 07:41:22,690 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12234] Executing command ['date', '+%z'] in directory '/root'
2019-11-23 07:41:22,708 [salt.utils.schedule:568 ][INFO    ][12234] Updating job settings for scheduled job: __mine_interval
2019-11-23 07:41:22,710 [salt.minion      :1108][INFO    ][12234] Added mine.update to scheduler
2019-11-23 07:41:22,714 [salt.minion      :1975][INFO    ][12234] Minion is starting as user 'root'
2019-11-23 07:41:22,727 [salt.minion      :2336][INFO    ][12234] Minion is ready to receive requests!
2019-11-23 07:41:47,014 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123074147001842
2019-11-23 07:41:47,036 [salt.minion      :1432][INFO    ][12348] Starting a new job with PID 12348
2019-11-23 07:41:50,824 [salt.state       :915 ][INFO    ][12348] Loading fresh modules for state activity
2019-11-23 07:41:50,876 [salt.fileclient  :1219][INFO    ][12348] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-23 07:41:50,917 [salt.state       :1780][INFO    ][12348] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:41:50.917820
2019-11-23 07:41:50,918 [salt.state       :1813][INFO    ][12348] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 07:41:50,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12348] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 07:41:52,403 [salt.state       :300 ][INFO    ][12348] {'pid': 12355, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 07:41:52,403 [salt.state       :1951][INFO    ][12348] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:41:52.403712 duration_in_ms=1485.893
2019-11-23 07:41:52,404 [salt.state       :1780][INFO    ][12348] Running state [maas.wait_for_machine_status] at time 07:41:52.404839
2019-11-23 07:41:52,405 [salt.state       :1813][INFO    ][12348] Executing state module.run for [maas.wait_for_machine_status]
2019-11-23 07:41:52,405 [salt.utils.decorators:613 ][WARNING ][12348] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:41:53,232 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.17734718s left)
2019-11-23 07:42:02,100 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074202087414
2019-11-23 07:42:02,123 [salt.minion      :1432][INFO    ][12370] Starting a new job with PID 12370
2019-11-23 07:42:02,147 [salt.minion      :1711][INFO    ][12370] Returning information for job: 20191123074202087414
2019-11-23 07:42:24,174 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.23525214s left)
2019-11-23 07:42:32,149 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074232133721
2019-11-23 07:42:32,171 [salt.minion      :1432][INFO    ][12416] Starting a new job with PID 12416
2019-11-23 07:42:32,196 [salt.minion      :1711][INFO    ][12416] Returning information for job: 20191123074232133721
2019-11-23 07:42:55,503 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.90711117s left)
2019-11-23 07:43:02,206 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074302192764
2019-11-23 07:43:02,222 [salt.minion      :1432][INFO    ][12563] Starting a new job with PID 12563
2019-11-23 07:43:02,240 [salt.minion      :1711][INFO    ][12563] Returning information for job: 20191123074302192764
2019-11-23 07:43:26,811 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.59893608s left)
2019-11-23 07:43:32,242 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074332229592
2019-11-23 07:43:32,265 [salt.minion      :1432][INFO    ][12731] Starting a new job with PID 12731
2019-11-23 07:43:32,290 [salt.minion      :1711][INFO    ][12731] Returning information for job: 20191123074332229592
2019-11-23 07:43:58,555 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.85513902s left)
2019-11-23 07:44:02,304 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074402292032
2019-11-23 07:44:02,327 [salt.minion      :1432][INFO    ][13318] Starting a new job with PID 13318
2019-11-23 07:44:02,351 [salt.minion      :1711][INFO    ][13318] Returning information for job: 20191123074402292032
2019-11-23 07:44:30,424 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.98610616s left)
2019-11-23 07:44:32,362 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074432347947
2019-11-23 07:44:32,384 [salt.minion      :1432][INFO    ][13489] Starting a new job with PID 13489
2019-11-23 07:44:32,408 [salt.minion      :1711][INFO    ][13489] Returning information for job: 20191123074432347947
2019-11-23 07:45:02,428 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074502413189
2019-11-23 07:45:02,447 [salt.minion      :1432][INFO    ][13649] Starting a new job with PID 13649
2019-11-23 07:45:02,470 [salt.minion      :1711][INFO    ][13649] Returning information for job: 20191123074502413189
2019-11-23 07:45:03,969 [salt.loaded.ext.module.maas:1023][INFO    ][12348] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1308.44028115s left)
2019-11-23 07:45:32,483 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074532470669
2019-11-23 07:45:32,506 [salt.minion      :1432][INFO    ][13721] Starting a new job with PID 13721
2019-11-23 07:45:32,531 [salt.minion      :1711][INFO    ][13721] Returning information for job: 20191123074532470669
2019-11-23 07:45:37,161 [salt.state       :300 ][INFO    ][12348] {'ret': True}
2019-11-23 07:45:37,162 [salt.state       :1951][INFO    ][12348] Completed state [maas.wait_for_machine_status] at time 07:45:37.162218 duration_in_ms=224757.376
2019-11-23 07:45:37,166 [salt.minion      :1711][INFO    ][12348] Returning information for job: 20191123074147001842
2019-11-23 07:45:37,806 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123074537792799
2019-11-23 07:45:37,828 [salt.minion      :1432][INFO    ][13807] Starting a new job with PID 13807
2019-11-23 07:45:41,702 [salt.state       :915 ][INFO    ][13807] Loading fresh modules for state activity
2019-11-23 07:45:41,731 [salt.fileclient  :1219][INFO    ][13807] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-23 07:45:41,786 [salt.state       :1780][INFO    ][13807] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:45:41.786110
2019-11-23 07:45:41,786 [salt.state       :1813][INFO    ][13807] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 07:45:41,787 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13807] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 07:45:43,233 [salt.state       :300 ][INFO    ][13807] {'pid': 13851, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 07:45:43,234 [salt.state       :1951][INFO    ][13807] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:45:43.234208 duration_in_ms=1448.098
2019-11-23 07:45:43,235 [salt.state       :1780][INFO    ][13807] Running state [maas_machines_storage_cmp002_lvm] at time 07:45:43.235682
2019-11-23 07:45:43,235 [salt.state       :1813][INFO    ][13807] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-23 07:45:44,217 [salt.loaded.ext.module.maasng:610 ][INFO    ][13807] 88ks4w
2019-11-23 07:45:44,217 [salt.loaded.ext.module.maasng:626 ][INFO    ][13807] sda
2019-11-23 07:45:44,924 [salt.loaded.ext.module.maasng:361 ][INFO    ][13807] 88ks4w
2019-11-23 07:45:45,035 [salt.loaded.ext.module.maasng:367 ][INFO    ][13807] [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'5fc1d2a3-feb4-498b-b18c-f5983a4729b9', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/partition/2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88ks4w', u'filesystem': {u'mount_options': None, u'uuid': u'ab4eccf7-cda8-4048-b502-0fd56420cd0f', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 2, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88ks4w', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}, {u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/7/', u'uuid': u'bb8f2965-14ff-4040-9914-74b13eaadbb1', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'adc86cca-ab63-4bde-97f3-a66dc28f1c4d', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'88ks4w', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 7, u'size': 2397988454400}]
2019-11-23 07:45:45,035 [salt.loaded.ext.module.maasng:632 ][INFO    ][13807] vgroot
2019-11-23 07:45:45,036 [salt.loaded.ext.module.maasng:635 ][INFO    ][13807] lvroot
2019-11-23 07:45:45,036 [salt.loaded.ext.module.maasng:639 ][INFO    ][13807] 107374182400
2019-11-23 07:45:45,678 [salt.loaded.ext.module.maasng:645 ][INFO    ][13807] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'e6da77fc-e8ad-4f0d-9552-d10e0c178814', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88ks4w', u'filesystem': {u'mount_options': None, u'uuid': u'd538ec58-8196-4c80-9734-6222e382fe74', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88ks4w', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}, {u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/11/', u'uuid': u'b13c329f-109e-4f22-a6c9-8046ca760b64', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'20824e4a-c077-4df0-939c-9c5fac588813', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'88ks4w', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'size': 107374182400}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/88ks4w/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'88ks4w', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.42'], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'88ks4w', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 20, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'88ks4w', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 21, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'system_id': u'88ks4w', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/interfaces/12/'}, {u'name': u'enp8s0', u'links': [{u'id': 22, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'system_id': u'88ks4w', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/interfaces/13/'}, {u'name': u'enp7s0', u'links': [{u'id': 23, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'system_id': u'88ks4w', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/interfaces/14/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'e6da77fc-e8ad-4f0d-9552-d10e0c178814', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88ks4w', u'filesystem': {u'mount_options': None, u'uuid': u'd538ec58-8196-4c80-9734-6222e382fe74', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88ks4w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'virtualblockdevice_set': [{u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/11/', u'uuid': u'b13c329f-109e-4f22-a6c9-8046ca760b64', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'20824e4a-c077-4df0-939c-9c5fac588813', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'88ks4w', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 11, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 20, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'88ks4w', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/interfaces/4/'}, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'e6da77fc-e8ad-4f0d-9552-d10e0c178814', u'resource_uri': u'/MAAS/api/2.0/nodes/88ks4w/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88ks4w', u'filesystem': {u'mount_options': None, u'uuid': u'd538ec58-8196-4c80-9734-6222e382fe74', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88ks4w', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}, u'current_commissioning_result_id': 2, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-23 07:45:45,680 [salt.state       :300 ][INFO    ][13807] {'new': {'storage_layout': 'lvm'}}
2019-11-23 07:45:45,680 [salt.state       :1951][INFO    ][13807] Completed state [maas_machines_storage_cmp002_lvm] at time 07:45:45.680837 duration_in_ms=2445.153
2019-11-23 07:45:45,681 [salt.state       :1780][INFO    ][13807] Running state [maas_machines_storage_cmp001_lvm] at time 07:45:45.681419
2019-11-23 07:45:45,681 [salt.state       :1813][INFO    ][13807] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-23 07:45:47,263 [salt.loaded.ext.module.maasng:610 ][INFO    ][13807] dqwar4
2019-11-23 07:45:47,263 [salt.loaded.ext.module.maasng:626 ][INFO    ][13807] sda
2019-11-23 07:45:47,863 [salt.loaded.ext.module.maasng:361 ][INFO    ][13807] dqwar4
2019-11-23 07:45:47,995 [salt.loaded.ext.module.maasng:367 ][INFO    ][13807] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dqwar4', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'size': 2397992648704, u'uuid': u'bb626115-07c3-4c02-8515-1a91304172f1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dqwar4', u'filesystem': {u'uuid': u'cf393dad-4af9-4792-860c-4b6d6347504b', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/partition/1'}]}, {u'size': 2397988454400, u'model': None, u'block_size': 4096, u'uuid': u'ff22a233-cb76-4716-91a4-958659437bb1', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'uuid': u'17d9fea0-e197-43aa-a211-067e51944853', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'dqwar4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/6/', u'used_size': 2397988454400, u'id': 6, u'partitions': []}]
2019-11-23 07:45:47,996 [salt.loaded.ext.module.maasng:632 ][INFO    ][13807] vgroot
2019-11-23 07:45:47,996 [salt.loaded.ext.module.maasng:635 ][INFO    ][13807] lvroot
2019-11-23 07:45:47,996 [salt.loaded.ext.module.maasng:639 ][INFO    ][13807] 107374182400
2019-11-23 07:45:48,644 [salt.loaded.ext.module.maasng:645 ][INFO    ][13807] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'85a2ea5c-30f7-41ac-b06f-069f68932ef7', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dqwar4', u'filesystem': {u'mount_options': None, u'uuid': u'8cdc3a85-8699-413e-a068-cb807a882552', u'mount_point': None, u'label': None, 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'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dqwar4', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'size': 2397998940160}, {u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/12/', u'uuid': u'6d77f087-b45f-44ac-b118-91b6d8e945ad', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'c291f47e-7fb5-4e6e-bb81-ceccbcf9f181', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'dqwar4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'size': 107374182400}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/dqwar4/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'dqwar4', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.38'], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'dqwar4', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'dqwar4', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/interfaces/5/'}, {u'name': u'enp9s0', 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'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'dqwar4', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/interfaces/9/'}, {u'name': u'enp8s0', 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'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'dqwar4', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/interfaces/10/'}, {u'name': u'enp7s0', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'dqwar4', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'85a2ea5c-30f7-41ac-b06f-069f68932ef7', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dqwar4', u'filesystem': {u'mount_options': None, u'uuid': u'8cdc3a85-8699-413e-a068-cb807a882552', u'mount_point': None, u'label': None, 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'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dqwar4', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'virtualblockdevice_set': [{u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/12/', u'uuid': u'6d77f087-b45f-44ac-b118-91b6d8e945ad', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'c291f47e-7fb5-4e6e-bb81-ceccbcf9f181', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'dqwar4', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-18.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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'dqwar4', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/interfaces/5/'}, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'85a2ea5c-30f7-41ac-b06f-069f68932ef7', u'resource_uri': u'/MAAS/api/2.0/nodes/dqwar4/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dqwar4', u'filesystem': {u'mount_options': None, u'uuid': u'8cdc3a85-8699-413e-a068-cb807a882552', u'mount_point': None, u'label': None, 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'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dqwar4', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'size': 2397998940160}, u'current_commissioning_result_id': 4, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-11-23 07:45:48,646 [salt.state       :300 ][INFO    ][13807] {'new': {'storage_layout': 'lvm'}}
2019-11-23 07:45:48,647 [salt.state       :1951][INFO    ][13807] Completed state [maas_machines_storage_cmp001_lvm] at time 07:45:48.647282 duration_in_ms=2965.863
2019-11-23 07:45:48,651 [salt.minion      :1711][INFO    ][13807] Returning information for job: 20191123074537792799
2019-11-23 07:45:49,287 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123074549274748
2019-11-23 07:45:49,308 [salt.minion      :1432][INFO    ][13869] Starting a new job with PID 13869
2019-11-23 07:45:50,112 [salt.state       :915 ][INFO    ][13869] Loading fresh modules for state activity
2019-11-23 07:45:50,162 [salt.fileclient  :1219][INFO    ][13869] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-23 07:45:50,203 [salt.state       :1780][INFO    ][13869] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:45:50.203566
2019-11-23 07:45:50,203 [salt.state       :1813][INFO    ][13869] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 07:45:50,206 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13869] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 07:45:51,643 [salt.state       :300 ][INFO    ][13869] {'pid': 13876, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 07:45:51,644 [salt.state       :1951][INFO    ][13869] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:45:51.644262 duration_in_ms=1440.697
2019-11-23 07:45:51,645 [salt.state       :1780][INFO    ][13869] Running state [maas.deploy_machines] at time 07:45:51.645508
2019-11-23 07:45:51,645 [salt.state       :1813][INFO    ][13869] Executing state module.run for [maas.deploy_machines]
2019-11-23 07:45:51,646 [salt.utils.decorators:613 ][WARNING ][13869] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:45:52,387 [salt.loaded.ext.module.maas:684 ][INFO    ][13869] deploymachines hwe_kernel=ga-18.04 system_id=88ks4w distro_series=bionic
2019-11-23 07:45:54,875 [salt.loaded.ext.module.maas:684 ][INFO    ][13869] deploymachines hwe_kernel=ga-18.04 system_id=dqwar4 distro_series=bionic
2019-11-23 07:45:57,559 [salt.loaded.ext.module.maas:684 ][INFO    ][13869] deploymachines hwe_kernel=ga-18.04 system_id=tc7bt7 distro_series=bionic
2019-11-23 07:46:00,232 [salt.loaded.ext.module.maas:684 ][INFO    ][13869] deploymachines hwe_kernel=ga-18.04 system_id=cp3bf6 distro_series=bionic
2019-11-23 07:46:02,907 [salt.loaded.ext.module.maas:684 ][INFO    ][13869] deploymachines hwe_kernel=ga-18.04 system_id=ned48r distro_series=bionic
2019-11-23 07:46:04,389 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074604376441
2019-11-23 07:46:04,412 [salt.minion      :1432][INFO    ][14152] Starting a new job with PID 14152
2019-11-23 07:46:04,435 [salt.minion      :1711][INFO    ][14152] Returning information for job: 20191123074604376441
2019-11-23 07:46:05,279 [salt.state       :300 ][INFO    ][13869] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-23 07:46:05,280 [salt.state       :1951][INFO    ][13869] Completed state [maas.deploy_machines] at time 07:46:05.280363 duration_in_ms=13634.852
2019-11-23 07:46:05,284 [salt.minion      :1711][INFO    ][13869] Returning information for job: 20191123074549274748
2019-11-23 07:46:05,928 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123074605916136
2019-11-23 07:46:05,949 [salt.minion      :1432][INFO    ][14171] Starting a new job with PID 14171
2019-11-23 07:46:09,847 [salt.state       :915 ][INFO    ][14171] Loading fresh modules for state activity
2019-11-23 07:46:09,899 [salt.fileclient  :1219][INFO    ][14171] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-23 07:46:09,942 [salt.state       :1780][INFO    ][14171] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:46:09.942218
2019-11-23 07:46:09,942 [salt.state       :1813][INFO    ][14171] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 07:46:09,944 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14171] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 07:46:11,316 [salt.state       :300 ][INFO    ][14171] {'pid': 14185, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 07:46:11,317 [salt.state       :1951][INFO    ][14171] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:46:11.317106 duration_in_ms=1374.889
2019-11-23 07:46:11,318 [salt.state       :1780][INFO    ][14171] Running state [maas.wait_for_machine_status] at time 07:46:11.318436
2019-11-23 07:46:11,318 [salt.state       :1813][INFO    ][14171] Executing state module.run for [maas.wait_for_machine_status]
2019-11-23 07:46:11,318 [salt.utils.decorators:613 ][WARNING ][14171] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 07:46:14,375 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.94800711s left)
2019-11-23 07:46:21,022 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074621008528
2019-11-23 07:46:21,044 [salt.minion      :1432][INFO    ][14197] Starting a new job with PID 14197
2019-11-23 07:46:21,067 [salt.minion      :1711][INFO    ][14197] Returning information for job: 20191123074621008528
2019-11-23 07:46:48,081 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.24154091s left)
2019-11-23 07:46:51,076 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074651062645
2019-11-23 07:46:51,099 [salt.minion      :1432][INFO    ][14255] Starting a new job with PID 14255
2019-11-23 07:46:51,124 [salt.minion      :1711][INFO    ][14255] Returning information for job: 20191123074651062645
2019-11-23 07:47:21,125 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074721112695
2019-11-23 07:47:21,145 [salt.minion      :1432][INFO    ][14296] Starting a new job with PID 14296
2019-11-23 07:47:21,167 [salt.minion      :1711][INFO    ][14296] Returning information for job: 20191123074721112695
2019-11-23 07:47:21,524 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.79894209s left)
2019-11-23 07:47:51,169 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074751156409
2019-11-23 07:47:51,189 [salt.minion      :1432][INFO    ][14420] Starting a new job with PID 14420
2019-11-23 07:47:51,211 [salt.minion      :1711][INFO    ][14420] Returning information for job: 20191123074751156409
2019-11-23 07:47:55,182 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.14051509s left)
2019-11-23 07:48:21,220 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074821207583
2019-11-23 07:48:21,239 [salt.minion      :1432][INFO    ][14662] Starting a new job with PID 14662
2019-11-23 07:48:21,261 [salt.minion      :1711][INFO    ][14662] Returning information for job: 20191123074821207583
2019-11-23 07:48:28,567 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.75521088s left)
2019-11-23 07:48:51,271 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074851258811
2019-11-23 07:48:51,293 [salt.minion      :1432][INFO    ][15158] Starting a new job with PID 15158
2019-11-23 07:48:51,317 [salt.minion      :1711][INFO    ][15158] Returning information for job: 20191123074851258811
2019-11-23 07:49:02,165 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.15716505s left)
2019-11-23 07:49:21,328 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074921316432
2019-11-23 07:49:21,349 [salt.minion      :1432][INFO    ][15370] Starting a new job with PID 15370
2019-11-23 07:49:21,373 [salt.minion      :1711][INFO    ][15370] Returning information for job: 20191123074921316432
2019-11-23 07:49:35,138 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.18495893s left)
2019-11-23 07:49:51,388 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123074951376006
2019-11-23 07:49:51,410 [salt.minion      :1432][INFO    ][15569] Starting a new job with PID 15569
2019-11-23 07:49:51,433 [salt.minion      :1711][INFO    ][15569] Returning information for job: 20191123074951376006
2019-11-23 07:50:08,582 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.7405231s left)
2019-11-23 07:50:21,454 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075021441836
2019-11-23 07:50:21,476 [salt.minion      :1432][INFO    ][15624] Starting a new job with PID 15624
2019-11-23 07:50:21,499 [salt.minion      :1711][INFO    ][15624] Returning information for job: 20191123075021441836
2019-11-23 07:50:41,925 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.39804697s left)
2019-11-23 07:50:51,531 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075051518958
2019-11-23 07:50:51,554 [salt.minion      :1432][INFO    ][15764] Starting a new job with PID 15764
2019-11-23 07:50:51,579 [salt.minion      :1711][INFO    ][15764] Returning information for job: 20191123075051518958
2019-11-23 07:51:15,319 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.00311995s left)
2019-11-23 07:51:21,611 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075121598014
2019-11-23 07:51:21,633 [salt.minion      :1432][INFO    ][15865] Starting a new job with PID 15865
2019-11-23 07:51:21,658 [salt.minion      :1711][INFO    ][15865] Returning information for job: 20191123075121598014
2019-11-23 07:51:48,979 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.34397793s left)
2019-11-23 07:51:51,692 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075151678939
2019-11-23 07:51:51,714 [salt.minion      :1432][INFO    ][16175] Starting a new job with PID 16175
2019-11-23 07:51:51,739 [salt.minion      :1711][INFO    ][16175] Returning information for job: 20191123075151678939
2019-11-23 07:52:21,776 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075221763580
2019-11-23 07:52:21,799 [salt.minion      :1432][INFO    ][16323] Starting a new job with PID 16323
2019-11-23 07:52:21,823 [salt.minion      :1711][INFO    ][16323] Returning information for job: 20191123075221763580
2019-11-23 07:52:22,598 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.72484303s left)
2019-11-23 07:52:51,862 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075251849366
2019-11-23 07:52:51,884 [salt.minion      :1432][INFO    ][16563] Starting a new job with PID 16563
2019-11-23 07:52:51,908 [salt.minion      :1711][INFO    ][16563] Returning information for job: 20191123075251849366
2019-11-23 07:52:56,124 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.19820499s left)
2019-11-23 07:53:21,956 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075321943309
2019-11-23 07:53:21,979 [salt.minion      :1432][INFO    ][16602] Starting a new job with PID 16602
2019-11-23 07:53:22,002 [salt.minion      :1711][INFO    ][16602] Returning information for job: 20191123075321943309
2019-11-23 07:53:29,512 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1811.81019092s left)
2019-11-23 07:53:52,184 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075352167903
2019-11-23 07:53:52,206 [salt.minion      :1432][INFO    ][16806] Starting a new job with PID 16806
2019-11-23 07:53:52,231 [salt.minion      :1711][INFO    ][16806] Returning information for job: 20191123075352167903
2019-11-23 07:54:02,893 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1778.42968988s left)
2019-11-23 07:54:22,385 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075422372506
2019-11-23 07:54:22,407 [salt.minion      :1432][INFO    ][16926] Starting a new job with PID 16926
2019-11-23 07:54:22,431 [salt.minion      :1711][INFO    ][16926] Returning information for job: 20191123075422372506
2019-11-23 07:54:35,952 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1745.37024093s left)
2019-11-23 07:54:52,500 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075452487632
2019-11-23 07:54:52,523 [salt.minion      :1432][INFO    ][17198] Starting a new job with PID 17198
2019-11-23 07:54:52,548 [salt.minion      :1711][INFO    ][17198] Returning information for job: 20191123075452487632
2019-11-23 07:55:09,236 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1712.08627009s left)
2019-11-23 07:55:22,622 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075522609215
2019-11-23 07:55:22,645 [salt.minion      :1432][INFO    ][17317] Starting a new job with PID 17317
2019-11-23 07:55:22,669 [salt.minion      :1711][INFO    ][17317] Returning information for job: 20191123075522609215
2019-11-23 07:55:42,718 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1678.60458493s left)
2019-11-23 07:55:52,750 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075552737867
2019-11-23 07:55:52,773 [salt.minion      :1432][INFO    ][17358] Starting a new job with PID 17358
2019-11-23 07:55:52,795 [salt.minion      :1711][INFO    ][17358] Returning information for job: 20191123075552737867
2019-11-23 07:56:16,227 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1645.09581709s left)
2019-11-23 07:56:22,885 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075622872748
2019-11-23 07:56:22,907 [salt.minion      :1432][INFO    ][17397] Starting a new job with PID 17397
2019-11-23 07:56:22,930 [salt.minion      :1711][INFO    ][17397] Returning information for job: 20191123075622872748
2019-11-23 07:56:49,668 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1611.6542089s left)
2019-11-23 07:56:53,026 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075653014062
2019-11-23 07:56:53,045 [salt.minion      :1432][INFO    ][17537] Starting a new job with PID 17537
2019-11-23 07:56:53,067 [salt.minion      :1711][INFO    ][17537] Returning information for job: 20191123075653014062
2019-11-23 07:57:23,174 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075723161061
2019-11-23 07:57:23,196 [salt.minion      :1432][INFO    ][17575] Starting a new job with PID 17575
2019-11-23 07:57:23,217 [salt.minion      :1711][INFO    ][17575] Returning information for job: 20191123075723161061
2019-11-23 07:57:23,310 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1578.01367688s left)
2019-11-23 07:57:53,334 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075753321961
2019-11-23 07:57:53,355 [salt.minion      :1432][INFO    ][17620] Starting a new job with PID 17620
2019-11-23 07:57:53,378 [salt.minion      :1711][INFO    ][17620] Returning information for job: 20191123075753321961
2019-11-23 07:57:56,855 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1544.46761894s left)
2019-11-23 07:58:23,513 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075823500438
2019-11-23 07:58:23,536 [salt.minion      :1432][INFO    ][17661] Starting a new job with PID 17661
2019-11-23 07:58:23,559 [salt.minion      :1711][INFO    ][17661] Returning information for job: 20191123075823500438
2019-11-23 07:58:30,350 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1510.97267008s left)
2019-11-23 07:58:53,695 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075853682612
2019-11-23 07:58:53,718 [salt.minion      :1432][INFO    ][17702] Starting a new job with PID 17702
2019-11-23 07:58:53,741 [salt.minion      :1711][INFO    ][17702] Returning information for job: 20191123075853682612
2019-11-23 07:59:03,339 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1477.98333693s left)
2019-11-23 07:59:23,884 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075923871463
2019-11-23 07:59:23,907 [salt.minion      :1432][INFO    ][17739] Starting a new job with PID 17739
2019-11-23 07:59:23,930 [salt.minion      :1711][INFO    ][17739] Returning information for job: 20191123075923871463
2019-11-23 07:59:37,108 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1444.21464205s left)
2019-11-23 07:59:54,088 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123075954075648
2019-11-23 07:59:54,110 [salt.minion      :1432][INFO    ][17779] Starting a new job with PID 17779
2019-11-23 07:59:54,134 [salt.minion      :1711][INFO    ][17779] Returning information for job: 20191123075954075648
2019-11-23 08:00:10,588 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1410.734586s left)
2019-11-23 08:00:24,301 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080024289112
2019-11-23 08:00:24,324 [salt.minion      :1432][INFO    ][17814] Starting a new job with PID 17814
2019-11-23 08:00:24,347 [salt.minion      :1711][INFO    ][17814] Returning information for job: 20191123080024289112
2019-11-23 08:00:43,972 [salt.loaded.ext.module.maas:1023][INFO    ][14171] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1377.350137s left)
2019-11-23 08:00:54,527 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080054514167
2019-11-23 08:00:54,549 [salt.minion      :1432][INFO    ][17855] Starting a new job with PID 17855
2019-11-23 08:00:54,573 [salt.minion      :1711][INFO    ][17855] Returning information for job: 20191123080054514167
2019-11-23 08:01:16,787 [salt.loaded.ext.module.maas:993 ][INFO    ][14171] Machine cp3bf6 mark broken
2019-11-23 08:01:17,446 [salt.loaded.ext.module.maas:996 ][INFO    ][14171] Machine cp3bf6 mark fixed
2019-11-23 08:01:18,698 [salt.loaded.ext.module.maas:684 ][INFO    ][14171] deploymachines hwe_kernel=ga-18.04 system_id=cp3bf6 distro_series=bionic
2019-11-23 08:01:21,380 [salt.loaded.ext.module.maas:160 ][ERROR   ][14171] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-11-23 08:01:21,382 [salt.state       :302 ][ERROR   ][14171] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-11-23 08:01:21,383 [salt.state       :1951][INFO    ][14171] Completed state [maas.wait_for_machine_status] at time 08:01:21.383417 duration_in_ms=910064.973
2019-11-23 08:01:21,393 [salt.minion      :1711][INFO    ][14171] Returning information for job: 20191123074605916136
2019-11-23 08:01:32,161 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command pillar.get with jid 20191123080132145283
2019-11-23 08:01:32,181 [salt.minion      :1432][INFO    ][17977] Starting a new job with PID 17977
2019-11-23 08:01:32,185 [salt.minion      :1711][INFO    ][17977] Returning information for job: 20191123080132145283
2019-11-23 08:01:32,682 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command service.status with jid 20191123080132669893
2019-11-23 08:01:32,703 [salt.minion      :1432][INFO    ][17982] Starting a new job with PID 17982
2019-11-23 08:01:33,095 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][17982] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:33,130 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][17982] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-23 08:01:33,146 [salt.minion      :1711][INFO    ][17982] Returning information for job: 20191123080132669893
2019-11-23 08:01:33,722 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123080133709122
2019-11-23 08:01:33,744 [salt.minion      :1432][INFO    ][17997] Starting a new job with PID 17997
2019-11-23 08:01:37,654 [salt.state       :915 ][INFO    ][17997] Loading fresh modules for state activity
2019-11-23 08:01:38,095 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'salt-minion --version' in directory '/root'
2019-11-23 08:01:38,450 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'salt-minion --version' in directory '/root'
2019-11-23 08:01:39,337 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'salt-minion --version' in directory '/root'
2019-11-23 08:01:39,704 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'salt-minion --version' in directory '/root'
2019-11-23 08:01:41,035 [salt.state       :1780][INFO    ][17997] Running state [salt-minion] at time 08:01:41.035213
2019-11-23 08:01:41,035 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [salt-minion]
2019-11-23 08:01:41,036 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-23 08:01:41,109 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,109 [salt.state       :1951][INFO    ][17997] Completed state [salt-minion] at time 08:01:41.109745 duration_in_ms=74.533
2019-11-23 08:01:41,110 [salt.state       :1780][INFO    ][17997] Running state [salt_minion_dependency_packages] at time 08:01:41.109993
2019-11-23 08:01:41,110 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-23 08:01:41,114 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,114 [salt.state       :1951][INFO    ][17997] Completed state [salt_minion_dependency_packages] at time 08:01:41.114873 duration_in_ms=4.88
2019-11-23 08:01:41,117 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/minion.d/minion.conf] at time 08:01:41.117188
2019-11-23 08:01:41,117 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-23 08:01:41,272 [salt.state       :300 ][INFO    ][17997] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-23 08:01:41,272 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/minion.d/minion.conf] at time 08:01:41.272774 duration_in_ms=155.586
2019-11-23 08:01:41,272 [salt.state       :1780][INFO    ][17997] Running state [python-netaddr] at time 08:01:41.272945
2019-11-23 08:01:41,273 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [python-netaddr]
2019-11-23 08:01:41,277 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,277 [salt.state       :1951][INFO    ][17997] Completed state [python-netaddr] at time 08:01:41.277504 duration_in_ms=4.559
2019-11-23 08:01:41,279 [salt.state       :1780][INFO    ][17997] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 08:01:41.279499
2019-11-23 08:01:41,279 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-23 08:01:41,288 [salt.state       :300 ][INFO    ][17997] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-23 08:01:41,288 [salt.state       :1951][INFO    ][17997] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 08:01:41.288463 duration_in_ms=8.965
2019-11-23 08:01:41,289 [salt.state       :1780][INFO    ][17997] Running state [salt-minion] at time 08:01:41.289102
2019-11-23 08:01:41,289 [salt.state       :1813][INFO    ][17997] Executing state service.running for [salt-minion]
2019-11-23 08:01:41,289 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:41,324 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-23 08:01:41,339 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-23 08:01:41,355 [salt.state       :300 ][INFO    ][17997] The service salt-minion is already running
2019-11-23 08:01:41,355 [salt.state       :1951][INFO    ][17997] Completed state [salt-minion] at time 08:01:41.355264 duration_in_ms=66.162
2019-11-23 08:01:41,356 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains.d] at time 08:01:41.356325
2019-11-23 08:01:41,356 [salt.state       :1813][INFO    ][17997] Executing state file.directory for [/etc/salt/grains.d]
2019-11-23 08:01:41,357 [salt.state       :300 ][INFO    ][17997] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-23 08:01:41,357 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains.d] at time 08:01:41.357408 duration_in_ms=1.082
2019-11-23 08:01:41,357 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains] at time 08:01:41.357880
2019-11-23 08:01:41,358 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/grains]
2019-11-23 08:01:41,358 [salt.state       :300 ][INFO    ][17997] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-23 08:01:41,358 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains] at time 08:01:41.358644 duration_in_ms=0.764
2019-11-23 08:01:41,358 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains.d/placeholder] at time 08:01:41.358961
2019-11-23 08:01:41,359 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-23 08:01:41,359 [salt.state       :300 ][INFO    ][17997] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-23 08:01:41,359 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains.d/placeholder] at time 08:01:41.359688 duration_in_ms=0.727
2019-11-23 08:01:41,360 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains.d/sphinx] at time 08:01:41.360001
2019-11-23 08:01:41,360 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-23 08:01:41,361 [salt.state       :300 ][INFO    ][17997] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-23 08:01:41,361 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains.d/sphinx] at time 08:01:41.361194 duration_in_ms=1.192
2019-11-23 08:01:41,362 [salt.state       :1780][INFO    ][17997] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.362775
2019-11-23 08:01:41,363 [salt.state       :1813][INFO    ][17997] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-23 08:01:41,363 [salt.state       :300 ][INFO    ][17997] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-23 08:01:41,363 [salt.state       :1951][INFO    ][17997] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.363368 duration_in_ms=0.593
2019-11-23 08:01:41,363 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains.d/dns_records] at time 08:01:41.363691
2019-11-23 08:01:41,363 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-23 08:01:41,364 [salt.state       :300 ][INFO    ][17997] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-23 08:01:41,364 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains.d/dns_records] at time 08:01:41.364695 duration_in_ms=1.004
2019-11-23 08:01:41,365 [salt.state       :1780][INFO    ][17997] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.365278
2019-11-23 08:01:41,365 [salt.state       :1813][INFO    ][17997] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-23 08:01:41,365 [salt.state       :300 ][INFO    ][17997] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-23 08:01:41,365 [salt.state       :1951][INFO    ][17997] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.365866 duration_in_ms=0.588
2019-11-23 08:01:41,366 [salt.state       :1780][INFO    ][17997] Running state [/etc/salt/grains.d/salt] at time 08:01:41.366172
2019-11-23 08:01:41,366 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-23 08:01:41,367 [salt.state       :300 ][INFO    ][17997] File /etc/salt/grains.d/salt is in the correct state
2019-11-23 08:01:41,367 [salt.state       :1951][INFO    ][17997] Completed state [/etc/salt/grains.d/salt] at time 08:01:41.367166 duration_in_ms=0.994
2019-11-23 08:01:41,367 [salt.state       :1780][INFO    ][17997] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.367745
2019-11-23 08:01:41,367 [salt.state       :1813][INFO    ][17997] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-23 08:01:41,368 [salt.state       :300 ][INFO    ][17997] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-23 08:01:41,368 [salt.state       :1951][INFO    ][17997] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 08:01:41.368320 duration_in_ms=0.576
2019-11-23 08:01:41,369 [salt.state       :1780][INFO    ][17997] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 08:01:41.369548
2019-11-23 08:01:41,369 [salt.state       :1813][INFO    ][17997] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-23 08:01:41,370 [salt.state       :300 ][INFO    ][17997] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-23 08:01:41,370 [salt.state       :1951][INFO    ][17997] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 08:01:41.370115 duration_in_ms=0.567
2019-11-23 08:01:41,370 [salt.state       :1780][INFO    ][17997] Running state [mine.update] at time 08:01:41.370557
2019-11-23 08:01:41,370 [salt.state       :1813][INFO    ][17997] Executing state module.wait for [mine.update]
2019-11-23 08:01:41,370 [salt.state       :300 ][INFO    ][17997] No changes made for mine.update
2019-11-23 08:01:41,371 [salt.state       :1951][INFO    ][17997] Completed state [mine.update] at time 08:01:41.371088 duration_in_ms=0.53
2019-11-23 08:01:41,371 [salt.state       :1780][INFO    ][17997] Running state [ca-certificates] at time 08:01:41.371256
2019-11-23 08:01:41,371 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [ca-certificates]
2019-11-23 08:01:41,376 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,376 [salt.state       :1951][INFO    ][17997] Completed state [ca-certificates] at time 08:01:41.376329 duration_in_ms=5.072
2019-11-23 08:01:41,376 [salt.state       :1780][INFO    ][17997] Running state [update-ca-certificates] at time 08:01:41.376798
2019-11-23 08:01:41,377 [salt.state       :1813][INFO    ][17997] Executing state cmd.wait for [update-ca-certificates]
2019-11-23 08:01:41,377 [salt.state       :300 ][INFO    ][17997] No changes made for update-ca-certificates
2019-11-23 08:01:41,377 [salt.state       :1951][INFO    ][17997] Completed state [update-ca-certificates] at time 08:01:41.377338 duration_in_ms=0.54
2019-11-23 08:01:41,377 [salt.state       :1780][INFO    ][17997] Running state [iptables] at time 08:01:41.377511
2019-11-23 08:01:41,377 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [iptables]
2019-11-23 08:01:41,382 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,382 [salt.state       :1951][INFO    ][17997] Completed state [iptables] at time 08:01:41.382259 duration_in_ms=4.748
2019-11-23 08:01:41,382 [salt.state       :1780][INFO    ][17997] Running state [iptables-persistent] at time 08:01:41.382423
2019-11-23 08:01:41,382 [salt.state       :1813][INFO    ][17997] Executing state pkg.installed for [iptables-persistent]
2019-11-23 08:01:41,387 [salt.state       :300 ][INFO    ][17997] All specified packages are already installed
2019-11-23 08:01:41,387 [salt.state       :1951][INFO    ][17997] Completed state [iptables-persistent] at time 08:01:41.387132 duration_in_ms=4.71
2019-11-23 08:01:41,387 [salt.state       :1780][INFO    ][17997] Running state [iptables_modules_v4_load] at time 08:01:41.387811
2019-11-23 08:01:41,388 [salt.state       :1813][INFO    ][17997] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-23 08:01:41,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'lsmod' in directory '/root'
2019-11-23 08:01:41,410 [salt.state       :300 ][INFO    ][17997] Kernel modules iptable_filter, ip_tables are already present
2019-11-23 08:01:41,410 [salt.state       :1951][INFO    ][17997] Completed state [iptables_modules_v4_load] at time 08:01:41.410948 duration_in_ms=23.137
2019-11-23 08:01:41,411 [salt.state       :1780][INFO    ][17997] Running state [/etc/iptables/rules.v4] at time 08:01:41.411378
2019-11-23 08:01:41,411 [salt.state       :1813][INFO    ][17997] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-23 08:01:41,468 [salt.state       :300 ][INFO    ][17997] File /etc/iptables/rules.v4 is in the correct state
2019-11-23 08:01:41,469 [salt.state       :1951][INFO    ][17997] Completed state [/etc/iptables/rules.v4] at time 08:01:41.469096 duration_in_ms=57.718
2019-11-23 08:01:41,469 [salt.state       :1780][INFO    ][17997] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 08:01:41.469821
2019-11-23 08:01:41,470 [salt.state       :1813][INFO    ][17997] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-23 08:01:41,470 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-23 08:01:41,486 [salt.state       :300 ][INFO    ][17997] onlyif execution failed
2019-11-23 08:01:41,487 [salt.state       :1951][INFO    ][17997] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 08:01:41.486977 duration_in_ms=17.156
2019-11-23 08:01:41,487 [salt.state       :1780][INFO    ][17997] Running state [netfilter-persistent] at time 08:01:41.487646
2019-11-23 08:01:41,487 [salt.state       :1813][INFO    ][17997] Executing state service.running for [netfilter-persistent]
2019-11-23 08:01:41,488 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:41,506 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-23 08:01:41,522 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-23 08:01:41,537 [salt.state       :300 ][INFO    ][17997] The service netfilter-persistent is already running
2019-11-23 08:01:41,538 [salt.state       :1951][INFO    ][17997] Completed state [netfilter-persistent] at time 08:01:41.538189 duration_in_ms=50.543
2019-11-23 08:01:41,538 [salt.state       :1780][INFO    ][17997] Running state [iptables_extra.remove_stale_tables] at time 08:01:41.538765
2019-11-23 08:01:41,539 [salt.state       :1813][INFO    ][17997] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-23 08:01:41,539 [salt.state       :300 ][INFO    ][17997] No changes made for iptables_extra.remove_stale_tables
2019-11-23 08:01:41,539 [salt.state       :1951][INFO    ][17997] Completed state [iptables_extra.remove_stale_tables] at time 08:01:41.539391 duration_in_ms=0.626
2019-11-23 08:01:41,539 [salt.state       :1780][INFO    ][17997] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 08:01:41.539575
2019-11-23 08:01:41,539 [salt.state       :1813][INFO    ][17997] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-23 08:01:41,540 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17997] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-23 08:01:41,553 [salt.state       :300 ][INFO    ][17997] onlyif execution failed
2019-11-23 08:01:41,553 [salt.state       :1951][INFO    ][17997] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 08:01:41.553936 duration_in_ms=14.36
2019-11-23 08:01:41,554 [salt.state       :1780][INFO    ][17997] Running state [/etc/iptables/rules.v6] at time 08:01:41.554618
2019-11-23 08:01:41,554 [salt.state       :1813][INFO    ][17997] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-23 08:01:41,555 [salt.state       :300 ][INFO    ][17997] File /etc/iptables/rules.v6 is not present
2019-11-23 08:01:41,555 [salt.state       :1951][INFO    ][17997] Completed state [/etc/iptables/rules.v6] at time 08:01:41.555330 duration_in_ms=0.712
2019-11-23 08:01:41,555 [salt.state       :1780][INFO    ][17997] Running state [iptables_extra.flush_all] at time 08:01:41.555804
2019-11-23 08:01:41,556 [salt.state       :1813][INFO    ][17997] Executing state module.wait for [iptables_extra.flush_all]
2019-11-23 08:01:41,556 [salt.state       :300 ][INFO    ][17997] No changes made for iptables_extra.flush_all
2019-11-23 08:01:41,556 [salt.state       :1951][INFO    ][17997] Completed state [iptables_extra.flush_all] at time 08:01:41.556366 duration_in_ms=0.562
2019-11-23 08:01:41,558 [salt.minion      :1711][INFO    ][17997] Returning information for job: 20191123080133709122
2019-11-23 08:01:42,158 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123080142145754
2019-11-23 08:01:42,177 [salt.minion      :1432][INFO    ][18087] Starting a new job with PID 18087
2019-11-23 08:01:42,957 [salt.state       :915 ][INFO    ][18087] Loading fresh modules for state activity
2019-11-23 08:01:43,577 [salt.state       :1780][INFO    ][18087] Running state [maas-rack-controller] at time 08:01:43.577290
2019-11-23 08:01:43,577 [salt.state       :1813][INFO    ][18087] Executing state pkg.installed for [maas-rack-controller]
2019-11-23 08:01:43,578 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18087] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-23 08:01:43,656 [salt.state       :300 ][INFO    ][18087] All specified packages are already installed
2019-11-23 08:01:43,656 [salt.state       :1951][INFO    ][18087] Completed state [maas-rack-controller] at time 08:01:43.656345 duration_in_ms=79.055
2019-11-23 08:01:43,656 [salt.state       :1780][INFO    ][18087] Running state [ipmitool] at time 08:01:43.656594
2019-11-23 08:01:43,656 [salt.state       :1813][INFO    ][18087] Executing state pkg.installed for [ipmitool]
2019-11-23 08:01:43,661 [salt.state       :300 ][INFO    ][18087] All specified packages are already installed
2019-11-23 08:01:43,661 [salt.state       :1951][INFO    ][18087] Completed state [ipmitool] at time 08:01:43.661395 duration_in_ms=4.801
2019-11-23 08:01:43,663 [salt.state       :1780][INFO    ][18087] Running state [/etc/maas/rackd.conf] at time 08:01:43.663672
2019-11-23 08:01:43,663 [salt.state       :1813][INFO    ][18087] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-23 08:01:43,664 [salt.state       :300 ][INFO    ][18087] No changes needed to be made
2019-11-23 08:01:43,664 [salt.state       :1951][INFO    ][18087] Completed state [/etc/maas/rackd.conf] at time 08:01:43.664817 duration_in_ms=1.145
2019-11-23 08:01:43,665 [salt.state       :1780][INFO    ][18087] Running state [/etc/maas/rackd.conf] at time 08:01:43.664981
2019-11-23 08:01:43,665 [salt.state       :1813][INFO    ][18087] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-23 08:01:43,665 [salt.loaded.int.states.file:2298][WARNING ][18087] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-11-23 08:01:43,665 [salt.state       :300 ][INFO    ][18087] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-23 08:01:43,665 [salt.state       :1951][INFO    ][18087] Completed state [/etc/maas/rackd.conf] at time 08:01:43.665870 duration_in_ms=0.888
2019-11-23 08:01:43,666 [salt.state       :1780][INFO    ][18087] Running state [maas-rackd] at time 08:01:43.666570
2019-11-23 08:01:43,666 [salt.state       :1813][INFO    ][18087] Executing state service.running for [maas-rackd]
2019-11-23 08:01:43,667 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18087] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:43,698 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18087] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-23 08:01:43,714 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18087] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-23 08:01:43,729 [salt.state       :300 ][INFO    ][18087] The service maas-rackd is already running
2019-11-23 08:01:43,729 [salt.state       :1951][INFO    ][18087] Completed state [maas-rackd] at time 08:01:43.729772 duration_in_ms=63.202
2019-11-23 08:01:43,730 [salt.minion      :1711][INFO    ][18087] Returning information for job: 20191123080142145754
2019-11-23 08:01:44,326 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123080144313595
2019-11-23 08:01:44,349 [salt.minion      :1432][INFO    ][18110] Starting a new job with PID 18110
2019-11-23 08:01:45,111 [salt.state       :915 ][INFO    ][18110] Loading fresh modules for state activity
2019-11-23 08:01:45,888 [salt.state       :1780][INFO    ][18110] Running state [maas-region-controller] at time 08:01:45.888175
2019-11-23 08:01:45,888 [salt.state       :1813][INFO    ][18110] Executing state pkg.installed for [maas-region-controller]
2019-11-23 08:01:45,889 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-23 08:01:45,980 [salt.state       :300 ][INFO    ][18110] All specified packages are already installed
2019-11-23 08:01:45,981 [salt.state       :1951][INFO    ][18110] Completed state [maas-region-controller] at time 08:01:45.981292 duration_in_ms=93.117
2019-11-23 08:01:45,981 [salt.state       :1780][INFO    ][18110] Running state [python-oauth] at time 08:01:45.981663
2019-11-23 08:01:45,982 [salt.state       :1813][INFO    ][18110] Executing state pkg.installed for [python-oauth]
2019-11-23 08:01:45,988 [salt.state       :300 ][INFO    ][18110] All specified packages are already installed
2019-11-23 08:01:45,989 [salt.state       :1951][INFO    ][18110] Completed state [python-oauth] at time 08:01:45.989070 duration_in_ms=7.407
2019-11-23 08:01:45,992 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/regiond.conf] at time 08:01:45.992458
2019-11-23 08:01:45,992 [salt.state       :1813][INFO    ][18110] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-23 08:01:45,997 [salt.state       :300 ][INFO    ][18110] No changes needed to be made
2019-11-23 08:01:45,997 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/regiond.conf] at time 08:01:45.997697 duration_in_ms=5.239
2019-11-23 08:01:45,998 [salt.state       :1780][INFO    ][18110] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:01:45.998133
2019-11-23 08:01:45,998 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-23 08:01:46,058 [salt.state       :300 ][INFO    ][18110] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-23 08:01:46,059 [salt.state       :1951][INFO    ][18110] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:01:46.059060 duration_in_ms=60.927
2019-11-23 08:01:46,059 [salt.state       :1780][INFO    ][18110] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:01:46.059950
2019-11-23 08:01:46,060 [salt.state       :1813][INFO    ][18110] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-23 08:01:46,064 [salt.state       :300 ][INFO    ][18110] No changes needed to be made
2019-11-23 08:01:46,064 [salt.state       :1951][INFO    ][18110] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:01:46.064288 duration_in_ms=4.338
2019-11-23 08:01:46,064 [salt.state       :1780][INFO    ][18110] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:01:46.064719
2019-11-23 08:01:46,064 [salt.state       :1813][INFO    ][18110] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-23 08:01:46,067 [salt.state       :300 ][INFO    ][18110] No changes needed to be made
2019-11-23 08:01:46,068 [salt.state       :1951][INFO    ][18110] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:01:46.068073 duration_in_ms=3.354
2019-11-23 08:01:46,068 [salt.state       :1780][INFO    ][18110] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:01:46.068482
2019-11-23 08:01:46,068 [salt.state       :1813][INFO    ][18110] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-23 08:01:46,090 [salt.state       :300 ][INFO    ][18110] No changes needed to be made
2019-11-23 08:01:46,090 [salt.state       :1951][INFO    ][18110] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:01:46.090336 duration_in_ms=21.855
2019-11-23 08:01:46,090 [salt.state       :1780][INFO    ][18110] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:01:46.090742
2019-11-23 08:01:46,090 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-23 08:01:46,101 [salt.state       :300 ][INFO    ][18110] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-23 08:01:46,102 [salt.state       :1951][INFO    ][18110] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:01:46.102132 duration_in_ms=11.39
2019-11-23 08:01:46,104 [salt.state       :1780][INFO    ][18110] Running state [a2enmod headers] at time 08:01:46.104593
2019-11-23 08:01:46,104 [salt.state       :1813][INFO    ][18110] Executing state cmd.run for [a2enmod headers]
2019-11-23 08:01:46,105 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command 'a2enmod headers' in directory '/root'
2019-11-23 08:01:46,179 [salt.state       :300 ][INFO    ][18110] {'pid': 18129, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-23 08:01:46,179 [salt.state       :1951][INFO    ][18110] Completed state [a2enmod headers] at time 08:01:46.179737 duration_in_ms=75.142
2019-11-23 08:01:46,180 [salt.state       :1780][INFO    ][18110] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:01:46.180370
2019-11-23 08:01:46,181 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-23 08:01:46,200 [salt.state       :300 ][INFO    ][18110] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-23 08:01:46,201 [salt.state       :1951][INFO    ][18110] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:01:46.201022 duration_in_ms=20.651
2019-11-23 08:01:46,202 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:01:46.202045
2019-11-23 08:01:46,202 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-23 08:01:46,260 [salt.state       :300 ][INFO    ][18110] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-23 08:01:46,261 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:01:46.261202 duration_in_ms=59.156
2019-11-23 08:01:46,262 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:01:46.261945
2019-11-23 08:01:46,262 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-23 08:01:46,312 [salt.state       :300 ][INFO    ][18110] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-23 08:01:46,313 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:01:46.313069 duration_in_ms=51.124
2019-11-23 08:01:46,313 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:01:46.313665
2019-11-23 08:01:46,313 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-23 08:01:46,359 [salt.state       :300 ][INFO    ][18110] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-23 08:01:46,359 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:01:46.359657 duration_in_ms=45.992
2019-11-23 08:01:46,360 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 08:01:46.360187
2019-11-23 08:01:46,360 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic]
2019-11-23 08:01:46,401 [salt.state       :300 ][INFO    ][18110] File /etc/maas/preseeds/curtin_userdata_amd64_generic_bionic is in the correct state
2019-11-23 08:01:46,401 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_bionic] at time 08:01:46.401688 duration_in_ms=41.501
2019-11-23 08:01:46,402 [salt.state       :1780][INFO    ][18110] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 08:01:46.402175
2019-11-23 08:01:46,402 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic]
2019-11-23 08:01:46,437 [salt.state       :300 ][INFO    ][18110] File /etc/maas/preseeds/curtin_userdata_arm64_generic_bionic is in the correct state
2019-11-23 08:01:46,437 [salt.state       :1951][INFO    ][18110] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_bionic] at time 08:01:46.437365 duration_in_ms=35.19
2019-11-23 08:01:46,437 [salt.state       :1780][INFO    ][18110] Running state [/root/.pgpass] at time 08:01:46.437625
2019-11-23 08:01:46,437 [salt.state       :1813][INFO    ][18110] Executing state file.managed for [/root/.pgpass]
2019-11-23 08:01:46,469 [salt.state       :300 ][INFO    ][18110] File /root/.pgpass is in the correct state
2019-11-23 08:01:46,469 [salt.state       :1951][INFO    ][18110] Completed state [/root/.pgpass] at time 08:01:46.469653 duration_in_ms=32.028
2019-11-23 08:01:46,474 [salt.state       :1780][INFO    ][18110] Running state [maas-region syncdb --noinput] at time 08:01:46.474097
2019-11-23 08:01:46,474 [salt.state       :1813][INFO    ][18110] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-23 08:01:46,474 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-23 08:01:48,522 [salt.state       :300 ][INFO    ][18110] {'pid': 18146, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: auth, maasserver, sites, piston3, sessions, contenttypes, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-23 08:01:48,523 [salt.state       :1951][INFO    ][18110] Completed state [maas-region syncdb --noinput] at time 08:01:48.523612 duration_in_ms=2049.514
2019-11-23 08:01:48,524 [salt.state       :2022][WARNING ][18110] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-23 08:01:48,527 [salt.state       :1780][INFO    ][18110] Running state [maas-regiond] at time 08:01:48.527038
2019-11-23 08:01:48,527 [salt.state       :1813][INFO    ][18110] Executing state service.running for [maas-regiond]
2019-11-23 08:01:48,529 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:48,568 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-23 08:01:48,586 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-23 08:01:48,603 [salt.state       :300 ][INFO    ][18110] The service maas-regiond is already running
2019-11-23 08:01:48,604 [salt.state       :1951][INFO    ][18110] Completed state [maas-regiond] at time 08:01:48.604064 duration_in_ms=77.026
2019-11-23 08:01:48,606 [salt.state       :1780][INFO    ][18110] Running state [bind9] at time 08:01:48.606485
2019-11-23 08:01:48,606 [salt.state       :1813][INFO    ][18110] Executing state service.running for [bind9]
2019-11-23 08:01:48,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:48,626 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-23 08:01:48,643 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-23 08:01:48,659 [salt.state       :300 ][INFO    ][18110] The service bind9 is already running
2019-11-23 08:01:48,660 [salt.state       :1951][INFO    ][18110] Completed state [bind9] at time 08:01:48.659963 duration_in_ms=53.485
2019-11-23 08:01:48,662 [salt.state       :1780][INFO    ][18110] Running state [apache2] at time 08:01:48.662185
2019-11-23 08:01:48,662 [salt.state       :1813][INFO    ][18110] Executing state service.running for [apache2]
2019-11-23 08:01:48,663 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-23 08:01:48,682 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-23 08:01:48,698 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-23 08:01:48,719 [salt.state       :300 ][INFO    ][18110] The service apache2 is already running
2019-11-23 08:01:48,720 [salt.state       :1951][INFO    ][18110] Completed state [apache2] at time 08:01:48.719914 duration_in_ms=57.729
2019-11-23 08:01:48,721 [salt.state       :1780][INFO    ][18110] Running state [maasng.wait_for_http_code] at time 08:01:48.721714
2019-11-23 08:01:48,722 [salt.state       :1813][INFO    ][18110] Executing state module.run for [maasng.wait_for_http_code]
2019-11-23 08:01:48,722 [salt.utils.decorators:613 ][WARNING ][18110] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:01:48,853 [salt.state       :300 ][INFO    ][18110] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-23 08:01:48,853 [salt.state       :1951][INFO    ][18110] Completed state [maasng.wait_for_http_code] at time 08:01:48.853853 duration_in_ms=132.139
2019-11-23 08:01:48,855 [salt.state       :1780][INFO    ][18110] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:01:48.855330
2019-11-23 08:01:48,855 [salt.state       :1813][INFO    ][18110] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-23 08:01:48,856 [salt.state       :300 ][INFO    ][18110] /var/lib/maas/.setup_admin exists
2019-11-23 08:01:48,857 [salt.state       :1951][INFO    ][18110] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:01:48.857029 duration_in_ms=1.699
2019-11-23 08:01:48,858 [salt.state       :1780][INFO    ][18110] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:01:48.858211
2019-11-23 08:01:48,858 [salt.state       :1813][INFO    ][18110] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:01:48,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18110] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:01:50,357 [salt.state       :300 ][INFO    ][18110] {'pid': 18167, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:01:50,358 [salt.state       :1951][INFO    ][18110] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:01:50.358532 duration_in_ms=1500.32
2019-11-23 08:01:50,367 [salt.state       :1780][INFO    ][18110] Running state [maas_region_boot_source_resources_mirror] at time 08:01:50.367330
2019-11-23 08:01:50,367 [salt.state       :1813][INFO    ][18110] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-23 08:01:50,471 [salt.state       :300 ][INFO    ][18110] {'changes': {}}
2019-11-23 08:01:50,471 [salt.state       :1951][INFO    ][18110] Completed state [maas_region_boot_source_resources_mirror] at time 08:01:50.471680 duration_in_ms=104.35
2019-11-23 08:01:50,472 [salt.state       :1780][INFO    ][18110] Running state [maasng.boot_resources_import] at time 08:01:50.472832
2019-11-23 08:01:50,473 [salt.state       :1813][INFO    ][18110] Executing state module.run for [maasng.boot_resources_import]
2019-11-23 08:01:50,473 [salt.utils.decorators:613 ][WARNING ][18110] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:01:50,597 [salt.loaded.ext.module.maasng:1600][INFO    ][18110] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-23 08:01:55,676 [salt.loaded.ext.module.maasng:1600][INFO    ][18110] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-23 08:01:59,391 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080159376558
2019-11-23 08:01:59,415 [salt.minion      :1432][INFO    ][18194] Starting a new job with PID 18194
2019-11-23 08:01:59,437 [salt.minion      :1711][INFO    ][18194] Returning information for job: 20191123080159376558
2019-11-23 08:02:00,737 [salt.loaded.ext.module.maasng:1600][INFO    ][18110] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-23 08:02:05,851 [salt.state       :300 ][INFO    ][18110] {'ret': True}
2019-11-23 08:02:05,852 [salt.state       :1951][INFO    ][18110] Completed state [maasng.boot_resources_import] at time 08:02:05.852409 duration_in_ms=15379.577
2019-11-23 08:02:05,853 [salt.state       :1780][INFO    ][18110] Running state [maas_region_boot_sources_selection_bionic] at time 08:02:05.853754
2019-11-23 08:02:05,854 [salt.state       :1813][INFO    ][18110] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_bionic]
2019-11-23 08:02:06,087 [salt.state       :300 ][INFO    ][18110] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-23 08:02:06,087 [salt.state       :1951][INFO    ][18110] Completed state [maas_region_boot_sources_selection_bionic] at time 08:02:06.087617 duration_in_ms=233.862
2019-11-23 08:02:06,089 [salt.state       :1780][INFO    ][18110] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 08:02:06.089349
2019-11-23 08:02:06,090 [salt.state       :1813][INFO    ][18110] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-23 08:02:06,090 [salt.utils.decorators:613 ][WARNING ][18110] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:02:06,091 [salt.loaded.ext.module.maasng:1771][INFO    ][18110] boot-sources sync initiated for ALL Rack's
2019-11-23 08:02:06,988 [salt.state       :300 ][INFO    ][18110] {'ret': True}
2019-11-23 08:02:06,989 [salt.state       :1951][INFO    ][18110] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 08:02:06.989177 duration_in_ms=899.827
2019-11-23 08:02:06,991 [salt.state       :1780][INFO    ][18110] Running state [maas.process_maas_config] at time 08:02:06.991342
2019-11-23 08:02:06,991 [salt.state       :1813][INFO    ][18110] Executing state module.run for [maas.process_maas_config]
2019-11-23 08:02:06,992 [salt.utils.decorators:613 ][WARNING ][18110] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:02:06,993 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=enable_http_proxy value=True
2019-11-23 08:02:07,062 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=upstream_dns value=8.8.8.8
2019-11-23 08:02:07,135 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=commissioning_distro_series value=bionic
2019-11-23 08:02:25,547 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=default_osystem value=ubuntu
2019-11-23 08:02:25,606 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=active_discovery_interval value=600
2019-11-23 08:02:25,659 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=dnssec_validation value=no
2019-11-23 08:02:25,701 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=maas_name value=mas01
2019-11-23 08:02:25,755 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=network_discovery value=enabled
2019-11-23 08:02:25,869 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=enable_third_party_drivers value=True
2019-11-23 08:02:25,917 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=default_storage_layout value=lvm
2019-11-23 08:02:25,971 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=ntp_external_only value=True
2019-11-23 08:02:26,044 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-23 08:02:26,096 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=default_distro_series value=bionic
2019-11-23 08:02:26,156 [salt.loaded.ext.module.maas:92  ][INFO    ][18110] maasconfig name=default_min_hwe_kernel value=ga-18.04
2019-11-23 08:02:26,252 [salt.state       :300 ][INFO    ][18110] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-11-23 08:02:26,252 [salt.state       :1951][INFO    ][18110] Completed state [maas.process_maas_config] at time 08:02:26.252616 duration_in_ms=19261.274
2019-11-23 08:02:26,253 [salt.state       :1780][INFO    ][18110] Running state [pxe_admin] at time 08:02:26.253567
2019-11-23 08:02:26,254 [salt.state       :1813][INFO    ][18110] Executing state maasng.fabric_present for [pxe_admin]
2019-11-23 08:02:26,317 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:26,390 [salt.loaded.ext.module.maasng:1008][WARNING ][18110] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-23 08:02:26,390 [salt.loaded.ext.module.maasng:1011][WARNING ][18110] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-23 08:02:26,456 [salt.state       :300 ][INFO    ][18110] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-23 08:02:26,456 [salt.state       :1951][INFO    ][18110] Completed state [pxe_admin] at time 08:02:26.456797 duration_in_ms=203.23
2019-11-23 08:02:26,457 [salt.state       :1780][INFO    ][18110] Running state [vlan 0] at time 08:02:26.457250
2019-11-23 08:02:26,457 [salt.state       :1813][INFO    ][18110] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-23 08:02:26,497 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:26,624 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:26,947 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, 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'external_dhcp': None, 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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:27,042 [salt.state       :300 ][INFO    ][18110] {'new': 'Vlan untagged was updated'}
2019-11-23 08:02:27,043 [salt.state       :1951][INFO    ][18110] Completed state [vlan 0] at time 08:02:27.042908 duration_in_ms=585.657
2019-11-23 08:02:27,044 [salt.state       :1780][INFO    ][18110] Running state [192.168.11.0/24] at time 08:02:27.044454
2019-11-23 08:02:27,045 [salt.state       :1813][INFO    ][18110] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-23 08:02:27,257 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:27,258 [salt.loaded.ext.module.maasng:1235][WARNING ][18110] Ignoring parameter vlan:0
2019-11-23 08:02:27,330 [salt.state       :300 ][INFO    ][18110] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-23 08:02:27,331 [salt.state       :1951][INFO    ][18110] Completed state [192.168.11.0/24] at time 08:02:27.330936 duration_in_ms=286.482
2019-11-23 08:02:27,332 [salt.state       :1780][INFO    ][18110] Running state [maas_create_iprange_1] at time 08:02:27.332195
2019-11-23 08:02:27,332 [salt.state       :1813][INFO    ][18110] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-23 08:02:27,371 [salt.state       :300 ][INFO    ][18110] Iprange maas_create_iprange_1 already exist.
2019-11-23 08:02:27,372 [salt.state       :1951][INFO    ][18110] Completed state [maas_create_iprange_1] at time 08:02:27.372120 duration_in_ms=39.925
2019-11-23 08:02:27,372 [salt.state       :1780][INFO    ][18110] Running state [vlan 0] at time 08:02:27.372544
2019-11-23 08:02:27,372 [salt.state       :1813][INFO    ][18110] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-23 08:02:27,432 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'nesnbq', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-11-23 08:02:27,527 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'nesnbq', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-23 08:02:27,790 [salt.loaded.ext.module.maasng:945 ][INFO    ][18110] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'nesnbq', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-23 08:02:27,874 [salt.state       :300 ][INFO    ][18110] {'new': 'Vlan untagged was updated'}
2019-11-23 08:02:27,875 [salt.state       :1951][INFO    ][18110] Completed state [vlan 0] at time 08:02:27.875154 duration_in_ms=502.61
2019-11-23 08:02:27,875 [salt.state       :1780][INFO    ][18110] Running state [opnfv] at time 08:02:27.875684
2019-11-23 08:02:27,875 [salt.state       :1813][INFO    ][18110] Executing state maasng.sshkey_present for [opnfv]
2019-11-23 08:02:27,928 [salt.loaded.ext.module.maasng:1903][INFO    ][18110] [{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-11-23 08:02:27,929 [salt.state       :300 ][INFO    ][18110] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-23 08:02:27,929 [salt.state       :1951][INFO    ][18110] Completed state [opnfv] at time 08:02:27.929323 duration_in_ms=53.638
2019-11-23 08:02:27,933 [salt.minion      :1711][INFO    ][18110] Returning information for job: 20191123080144313595
2019-11-23 08:02:28,539 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123080228528450
2019-11-23 08:02:28,557 [salt.minion      :1432][INFO    ][18497] Starting a new job with PID 18497
2019-11-23 08:02:32,418 [salt.state       :915 ][INFO    ][18497] Loading fresh modules for state activity
2019-11-23 08:02:32,503 [salt.state       :1780][INFO    ][18497] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:02:32.503390
2019-11-23 08:02:32,503 [salt.state       :1813][INFO    ][18497] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:02:32,505 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18497] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:02:34,143 [salt.state       :300 ][INFO    ][18497] {'pid': 18522, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:02:34,144 [salt.state       :1951][INFO    ][18497] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:02:34.144355 duration_in_ms=1640.964
2019-11-23 08:02:34,147 [salt.state       :1780][INFO    ][18497] Running state [maas.process_machines] at time 08:02:34.146942
2019-11-23 08:02:34,147 [salt.state       :1813][INFO    ][18497] Executing state module.run for [maas.process_machines]
2019-11-23 08:02:34,148 [salt.utils.decorators:613 ][WARNING ][18497] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:02:34,929 [salt.loaded.ext.module.maas:412 ][WARNING ][18497] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 08:02:34,930 [salt.loaded.ext.module.maas:92  ][INFO    ][18497] 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=88ks4w architecture=amd64/generic power_parameters_power_user=admin
2019-11-23 08:02:36,181 [salt.loaded.ext.module.maas:412 ][WARNING ][18497] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 08:02:36,182 [salt.loaded.ext.module.maas:92  ][INFO    ][18497] 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=dqwar4 architecture=amd64/generic power_parameters_power_user=admin
2019-11-23 08:02:37,470 [salt.loaded.ext.module.maas:412 ][WARNING ][18497] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 08:02:37,470 [salt.loaded.ext.module.maas:92  ][INFO    ][18497] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=tc7bt7 architecture=amd64/generic power_parameters_power_user=admin
2019-11-23 08:02:38,649 [salt.loaded.ext.module.maas:412 ][WARNING ][18497] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 08:02:38,650 [salt.loaded.ext.module.maas:92  ][INFO    ][18497] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=cp3bf6 architecture=amd64/generic power_parameters_power_user=admin
2019-11-23 08:02:39,875 [salt.loaded.ext.module.maas:412 ][WARNING ][18497] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-23 08:02:39,877 [salt.loaded.ext.module.maas:92  ][INFO    ][18497] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=ned48r architecture=amd64/generic power_parameters_power_user=admin
2019-11-23 08:02:41,188 [salt.state       :300 ][INFO    ][18497] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-23 08:02:41,188 [salt.state       :1951][INFO    ][18497] Completed state [maas.process_machines] at time 08:02:41.188585 duration_in_ms=7041.642
2019-11-23 08:02:41,192 [salt.minion      :1711][INFO    ][18497] Returning information for job: 20191123080228528450
2019-11-23 08:03:14,364 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123080314351062
2019-11-23 08:03:14,385 [salt.minion      :1432][INFO    ][18783] Starting a new job with PID 18783
2019-11-23 08:03:18,188 [salt.state       :915 ][INFO    ][18783] Loading fresh modules for state activity
2019-11-23 08:03:18,275 [salt.state       :1780][INFO    ][18783] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:03:18.275771
2019-11-23 08:03:18,276 [salt.state       :1813][INFO    ][18783] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:03:18,279 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18783] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:03:19,665 [salt.state       :300 ][INFO    ][18783] {'pid': 18790, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:03:19,665 [salt.state       :1951][INFO    ][18783] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:03:19.665742 duration_in_ms=1389.971
2019-11-23 08:03:19,668 [salt.state       :1780][INFO    ][18783] Running state [maas.wait_for_machine_status] at time 08:03:19.668767
2019-11-23 08:03:19,669 [salt.state       :1813][INFO    ][18783] Executing state module.run for [maas.wait_for_machine_status]
2019-11-23 08:03:19,669 [salt.utils.decorators:613 ][WARNING ][18783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:03:21,678 [salt.loaded.ext.module.maas:993 ][INFO    ][18783] Machine cp3bf6 mark broken
2019-11-23 08:03:22,217 [salt.loaded.ext.module.maas:996 ][INFO    ][18783] Machine cp3bf6 mark fixed
2019-11-23 08:03:23,491 [salt.loaded.ext.module.maas:684 ][INFO    ][18783] deploymachines hwe_kernel=ga-18.04 system_id=cp3bf6 distro_series=bionic
2019-11-23 08:03:26,810 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1492.86953092s left)
2019-11-23 08:03:29,533 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080329461655
2019-11-23 08:03:29,555 [salt.minion      :1432][INFO    ][18870] Starting a new job with PID 18870
2019-11-23 08:03:29,580 [salt.minion      :1711][INFO    ][18870] Returning information for job: 20191123080329461655
2019-11-23 08:03:59,587 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080359574386
2019-11-23 08:03:59,608 [salt.minion      :1432][INFO    ][18911] Starting a new job with PID 18911
2019-11-23 08:03:59,633 [salt.minion      :1711][INFO    ][18911] Returning information for job: 20191123080359574386
2019-11-23 08:04:00,296 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.38326597s left)
2019-11-23 08:04:29,676 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080429663302
2019-11-23 08:04:29,699 [salt.minion      :1432][INFO    ][18948] Starting a new job with PID 18948
2019-11-23 08:04:29,726 [salt.minion      :1711][INFO    ][18948] Returning information for job: 20191123080429663302
2019-11-23 08:04:33,902 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1425.77725291s left)
2019-11-23 08:04:59,730 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080459715462
2019-11-23 08:04:59,752 [salt.minion      :1432][INFO    ][18979] Starting a new job with PID 18979
2019-11-23 08:04:59,777 [salt.minion      :1711][INFO    ][18979] Returning information for job: 20191123080459715462
2019-11-23 08:05:07,123 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1392.55575895s left)
2019-11-23 08:05:29,774 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080529761444
2019-11-23 08:05:29,792 [salt.minion      :1432][INFO    ][19079] Starting a new job with PID 19079
2019-11-23 08:05:29,815 [salt.minion      :1711][INFO    ][19079] Returning information for job: 20191123080529761444
2019-11-23 08:05:40,668 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.01135206s left)
2019-11-23 08:05:59,823 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080559810050
2019-11-23 08:05:59,845 [salt.minion      :1432][INFO    ][19212] Starting a new job with PID 19212
2019-11-23 08:05:59,871 [salt.minion      :1711][INFO    ][19212] Returning information for job: 20191123080559810050
2019-11-23 08:06:14,152 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1325.52673507s left)
2019-11-23 08:06:29,883 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080629870302
2019-11-23 08:06:29,905 [salt.minion      :1432][INFO    ][19287] Starting a new job with PID 19287
2019-11-23 08:06:29,926 [salt.minion      :1711][INFO    ][19287] Returning information for job: 20191123080629870302
2019-11-23 08:06:47,746 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1291.9327209s left)
2019-11-23 08:06:59,942 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080659928408
2019-11-23 08:06:59,964 [salt.minion      :1432][INFO    ][19376] Starting a new job with PID 19376
2019-11-23 08:06:59,991 [salt.minion      :1711][INFO    ][19376] Returning information for job: 20191123080659928408
2019-11-23 08:07:21,465 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1258.21421409s left)
2019-11-23 08:07:30,011 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080729999124
2019-11-23 08:07:30,034 [salt.minion      :1432][INFO    ][19426] Starting a new job with PID 19426
2019-11-23 08:07:30,059 [salt.minion      :1711][INFO    ][19426] Returning information for job: 20191123080729999124
2019-11-23 08:07:54,896 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1224.78264499s left)
2019-11-23 08:08:00,083 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080800070371
2019-11-23 08:08:00,106 [salt.minion      :1432][INFO    ][19469] Starting a new job with PID 19469
2019-11-23 08:08:00,134 [salt.minion      :1711][INFO    ][19469] Returning information for job: 20191123080800070371
2019-11-23 08:08:28,531 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1191.14759493s left)
2019-11-23 08:08:30,159 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080830146189
2019-11-23 08:08:30,182 [salt.minion      :1432][INFO    ][19522] Starting a new job with PID 19522
2019-11-23 08:08:30,209 [salt.minion      :1711][INFO    ][19522] Returning information for job: 20191123080830146189
2019-11-23 08:09:00,239 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080900226141
2019-11-23 08:09:00,261 [salt.minion      :1432][INFO    ][19597] Starting a new job with PID 19597
2019-11-23 08:09:00,287 [salt.minion      :1711][INFO    ][19597] Returning information for job: 20191123080900226141
2019-11-23 08:09:02,273 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1157.40587997s left)
2019-11-23 08:09:30,330 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123080930314956
2019-11-23 08:09:30,352 [salt.minion      :1432][INFO    ][19663] Starting a new job with PID 19663
2019-11-23 08:09:30,377 [salt.minion      :1711][INFO    ][19663] Returning information for job: 20191123080930314956
2019-11-23 08:09:35,556 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1124.12263894s left)
2019-11-23 08:10:00,414 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123081000401196
2019-11-23 08:10:00,436 [salt.minion      :1432][INFO    ][19769] Starting a new job with PID 19769
2019-11-23 08:10:00,462 [salt.minion      :1711][INFO    ][19769] Returning information for job: 20191123081000401196
2019-11-23 08:10:08,657 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1091.02228689s left)
2019-11-23 08:10:30,507 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123081030494906
2019-11-23 08:10:30,530 [salt.minion      :1432][INFO    ][19817] Starting a new job with PID 19817
2019-11-23 08:10:30,556 [salt.minion      :1711][INFO    ][19817] Returning information for job: 20191123081030494906
2019-11-23 08:10:42,495 [salt.loaded.ext.module.maas:1023][INFO    ][18783] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1057.18445396s left)
2019-11-23 08:11:00,607 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command saltutil.find_job with jid 20191123081100594552
2019-11-23 08:11:00,631 [salt.minion      :1432][INFO    ][19881] Starting a new job with PID 19881
2019-11-23 08:11:00,657 [salt.minion      :1711][INFO    ][19881] Returning information for job: 20191123081100594552
2019-11-23 08:11:16,150 [salt.state       :300 ][INFO    ][18783] {'ret': True}
2019-11-23 08:11:16,150 [salt.state       :1951][INFO    ][18783] Completed state [maas.wait_for_machine_status] at time 08:11:16.150640 duration_in_ms=476481.871
2019-11-23 08:11:16,154 [salt.minion      :1711][INFO    ][18783] Returning information for job: 20191123080314351062
2019-11-23 08:11:16,814 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123081116801580
2019-11-23 08:11:16,837 [salt.minion      :1432][INFO    ][19940] Starting a new job with PID 19940
2019-11-23 08:11:20,737 [salt.state       :915 ][INFO    ][19940] Loading fresh modules for state activity
2019-11-23 08:11:20,872 [salt.state       :1780][INFO    ][19940] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:20.872722
2019-11-23 08:11:20,873 [salt.state       :1813][INFO    ][19940] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:11:20,874 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19940] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:11:22,309 [salt.state       :300 ][INFO    ][19940] {'pid': 19949, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:11:22,310 [salt.state       :1951][INFO    ][19940] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:22.310198 duration_in_ms=1437.477
2019-11-23 08:11:22,311 [salt.state       :1780][INFO    ][19940] Running state [maas_machines_storage_cmp002_lvm] at time 08:11:22.311517
2019-11-23 08:11:22,311 [salt.state       :1813][INFO    ][19940] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-23 08:11:22,745 [salt.state       :300 ][INFO    ][19940] Machine cmp002 is not in Ready state.
2019-11-23 08:11:22,746 [salt.state       :1951][INFO    ][19940] Completed state [maas_machines_storage_cmp002_lvm] at time 08:11:22.746100 duration_in_ms=434.583
2019-11-23 08:11:22,746 [salt.state       :1780][INFO    ][19940] Running state [maas_machines_storage_cmp001_lvm] at time 08:11:22.746356
2019-11-23 08:11:22,746 [salt.state       :1813][INFO    ][19940] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-23 08:11:23,484 [salt.state       :300 ][INFO    ][19940] Machine cmp001 is not in Ready state.
2019-11-23 08:11:23,485 [salt.state       :1951][INFO    ][19940] Completed state [maas_machines_storage_cmp001_lvm] at time 08:11:23.485084 duration_in_ms=738.727
2019-11-23 08:11:23,489 [salt.minion      :1711][INFO    ][19940] Returning information for job: 20191123081116801580
2019-11-23 08:11:24,067 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123081124054116
2019-11-23 08:11:24,087 [salt.minion      :1432][INFO    ][19965] Starting a new job with PID 19965
2019-11-23 08:11:24,882 [salt.state       :915 ][INFO    ][19965] Loading fresh modules for state activity
2019-11-23 08:11:24,970 [salt.state       :1780][INFO    ][19965] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:24.970858
2019-11-23 08:11:24,971 [salt.state       :1813][INFO    ][19965] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:11:24,973 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19965] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:11:26,440 [salt.state       :300 ][INFO    ][19965] {'pid': 19975, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:11:26,441 [salt.state       :1951][INFO    ][19965] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:26.441356 duration_in_ms=1470.499
2019-11-23 08:11:26,442 [salt.state       :1780][INFO    ][19965] Running state [maas.deploy_machines] at time 08:11:26.442579
2019-11-23 08:11:26,442 [salt.state       :1813][INFO    ][19965] Executing state module.run for [maas.deploy_machines]
2019-11-23 08:11:26,443 [salt.utils.decorators:613 ][WARNING ][19965] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:11:27,331 [salt.state       :300 ][INFO    ][19965] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-23 08:11:27,331 [salt.state       :1951][INFO    ][19965] Completed state [maas.deploy_machines] at time 08:11:27.331758 duration_in_ms=889.175
2019-11-23 08:11:27,335 [salt.minion      :1711][INFO    ][19965] Returning information for job: 20191123081124054116
2019-11-23 08:11:27,943 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command state.apply with jid 20191123081127934341
2019-11-23 08:11:27,967 [salt.minion      :1432][INFO    ][19997] Starting a new job with PID 19997
2019-11-23 08:11:28,738 [salt.state       :915 ][INFO    ][19997] Loading fresh modules for state activity
2019-11-23 08:11:28,828 [salt.state       :1780][INFO    ][19997] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:28.828013
2019-11-23 08:11:28,828 [salt.state       :1813][INFO    ][19997] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-23 08:11:28,830 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19997] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-23 08:11:30,315 [salt.state       :300 ][INFO    ][19997] {'pid': 20004, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-23 08:11:30,316 [salt.state       :1951][INFO    ][19997] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:11:30.316036 duration_in_ms=1488.023
2019-11-23 08:11:30,317 [salt.state       :1780][INFO    ][19997] Running state [maas.wait_for_machine_status] at time 08:11:30.317674
2019-11-23 08:11:30,317 [salt.state       :1813][INFO    ][19997] Executing state module.run for [maas.wait_for_machine_status]
2019-11-23 08:11:30,318 [salt.utils.decorators:613 ][WARNING ][19997] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-23 08:11:33,769 [salt.state       :300 ][INFO    ][19997] {'ret': True}
2019-11-23 08:11:33,770 [salt.state       :1951][INFO    ][19997] Completed state [maas.wait_for_machine_status] at time 08:11:33.769950 duration_in_ms=3452.275
2019-11-23 08:11:33,772 [salt.minion      :1711][INFO    ][19997] Returning information for job: 20191123081127934341
2019-11-23 08:41:23,729 [salt.utils.schedule:1377][INFO    ][12234] Running scheduled job: __mine_interval
2019-11-23 09:41:23,730 [salt.utils.schedule:1377][INFO    ][12234] Running scheduled job: __mine_interval
2019-11-23 09:45:55,586 [salt.minion      :1308][INFO    ][12234] User sudo_ubuntu Executing command cp.push_dir with jid 20191123094555573904
2019-11-23 09:45:55,602 [salt.minion      :1432][INFO    ][26570] Starting a new job with PID 26570
