2019-09-01 02:08:17,382 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-01 02:09:07,427 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-01 02:09:57,472 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-01 02:10:47,519 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-01 02:11:37,568 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-09-01 02:13:46,190 [salt.utils.decorators:613 ][WARNING ][2713] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 02:13:46,770 [salt.utils.decorators:613 ][WARNING ][2713] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 02:13:48,813 [salt.loaded.int.states.file:2298][WARNING ][2852] 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-09-01 02:13:54,598 [salt.state       :2022][WARNING ][2963] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-01 02:13:57,180 [salt.utils.decorators:613 ][WARNING ][2963] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 02:29:05,288 [salt.utils.decorators:613 ][WARNING ][2963] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 02:51:53,347 [salt.utils.decorators:613 ][WARNING ][2963] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:06:58,763 [salt.utils.decorators:613 ][WARNING ][2963] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:07:02,372 [salt.loaded.ext.module.maasng:1008][WARNING ][2963] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-09-01 03:07:02,373 [salt.loaded.ext.module.maasng:1011][WARNING ][2963] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-09-01 03:07:03,059 [salt.loaded.ext.module.maasng:1235][WARNING ][2963] Ignoring parameter vlan:0
2019-09-01 03:07:09,504 [salt.utils.decorators:613 ][WARNING ][1084] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:07:09,550 [salt.loaded.ext.module.maas:412 ][WARNING ][1084] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:07:13,833 [salt.loaded.ext.module.maas:412 ][WARNING ][1084] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:07:17,761 [salt.loaded.ext.module.maas:412 ][WARNING ][1084] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:07:20,827 [salt.loaded.ext.module.maas:412 ][WARNING ][1084] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:07:24,953 [salt.loaded.ext.module.maas:412 ][WARNING ][1084] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:07:32,383 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2044] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-01 03:07:32,416 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2044] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-09-01 03:07:32,439 [salt.utils.parsers:1051][WARNING ][359] Minion received a SIGTERM. Exiting.
2019-09-01 03:07:33,510 [salt.cli.daemons :293 ][INFO    ][2089] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-09-01 03:07:33,609 [salt.cli.daemons :82  ][INFO    ][2089] Starting up the Salt Minion
2019-09-01 03:07:33,610 [salt.utils.event :1017][INFO    ][2089] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-09-01 03:07:34,514 [salt.minion      :976 ][INFO    ][2089] Creating minion process manager
2019-09-01 03:07:36,071 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][2089] Executing command ['date', '+%z'] in directory '/root'
2019-09-01 03:07:36,092 [salt.utils.schedule:568 ][INFO    ][2089] Updating job settings for scheduled job: __mine_interval
2019-09-01 03:07:36,093 [salt.minion      :1108][INFO    ][2089] Added mine.update to scheduler
2019-09-01 03:07:36,098 [salt.minion      :1975][INFO    ][2089] Minion is starting as user 'root'
2019-09-01 03:07:36,113 [salt.minion      :2336][INFO    ][2089] Minion is ready to receive requests!
2019-09-01 03:08:00,681 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901030800667916
2019-09-01 03:08:00,704 [salt.minion      :1432][INFO    ][2217] Starting a new job with PID 2217
2019-09-01 03:08:04,423 [salt.state       :915 ][INFO    ][2217] Loading fresh modules for state activity
2019-09-01 03:08:04,475 [salt.fileclient  :1219][INFO    ][2217] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-09-01 03:08:04,515 [salt.state       :1780][INFO    ][2217] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:08:04.515580
2019-09-01 03:08:04,516 [salt.state       :1813][INFO    ][2217] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:08:04,518 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2217] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:08:05,998 [salt.state       :300 ][INFO    ][2217] {'pid': 2225, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:08:05,999 [salt.state       :1951][INFO    ][2217] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:08:05.999545 duration_in_ms=1483.964
2019-09-01 03:08:06,001 [salt.state       :1780][INFO    ][2217] Running state [maas.wait_for_machine_status] at time 03:08:06.001469
2019-09-01 03:08:06,002 [salt.state       :1813][INFO    ][2217] Executing state module.run for [maas.wait_for_machine_status]
2019-09-01 03:08:06,002 [salt.utils.decorators:613 ][WARNING ][2217] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:08:06,906 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.10342884s left)
2019-09-01 03:08:15,698 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901030815686227
2019-09-01 03:08:15,721 [salt.minion      :1432][INFO    ][2237] Starting a new job with PID 2237
2019-09-01 03:08:15,744 [salt.minion      :1711][INFO    ][2237] Returning information for job: 20190901030815686227
2019-09-01 03:08:37,913 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.0971508s left)
2019-09-01 03:08:45,750 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901030845737227
2019-09-01 03:08:45,772 [salt.minion      :1432][INFO    ][2257] Starting a new job with PID 2257
2019-09-01 03:08:45,795 [salt.minion      :1711][INFO    ][2257] Returning information for job: 20190901030845737227
2019-09-01 03:09:09,038 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.9722209s left)
2019-09-01 03:09:15,832 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901030915820626
2019-09-01 03:09:15,854 [salt.minion      :1432][INFO    ][2495] Starting a new job with PID 2495
2019-09-01 03:09:15,877 [salt.minion      :1711][INFO    ][2495] Returning information for job: 20190901030915820626
2019-09-01 03:09:40,285 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.72479296s left)
2019-09-01 03:09:45,883 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901030945870879
2019-09-01 03:09:45,902 [salt.minion      :1432][INFO    ][2644] Starting a new job with PID 2644
2019-09-01 03:09:45,918 [salt.minion      :1711][INFO    ][2644] Returning information for job: 20190901030945870879
2019-09-01 03:10:11,864 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.14567685s left)
2019-09-01 03:10:15,914 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031015902287
2019-09-01 03:10:15,933 [salt.minion      :1432][INFO    ][3476] Starting a new job with PID 3476
2019-09-01 03:10:15,955 [salt.minion      :1711][INFO    ][3476] Returning information for job: 20190901031015902287
2019-09-01 03:10:43,773 [salt.loaded.ext.module.maas:1023][INFO    ][2217] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.23676991s left)
2019-09-01 03:10:45,963 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031045950073
2019-09-01 03:10:45,986 [salt.minion      :1432][INFO    ][3718] Starting a new job with PID 3718
2019-09-01 03:10:46,009 [salt.minion      :1711][INFO    ][3718] Returning information for job: 20190901031045950073
2019-09-01 03:11:16,027 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031116014006
2019-09-01 03:11:16,049 [salt.minion      :1432][INFO    ][3960] Starting a new job with PID 3960
2019-09-01 03:11:16,072 [salt.minion      :1711][INFO    ][3960] Returning information for job: 20190901031116014006
2019-09-01 03:11:17,774 [salt.state       :300 ][INFO    ][2217] {'ret': True}
2019-09-01 03:11:17,774 [salt.state       :1951][INFO    ][2217] Completed state [maas.wait_for_machine_status] at time 03:11:17.774441 duration_in_ms=191772.97
2019-09-01 03:11:17,778 [salt.minion      :1711][INFO    ][2217] Returning information for job: 20190901030800667916
2019-09-01 03:11:18,415 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031118402592
2019-09-01 03:11:18,438 [salt.minion      :1432][INFO    ][3977] Starting a new job with PID 3977
2019-09-01 03:11:22,191 [salt.state       :915 ][INFO    ][3977] Loading fresh modules for state activity
2019-09-01 03:11:22,242 [salt.fileclient  :1219][INFO    ][3977] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-09-01 03:11:22,327 [salt.state       :1780][INFO    ][3977] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:11:22.327406
2019-09-01 03:11:22,327 [salt.state       :1813][INFO    ][3977] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:11:22,329 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3977] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:11:23,656 [salt.state       :300 ][INFO    ][3977] {'pid': 3991, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:11:23,656 [salt.state       :1951][INFO    ][3977] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:11:23.656797 duration_in_ms=1329.391
2019-09-01 03:11:23,659 [salt.state       :1780][INFO    ][3977] Running state [maas_machines_storage_cmp002_lvm] at time 03:11:23.659245
2019-09-01 03:11:23,659 [salt.state       :1813][INFO    ][3977] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-01 03:11:25,123 [salt.loaded.ext.module.maasng:610 ][INFO    ][3977] cn4wby
2019-09-01 03:11:25,124 [salt.loaded.ext.module.maasng:626 ][INFO    ][3977] sda
2019-09-01 03:11:25,917 [salt.loaded.ext.module.maasng:361 ][INFO    ][3977] cn4wby
2019-09-01 03:11:26,048 [salt.loaded.ext.module.maasng:367 ][INFO    ][3977] [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 2, u'used_for': u'GPT partitioned with 1 partition', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/', u'system_id': u'cn4wby', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'be1df175-77ec-4431-8861-055104091c65', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cn4wby', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'766d8d47-a2e9-4c0c-bb52-7cb77f333ee6'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/partition/2', u'type': u'partition', u'id': 2, u'device_id': 2}]}, {u'size': 2397988454400, u'block_size': 4096, u'uuid': u'64411ed4-886b-49fb-ad12-aa74fa2b7632', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'id': 7, u'used_for': u'ext4 formatted filesystem mounted at /', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/7/', u'system_id': u'cn4wby', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'3287d276-538a-429b-8ecd-c87699eb96e3'}, u'id_path': None, u'available_size': 0, u'serial': None, u'path': u'/dev/disk/by-dname/lvroot', u'type': u'virtual', u'model': None, u'partitions': []}]
2019-09-01 03:11:26,049 [salt.loaded.ext.module.maasng:632 ][INFO    ][3977] vgroot
2019-09-01 03:11:26,049 [salt.loaded.ext.module.maasng:635 ][INFO    ][3977] lvroot
2019-09-01 03:11:26,050 [salt.loaded.ext.module.maasng:639 ][INFO    ][3977] 107374182400
2019-09-01 03:11:26,787 [salt.loaded.ext.module.maasng:645 ][INFO    ][3977] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'id': 22, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'system_id': u'cn4wby', u'mac_address': u'00:25:b5:a0:00:6a', u'id': 4, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/interfaces/4/'}, u'ip_addresses': [u'192.168.11.41'], u'storage_test_status_name': u'Passed', u'owner_data': {}, 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'min_hwe_kernel': u'ga-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'cn4wby', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'be6326e4-0c5b-4756-9b03-bd3da6c309e6', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cn4wby', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ae67a490-b006-45a7-aa1a-59101bdf350d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cn4wby', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/'}, {u'size': 107374182400, u'uuid': u'3cabf463-ce37-4434-9eb7-3b211d8ccf61', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 11, u'partitions': [], u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'cn4wby', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'de6703fb-d6fa-4f92-8e5b-fb30174f78eb'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/11/'}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'be6326e4-0c5b-4756-9b03-bd3da6c309e6', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cn4wby', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ae67a490-b006-45a7-aa1a-59101bdf350d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cn4wby', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cn4wby', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'partitions': [{u'uuid': u'be6326e4-0c5b-4756-9b03-bd3da6c309e6', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cn4wby', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'ae67a490-b006-45a7-aa1a-59101bdf350d'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 2}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cn4wby', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/2/'}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'3cabf463-ce37-4434-9eb7-3b211d8ccf61', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 11, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'cn4wby', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'de6703fb-d6fa-4f92-8e5b-fb30174f78eb'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/blockdevices/11/'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41', u'id': 22, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'system_id': u'cn4wby', u'mac_address': u'00:25:b5:a0:00:6a', u'id': 4, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/interfaces/4/'}, {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'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cn4wby', u'mac_address': u'00:25:b5:a0:00:6b', u'id': 12, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/interfaces/12/'}, {u'name': u'enp8s0', u'links': [{u'id': 24, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cn4wby', u'mac_address': u'00:25:b5:a0:00:6c', u'id': 13, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/interfaces/13/'}, {u'name': u'enp9s0', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cn4wby', u'mac_address': u'00:25:b5:a0:00:6d', u'id': 14, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cn4wby/interfaces/14/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/cn4wby/'}
2019-09-01 03:11:26,789 [salt.state       :300 ][INFO    ][3977] {'new': {'storage_layout': 'lvm'}}
2019-09-01 03:11:26,789 [salt.state       :1951][INFO    ][3977] Completed state [maas_machines_storage_cmp002_lvm] at time 03:11:26.789535 duration_in_ms=3130.288
2019-09-01 03:11:26,790 [salt.state       :1780][INFO    ][3977] Running state [maas_machines_storage_cmp001_lvm] at time 03:11:26.790065
2019-09-01 03:11:26,790 [salt.state       :1813][INFO    ][3977] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-01 03:11:28,132 [salt.loaded.ext.module.maasng:610 ][INFO    ][3977] bh6cka
2019-09-01 03:11:28,132 [salt.loaded.ext.module.maasng:626 ][INFO    ][3977] sda
2019-09-01 03:11:28,862 [salt.loaded.ext.module.maasng:361 ][INFO    ][3977] bh6cka
2019-09-01 03:11:28,982 [salt.loaded.ext.module.maasng:367 ][INFO    ][3977] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'bh6cka', 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'partitions': [{u'uuid': u'a1e60a61-fac2-44fb-a9f8-81fbcce27dbc', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bh6cka', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'8d7af0aa-45b3-4bf4-bc7a-0933624b2e25', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'size': 2397992648704}], u'type': u'physical', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/'}, {u'size': 2397988454400, u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'325a37e3-c899-4ebe-9350-f72ae8ac9e36', u'fstype': u'ext4'}, u'uuid': u'62ce8f47-6e5c-4b9a-9b8e-577a3d092b36', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bh6cka', 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'partitions': [], u'type': u'virtual', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/6/'}]
2019-09-01 03:11:28,983 [salt.loaded.ext.module.maasng:632 ][INFO    ][3977] vgroot
2019-09-01 03:11:28,983 [salt.loaded.ext.module.maasng:635 ][INFO    ][3977] lvroot
2019-09-01 03:11:28,984 [salt.loaded.ext.module.maasng:639 ][INFO    ][3977] 107374182400
2019-09-01 03:11:29,685 [salt.loaded.ext.module.maasng:645 ][INFO    ][3977] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'bh6cka', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/interfaces/5/'}, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'owner_data': {}, 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'min_hwe_kernel': u'ga-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'bh6cka', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 1, u'partitions': [{u'uuid': u'dc597312-7dd3-425b-9ae5-382b43770c45', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bh6cka', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'a1e39c9d-99da-449f-a947-90ffb782d485'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'bh6cka', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/'}, {u'size': 107374182400, u'uuid': u'e8134649-7766-473e-8684-e6cf4ecae7b8', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 12, u'partitions': [], u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'bh6cka', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'e8f30660-44fe-4961-9a17-4373f3db9759'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/12/'}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'partitions': [{u'uuid': u'dc597312-7dd3-425b-9ae5-382b43770c45', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bh6cka', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'a1e39c9d-99da-449f-a947-90ffb782d485'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'bh6cka', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'bh6cka', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'partitions': [{u'uuid': u'dc597312-7dd3-425b-9ae5-382b43770c45', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bh6cka', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'uuid': u'a1e39c9d-99da-449f-a947-90ffb782d485'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'device_id': 1}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'bh6cka', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/1/'}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'e8134649-7766-473e-8684-e6cf4ecae7b8', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 12, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'bh6cka', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'uuid': u'e8f30660-44fe-4961-9a17-4373f3db9759'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/blockdevices/12/'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 15, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'bh6cka', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'id': 16, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'bh6cka', u'mac_address': u'00:25:b5:a0:00:5c', u'id': 9, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/interfaces/9/'}, {u'name': u'enp7s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'bh6cka', u'mac_address': u'00:25:b5:a0:00:5b', u'id': 10, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/interfaces/10/'}, {u'name': u'enp9s0', 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'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'bh6cka', u'mac_address': u'00:25:b5:a0:00:5d', u'id': 11, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bh6cka/interfaces/11/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/bh6cka/'}
2019-09-01 03:11:29,689 [salt.state       :300 ][INFO    ][3977] {'new': {'storage_layout': 'lvm'}}
2019-09-01 03:11:29,689 [salt.state       :1951][INFO    ][3977] Completed state [maas_machines_storage_cmp001_lvm] at time 03:11:29.689618 duration_in_ms=2899.551
2019-09-01 03:11:29,694 [salt.minion      :1711][INFO    ][3977] Returning information for job: 20190901031118402592
2019-09-01 03:11:30,322 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031130312905
2019-09-01 03:11:30,344 [salt.minion      :1432][INFO    ][4010] Starting a new job with PID 4010
2019-09-01 03:11:31,041 [salt.state       :915 ][INFO    ][4010] Loading fresh modules for state activity
2019-09-01 03:11:31,094 [salt.fileclient  :1219][INFO    ][4010] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-09-01 03:11:31,138 [salt.state       :1780][INFO    ][4010] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:11:31.137985
2019-09-01 03:11:31,138 [salt.state       :1813][INFO    ][4010] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:11:31,140 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4010] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:11:32,608 [salt.state       :300 ][INFO    ][4010] {'pid': 4017, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:11:32,609 [salt.state       :1951][INFO    ][4010] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:11:32.608974 duration_in_ms=1470.989
2019-09-01 03:11:32,610 [salt.state       :1780][INFO    ][4010] Running state [maas.deploy_machines] at time 03:11:32.610161
2019-09-01 03:11:32,610 [salt.state       :1813][INFO    ][4010] Executing state module.run for [maas.deploy_machines]
2019-09-01 03:11:32,611 [salt.utils.decorators:613 ][WARNING ][4010] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:11:33,303 [salt.loaded.ext.module.maas:684 ][INFO    ][4010] deploymachines hwe_kernel=ga-16.04 system_id=cn4wby distro_series=xenial
2019-09-01 03:11:40,289 [salt.loaded.ext.module.maas:684 ][INFO    ][4010] deploymachines hwe_kernel=ga-16.04 system_id=bh6cka distro_series=xenial
2019-09-01 03:11:45,423 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031145410457
2019-09-01 03:11:45,443 [salt.minion      :1432][INFO    ][4122] Starting a new job with PID 4122
2019-09-01 03:11:45,467 [salt.minion      :1711][INFO    ][4122] Returning information for job: 20190901031145410457
2019-09-01 03:11:47,109 [salt.loaded.ext.module.maas:684 ][INFO    ][4010] deploymachines hwe_kernel=ga-16.04 system_id=tadx3w distro_series=xenial
2019-09-01 03:11:54,386 [salt.loaded.ext.module.maas:684 ][INFO    ][4010] deploymachines hwe_kernel=ga-16.04 system_id=d3gr6c distro_series=xenial
2019-09-01 03:12:01,417 [salt.loaded.ext.module.maas:684 ][INFO    ][4010] deploymachines hwe_kernel=ga-16.04 system_id=pqhsph distro_series=xenial
2019-09-01 03:12:08,520 [salt.state       :300 ][INFO    ][4010] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-09-01 03:12:08,520 [salt.state       :1951][INFO    ][4010] Completed state [maas.deploy_machines] at time 03:12:08.520733 duration_in_ms=35910.569
2019-09-01 03:12:08,525 [salt.minion      :1711][INFO    ][4010] Returning information for job: 20190901031130312905
2019-09-01 03:12:09,170 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031209157455
2019-09-01 03:12:09,192 [salt.minion      :1432][INFO    ][4342] Starting a new job with PID 4342
2019-09-01 03:12:12,864 [salt.state       :915 ][INFO    ][4342] Loading fresh modules for state activity
2019-09-01 03:12:12,916 [salt.fileclient  :1219][INFO    ][4342] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-09-01 03:12:12,962 [salt.state       :1780][INFO    ][4342] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:12:12.962177
2019-09-01 03:12:12,962 [salt.state       :1813][INFO    ][4342] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:12:12,965 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4342] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:12:14,419 [salt.state       :300 ][INFO    ][4342] {'pid': 4351, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:12:14,420 [salt.state       :1951][INFO    ][4342] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:12:14.420113 duration_in_ms=1457.937
2019-09-01 03:12:14,421 [salt.state       :1780][INFO    ][4342] Running state [maas.wait_for_machine_status] at time 03:12:14.421640
2019-09-01 03:12:14,421 [salt.state       :1813][INFO    ][4342] Executing state module.run for [maas.wait_for_machine_status]
2019-09-01 03:12:14,422 [salt.utils.decorators:613 ][WARNING ][4342] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:12:18,008 [salt.loaded.ext.module.maas:1023][INFO    ][4342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.41823196s left)
2019-09-01 03:12:24,259 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031224245877
2019-09-01 03:12:24,279 [salt.minion      :1432][INFO    ][4370] Starting a new job with PID 4370
2019-09-01 03:12:24,301 [salt.minion      :1711][INFO    ][4370] Returning information for job: 20190901031224245877
2019-09-01 03:12:51,337 [salt.loaded.ext.module.maas:1023][INFO    ][4342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.08916211s left)
2019-09-01 03:12:54,308 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031254294371
2019-09-01 03:12:54,331 [salt.minion      :1432][INFO    ][4398] Starting a new job with PID 4398
2019-09-01 03:12:54,354 [salt.minion      :1711][INFO    ][4398] Returning information for job: 20190901031254294371
2019-09-01 03:13:24,169 [salt.loaded.ext.module.maas:1023][INFO    ][4342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.25791001s left)
2019-09-01 03:13:24,402 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031324389901
2019-09-01 03:13:24,420 [salt.minion      :1432][INFO    ][4462] Starting a new job with PID 4462
2019-09-01 03:13:24,443 [salt.minion      :1711][INFO    ][4462] Returning information for job: 20190901031324389901
2019-09-01 03:13:54,630 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031354617972
2019-09-01 03:13:54,650 [salt.minion      :1432][INFO    ][4661] Starting a new job with PID 4661
2019-09-01 03:13:54,674 [salt.minion      :1711][INFO    ][4661] Returning information for job: 20190901031354617972
2019-09-01 03:13:57,333 [salt.loaded.ext.module.maas:1023][INFO    ][4342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.09295797s left)
2019-09-01 03:14:24,699 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031424687018
2019-09-01 03:14:24,723 [salt.minion      :1432][INFO    ][5099] Starting a new job with PID 5099
2019-09-01 03:14:24,742 [salt.minion      :1711][INFO    ][5099] Returning information for job: 20190901031424687018
2019-09-01 03:14:54,782 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031454768666
2019-09-01 03:14:54,800 [salt.minion      :1432][INFO    ][5163] Starting a new job with PID 5163
2019-09-01 03:14:54,816 [salt.minion      :1711][INFO    ][5163] Returning information for job: 20190901031454768666
2019-09-01 03:15:24,857 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031524844124
2019-09-01 03:15:24,880 [salt.minion      :1432][INFO    ][5623] Starting a new job with PID 5623
2019-09-01 03:15:24,902 [salt.minion      :1711][INFO    ][5623] Returning information for job: 20190901031524844124
2019-09-01 03:15:54,940 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031554927713
2019-09-01 03:15:54,961 [salt.minion      :1432][INFO    ][5664] Starting a new job with PID 5664
2019-09-01 03:15:54,983 [salt.minion      :1711][INFO    ][5664] Returning information for job: 20190901031554927713
2019-09-01 03:16:25,047 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031625032376
2019-09-01 03:16:25,066 [salt.minion      :1432][INFO    ][5757] Starting a new job with PID 5757
2019-09-01 03:16:25,084 [salt.minion      :1711][INFO    ][5757] Returning information for job: 20190901031625032376
2019-09-01 03:16:55,191 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031655179452
2019-09-01 03:16:55,209 [salt.minion      :1432][INFO    ][5809] Starting a new job with PID 5809
2019-09-01 03:16:55,228 [salt.minion      :1711][INFO    ][5809] Returning information for job: 20190901031655179452
2019-09-01 03:17:25,294 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031725281516
2019-09-01 03:17:25,316 [salt.minion      :1432][INFO    ][6029] Starting a new job with PID 6029
2019-09-01 03:17:25,342 [salt.minion      :1711][INFO    ][6029] Returning information for job: 20190901031725281516
2019-09-01 03:17:55,395 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031755387784
2019-09-01 03:17:55,417 [salt.minion      :1432][INFO    ][6082] Starting a new job with PID 6082
2019-09-01 03:17:55,440 [salt.minion      :1711][INFO    ][6082] Returning information for job: 20190901031755387784
2019-09-01 03:18:25,515 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031825504064
2019-09-01 03:18:25,534 [salt.minion      :1432][INFO    ][6253] Starting a new job with PID 6253
2019-09-01 03:18:25,549 [salt.minion      :1711][INFO    ][6253] Returning information for job: 20190901031825504064
2019-09-01 03:18:55,618 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031855608287
2019-09-01 03:18:55,636 [salt.minion      :1432][INFO    ][6299] Starting a new job with PID 6299
2019-09-01 03:18:55,659 [salt.minion      :1711][INFO    ][6299] Returning information for job: 20190901031855608287
2019-09-01 03:19:25,746 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901031925733951
2019-09-01 03:19:25,764 [salt.minion      :1432][INFO    ][6445] Starting a new job with PID 6445
2019-09-01 03:19:25,782 [salt.minion      :1711][INFO    ][6445] Returning information for job: 20190901031925733951
2019-09-01 03:19:36,183 [salt.state       :302 ][ERROR   ][4342] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-09-01 03:19:36,184 [salt.state       :1951][INFO    ][4342] Completed state [maas.wait_for_machine_status] at time 03:19:36.184330 duration_in_ms=441762.687
2019-09-01 03:19:36,188 [salt.minion      :1711][INFO    ][4342] Returning information for job: 20190901031209157455
2019-09-01 03:19:46,931 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command pillar.get with jid 20190901031946919262
2019-09-01 03:19:46,948 [salt.minion      :1432][INFO    ][6593] Starting a new job with PID 6593
2019-09-01 03:19:46,956 [salt.minion      :1711][INFO    ][6593] Returning information for job: 20190901031946919262
2019-09-01 03:19:47,404 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command service.status with jid 20190901031947391457
2019-09-01 03:19:47,424 [salt.minion      :1432][INFO    ][6607] Starting a new job with PID 6607
2019-09-01 03:19:47,890 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6607] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-09-01 03:19:47,926 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6607] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-09-01 03:19:47,943 [salt.minion      :1711][INFO    ][6607] Returning information for job: 20190901031947391457
2019-09-01 03:19:48,424 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031948417800
2019-09-01 03:19:48,444 [salt.minion      :1432][INFO    ][6618] Starting a new job with PID 6618
2019-09-01 03:19:52,061 [salt.state       :915 ][INFO    ][6618] Loading fresh modules for state activity
2019-09-01 03:19:52,508 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'salt-minion --version' in directory '/root'
2019-09-01 03:19:52,877 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'salt-minion --version' in directory '/root'
2019-09-01 03:19:53,776 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'salt-minion --version' in directory '/root'
2019-09-01 03:19:54,133 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'salt-minion --version' in directory '/root'
2019-09-01 03:19:55,285 [salt.state       :1780][INFO    ][6618] Running state [salt-minion] at time 03:19:55.285760
2019-09-01 03:19:55,286 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [salt-minion]
2019-09-01 03:19:55,286 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-01 03:19:55,380 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,381 [salt.state       :1951][INFO    ][6618] Completed state [salt-minion] at time 03:19:55.381007 duration_in_ms=95.247
2019-09-01 03:19:55,381 [salt.state       :1780][INFO    ][6618] Running state [salt_minion_dependency_packages] at time 03:19:55.381290
2019-09-01 03:19:55,381 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-09-01 03:19:55,386 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,387 [salt.state       :1951][INFO    ][6618] Completed state [salt_minion_dependency_packages] at time 03:19:55.387130 duration_in_ms=5.84
2019-09-01 03:19:55,389 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/minion.d/minion.conf] at time 03:19:55.389927
2019-09-01 03:19:55,390 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-09-01 03:19:55,583 [salt.state       :300 ][INFO    ][6618] File /etc/salt/minion.d/minion.conf is in the correct state
2019-09-01 03:19:55,583 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/minion.d/minion.conf] at time 03:19:55.583599 duration_in_ms=193.671
2019-09-01 03:19:55,583 [salt.state       :1780][INFO    ][6618] Running state [python-netaddr] at time 03:19:55.583912
2019-09-01 03:19:55,584 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [python-netaddr]
2019-09-01 03:19:55,593 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,593 [salt.state       :1951][INFO    ][6618] Completed state [python-netaddr] at time 03:19:55.593427 duration_in_ms=9.515
2019-09-01 03:19:55,597 [salt.state       :1780][INFO    ][6618] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:19:55.597372
2019-09-01 03:19:55,597 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-09-01 03:19:55,613 [salt.state       :300 ][INFO    ][6618] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-09-01 03:19:55,613 [salt.state       :1951][INFO    ][6618] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:19:55.613838 duration_in_ms=16.465
2019-09-01 03:19:55,615 [salt.state       :1780][INFO    ][6618] Running state [salt-minion] at time 03:19:55.615550
2019-09-01 03:19:55,616 [salt.state       :1813][INFO    ][6618] Executing state service.running for [salt-minion]
2019-09-01 03:19:55,617 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-09-01 03:19:55,655 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-09-01 03:19:55,672 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-09-01 03:19:55,689 [salt.state       :300 ][INFO    ][6618] The service salt-minion is already running
2019-09-01 03:19:55,690 [salt.state       :1951][INFO    ][6618] Completed state [salt-minion] at time 03:19:55.689922 duration_in_ms=74.371
2019-09-01 03:19:55,692 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains.d] at time 03:19:55.692469
2019-09-01 03:19:55,693 [salt.state       :1813][INFO    ][6618] Executing state file.directory for [/etc/salt/grains.d]
2019-09-01 03:19:55,694 [salt.state       :300 ][INFO    ][6618] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-09-01 03:19:55,695 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains.d] at time 03:19:55.694919 duration_in_ms=2.449
2019-09-01 03:19:55,696 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains] at time 03:19:55.696066
2019-09-01 03:19:55,696 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/grains]
2019-09-01 03:19:55,697 [salt.state       :300 ][INFO    ][6618] File /etc/salt/grains exists with proper permissions. No changes made.
2019-09-01 03:19:55,697 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains] at time 03:19:55.697826 duration_in_ms=1.76
2019-09-01 03:19:55,698 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains.d/placeholder] at time 03:19:55.698618
2019-09-01 03:19:55,699 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-09-01 03:19:55,699 [salt.state       :300 ][INFO    ][6618] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-09-01 03:19:55,700 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains.d/placeholder] at time 03:19:55.700265 duration_in_ms=1.647
2019-09-01 03:19:55,701 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains.d/sphinx] at time 03:19:55.701013
2019-09-01 03:19:55,701 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-09-01 03:19:55,715 [salt.state       :300 ][INFO    ][6618] File /etc/salt/grains.d/sphinx is in the correct state
2019-09-01 03:19:55,715 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains.d/sphinx] at time 03:19:55.715315 duration_in_ms=14.302
2019-09-01 03:19:55,718 [salt.state       :1780][INFO    ][6618] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.718799
2019-09-01 03:19:55,719 [salt.state       :1813][INFO    ][6618] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-09-01 03:19:55,719 [salt.state       :300 ][INFO    ][6618] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-09-01 03:19:55,720 [salt.state       :1951][INFO    ][6618] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.720127 duration_in_ms=1.329
2019-09-01 03:19:55,720 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains.d/dns_records] at time 03:19:55.720876
2019-09-01 03:19:55,721 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-09-01 03:19:55,732 [salt.state       :300 ][INFO    ][6618] File /etc/salt/grains.d/dns_records is in the correct state
2019-09-01 03:19:55,733 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains.d/dns_records] at time 03:19:55.733057 duration_in_ms=12.181
2019-09-01 03:19:55,734 [salt.state       :1780][INFO    ][6618] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.734410
2019-09-01 03:19:55,734 [salt.state       :1813][INFO    ][6618] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-09-01 03:19:55,735 [salt.state       :300 ][INFO    ][6618] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-09-01 03:19:55,735 [salt.state       :1951][INFO    ][6618] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.735674 duration_in_ms=1.264
2019-09-01 03:19:55,736 [salt.state       :1780][INFO    ][6618] Running state [/etc/salt/grains.d/salt] at time 03:19:55.736365
2019-09-01 03:19:55,736 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-09-01 03:19:55,750 [salt.state       :300 ][INFO    ][6618] File /etc/salt/grains.d/salt is in the correct state
2019-09-01 03:19:55,751 [salt.state       :1951][INFO    ][6618] Completed state [/etc/salt/grains.d/salt] at time 03:19:55.751048 duration_in_ms=14.682
2019-09-01 03:19:55,752 [salt.state       :1780][INFO    ][6618] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.752358
2019-09-01 03:19:55,752 [salt.state       :1813][INFO    ][6618] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-09-01 03:19:55,753 [salt.state       :300 ][INFO    ][6618] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-09-01 03:19:55,753 [salt.state       :1951][INFO    ][6618] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:19:55.753617 duration_in_ms=1.259
2019-09-01 03:19:55,756 [salt.state       :1780][INFO    ][6618] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:19:55.756420
2019-09-01 03:19:55,756 [salt.state       :1813][INFO    ][6618] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-09-01 03:19:55,757 [salt.state       :300 ][INFO    ][6618] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-09-01 03:19:55,757 [salt.state       :1951][INFO    ][6618] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:19:55.757668 duration_in_ms=1.248
2019-09-01 03:19:55,758 [salt.state       :1780][INFO    ][6618] Running state [mine.update] at time 03:19:55.758665
2019-09-01 03:19:55,759 [salt.state       :1813][INFO    ][6618] Executing state module.wait for [mine.update]
2019-09-01 03:19:55,759 [salt.state       :300 ][INFO    ][6618] No changes made for mine.update
2019-09-01 03:19:55,759 [salt.state       :1951][INFO    ][6618] Completed state [mine.update] at time 03:19:55.759796 duration_in_ms=1.132
2019-09-01 03:19:55,760 [salt.state       :1780][INFO    ][6618] Running state [ca-certificates] at time 03:19:55.760151
2019-09-01 03:19:55,760 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [ca-certificates]
2019-09-01 03:19:55,770 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,771 [salt.state       :1951][INFO    ][6618] Completed state [ca-certificates] at time 03:19:55.771121 duration_in_ms=10.969
2019-09-01 03:19:55,772 [salt.state       :1780][INFO    ][6618] Running state [update-ca-certificates] at time 03:19:55.772108
2019-09-01 03:19:55,772 [salt.state       :1813][INFO    ][6618] Executing state cmd.wait for [update-ca-certificates]
2019-09-01 03:19:55,773 [salt.state       :300 ][INFO    ][6618] No changes made for update-ca-certificates
2019-09-01 03:19:55,773 [salt.state       :1951][INFO    ][6618] Completed state [update-ca-certificates] at time 03:19:55.773224 duration_in_ms=1.117
2019-09-01 03:19:55,773 [salt.state       :1780][INFO    ][6618] Running state [iptables] at time 03:19:55.773556
2019-09-01 03:19:55,773 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [iptables]
2019-09-01 03:19:55,783 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,783 [salt.state       :1951][INFO    ][6618] Completed state [iptables] at time 03:19:55.783462 duration_in_ms=9.907
2019-09-01 03:19:55,783 [salt.state       :1780][INFO    ][6618] Running state [iptables-persistent] at time 03:19:55.783824
2019-09-01 03:19:55,784 [salt.state       :1813][INFO    ][6618] Executing state pkg.installed for [iptables-persistent]
2019-09-01 03:19:55,792 [salt.state       :300 ][INFO    ][6618] All specified packages are already installed
2019-09-01 03:19:55,793 [salt.state       :1951][INFO    ][6618] Completed state [iptables-persistent] at time 03:19:55.793164 duration_in_ms=9.341
2019-09-01 03:19:55,794 [salt.state       :1780][INFO    ][6618] Running state [iptables_modules_v4_load] at time 03:19:55.794451
2019-09-01 03:19:55,794 [salt.state       :1813][INFO    ][6618] Executing state kmod.present for [iptables_modules_v4_load]
2019-09-01 03:19:55,795 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'lsmod' in directory '/root'
2019-09-01 03:19:55,820 [salt.state       :300 ][INFO    ][6618] Kernel modules iptable_filter, ip_tables are already present
2019-09-01 03:19:55,820 [salt.state       :1951][INFO    ][6618] Completed state [iptables_modules_v4_load] at time 03:19:55.820459 duration_in_ms=26.008
2019-09-01 03:19:55,821 [salt.state       :1780][INFO    ][6618] Running state [/etc/iptables/rules.v4] at time 03:19:55.821328
2019-09-01 03:19:55,821 [salt.state       :1813][INFO    ][6618] Executing state file.managed for [/etc/iptables/rules.v4]
2019-09-01 03:19:55,896 [salt.state       :300 ][INFO    ][6618] File /etc/iptables/rules.v4 is in the correct state
2019-09-01 03:19:55,896 [salt.state       :1951][INFO    ][6618] Completed state [/etc/iptables/rules.v4] at time 03:19:55.896528 duration_in_ms=75.2
2019-09-01 03:19:55,897 [salt.state       :1780][INFO    ][6618] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:19:55.897237
2019-09-01 03:19:55,897 [salt.state       :1813][INFO    ][6618] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-09-01 03:19:55,897 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-09-01 03:19:55,915 [salt.state       :300 ][INFO    ][6618] onlyif execution failed
2019-09-01 03:19:55,916 [salt.state       :1951][INFO    ][6618] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:19:55.916197 duration_in_ms=18.96
2019-09-01 03:19:55,916 [salt.state       :1780][INFO    ][6618] Running state [netfilter-persistent] at time 03:19:55.916911
2019-09-01 03:19:55,917 [salt.state       :1813][INFO    ][6618] Executing state service.running for [netfilter-persistent]
2019-09-01 03:19:55,917 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-09-01 03:19:55,939 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-09-01 03:19:55,956 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-09-01 03:19:55,972 [salt.state       :300 ][INFO    ][6618] The service netfilter-persistent is already running
2019-09-01 03:19:55,973 [salt.state       :1951][INFO    ][6618] Completed state [netfilter-persistent] at time 03:19:55.973258 duration_in_ms=56.346
2019-09-01 03:19:55,974 [salt.state       :1780][INFO    ][6618] Running state [iptables_extra.remove_stale_tables] at time 03:19:55.974178
2019-09-01 03:19:55,974 [salt.state       :1813][INFO    ][6618] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-09-01 03:19:55,974 [salt.state       :300 ][INFO    ][6618] No changes made for iptables_extra.remove_stale_tables
2019-09-01 03:19:55,975 [salt.state       :1951][INFO    ][6618] Completed state [iptables_extra.remove_stale_tables] at time 03:19:55.975178 duration_in_ms=1.001
2019-09-01 03:19:55,975 [salt.state       :1780][INFO    ][6618] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:19:55.975446
2019-09-01 03:19:55,975 [salt.state       :1813][INFO    ][6618] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-09-01 03:19:55,976 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6618] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-09-01 03:19:55,990 [salt.state       :300 ][INFO    ][6618] onlyif execution failed
2019-09-01 03:19:55,990 [salt.state       :1951][INFO    ][6618] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:19:55.990399 duration_in_ms=14.953
2019-09-01 03:19:55,991 [salt.state       :1780][INFO    ][6618] Running state [/etc/iptables/rules.v6] at time 03:19:55.991516
2019-09-01 03:19:55,991 [salt.state       :1813][INFO    ][6618] Executing state file.absent for [/etc/iptables/rules.v6]
2019-09-01 03:19:55,992 [salt.state       :300 ][INFO    ][6618] File /etc/iptables/rules.v6 is not present
2019-09-01 03:19:55,992 [salt.state       :1951][INFO    ][6618] Completed state [/etc/iptables/rules.v6] at time 03:19:55.992705 duration_in_ms=1.19
2019-09-01 03:19:55,993 [salt.state       :1780][INFO    ][6618] Running state [iptables_extra.flush_all] at time 03:19:55.993468
2019-09-01 03:19:55,993 [salt.state       :1813][INFO    ][6618] Executing state module.wait for [iptables_extra.flush_all]
2019-09-01 03:19:55,994 [salt.state       :300 ][INFO    ][6618] No changes made for iptables_extra.flush_all
2019-09-01 03:19:55,994 [salt.state       :1951][INFO    ][6618] Completed state [iptables_extra.flush_all] at time 03:19:55.994388 duration_in_ms=0.92
2019-09-01 03:19:55,998 [salt.minion      :1711][INFO    ][6618] Returning information for job: 20190901031948417800
2019-09-01 03:19:56,479 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031956467875
2019-09-01 03:19:56,497 [salt.minion      :1432][INFO    ][6738] Starting a new job with PID 6738
2019-09-01 03:19:57,097 [salt.state       :915 ][INFO    ][6738] Loading fresh modules for state activity
2019-09-01 03:19:57,649 [salt.state       :1780][INFO    ][6738] Running state [maas-rack-controller] at time 03:19:57.649701
2019-09-01 03:19:57,650 [salt.state       :1813][INFO    ][6738] Executing state pkg.installed for [maas-rack-controller]
2019-09-01 03:19:57,650 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6738] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-01 03:19:57,719 [salt.state       :300 ][INFO    ][6738] All specified packages are already installed
2019-09-01 03:19:57,719 [salt.state       :1951][INFO    ][6738] Completed state [maas-rack-controller] at time 03:19:57.719708 duration_in_ms=70.006
2019-09-01 03:19:57,720 [salt.state       :1780][INFO    ][6738] Running state [ipmitool] at time 03:19:57.720048
2019-09-01 03:19:57,720 [salt.state       :1813][INFO    ][6738] Executing state pkg.installed for [ipmitool]
2019-09-01 03:19:57,724 [salt.state       :300 ][INFO    ][6738] All specified packages are already installed
2019-09-01 03:19:57,725 [salt.state       :1951][INFO    ][6738] Completed state [ipmitool] at time 03:19:57.724968 duration_in_ms=4.921
2019-09-01 03:19:57,727 [salt.state       :1780][INFO    ][6738] Running state [/etc/maas/rackd.conf] at time 03:19:57.727249
2019-09-01 03:19:57,727 [salt.state       :1813][INFO    ][6738] Executing state file.line for [/etc/maas/rackd.conf]
2019-09-01 03:19:57,728 [salt.state       :300 ][INFO    ][6738] No changes needed to be made
2019-09-01 03:19:57,728 [salt.state       :1951][INFO    ][6738] Completed state [/etc/maas/rackd.conf] at time 03:19:57.728513 duration_in_ms=1.263
2019-09-01 03:19:57,728 [salt.state       :1780][INFO    ][6738] Running state [/etc/maas/rackd.conf] at time 03:19:57.728764
2019-09-01 03:19:57,729 [salt.state       :1813][INFO    ][6738] Executing state file.managed for [/etc/maas/rackd.conf]
2019-09-01 03:19:57,729 [salt.loaded.int.states.file:2298][WARNING ][6738] 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-09-01 03:19:57,729 [salt.state       :300 ][INFO    ][6738] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-09-01 03:19:57,729 [salt.state       :1951][INFO    ][6738] Completed state [/etc/maas/rackd.conf] at time 03:19:57.729942 duration_in_ms=1.178
2019-09-01 03:19:57,730 [salt.state       :1780][INFO    ][6738] Running state [maas-rackd] at time 03:19:57.730735
2019-09-01 03:19:57,730 [salt.state       :1813][INFO    ][6738] Executing state service.running for [maas-rackd]
2019-09-01 03:19:57,731 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6738] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-09-01 03:19:57,758 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6738] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-09-01 03:19:57,772 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6738] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-09-01 03:19:57,784 [salt.state       :300 ][INFO    ][6738] The service maas-rackd is already running
2019-09-01 03:19:57,785 [salt.state       :1951][INFO    ][6738] Completed state [maas-rackd] at time 03:19:57.785122 duration_in_ms=54.386
2019-09-01 03:19:57,786 [salt.minion      :1711][INFO    ][6738] Returning information for job: 20190901031956467875
2019-09-01 03:19:58,245 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901031958238279
2019-09-01 03:19:58,263 [salt.minion      :1432][INFO    ][6870] Starting a new job with PID 6870
2019-09-01 03:19:58,872 [salt.state       :915 ][INFO    ][6870] Loading fresh modules for state activity
2019-09-01 03:19:59,553 [salt.state       :1780][INFO    ][6870] Running state [maas-region-controller] at time 03:19:59.553162
2019-09-01 03:19:59,553 [salt.state       :1813][INFO    ][6870] Executing state pkg.installed for [maas-region-controller]
2019-09-01 03:19:59,553 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-09-01 03:19:59,632 [salt.state       :300 ][INFO    ][6870] All specified packages are already installed
2019-09-01 03:19:59,632 [salt.state       :1951][INFO    ][6870] Completed state [maas-region-controller] at time 03:19:59.632469 duration_in_ms=79.307
2019-09-01 03:19:59,632 [salt.state       :1780][INFO    ][6870] Running state [python-oauth] at time 03:19:59.632756
2019-09-01 03:19:59,633 [salt.state       :1813][INFO    ][6870] Executing state pkg.installed for [python-oauth]
2019-09-01 03:19:59,638 [salt.state       :300 ][INFO    ][6870] All specified packages are already installed
2019-09-01 03:19:59,638 [salt.state       :1951][INFO    ][6870] Completed state [python-oauth] at time 03:19:59.638533 duration_in_ms=5.776
2019-09-01 03:19:59,641 [salt.state       :1780][INFO    ][6870] Running state [/etc/maas/regiond.conf] at time 03:19:59.641123
2019-09-01 03:19:59,641 [salt.state       :1813][INFO    ][6870] Executing state file.replace for [/etc/maas/regiond.conf]
2019-09-01 03:19:59,682 [salt.state       :300 ][INFO    ][6870] No changes needed to be made
2019-09-01 03:19:59,682 [salt.state       :1951][INFO    ][6870] Completed state [/etc/maas/regiond.conf] at time 03:19:59.682693 duration_in_ms=41.568
2019-09-01 03:19:59,683 [salt.state       :1780][INFO    ][6870] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:19:59.683707
2019-09-01 03:19:59,684 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-09-01 03:19:59,759 [salt.state       :300 ][INFO    ][6870] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-09-01 03:19:59,759 [salt.state       :1951][INFO    ][6870] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:19:59.759724 duration_in_ms=76.017
2019-09-01 03:19:59,760 [salt.state       :1780][INFO    ][6870] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:19:59.760476
2019-09-01 03:19:59,760 [salt.state       :1813][INFO    ][6870] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-01 03:19:59,773 [salt.state       :300 ][INFO    ][6870] No changes needed to be made
2019-09-01 03:19:59,773 [salt.state       :1951][INFO    ][6870] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:19:59.773571 duration_in_ms=13.095
2019-09-01 03:19:59,774 [salt.state       :1780][INFO    ][6870] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:19:59.774222
2019-09-01 03:19:59,774 [salt.state       :1813][INFO    ][6870] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-09-01 03:19:59,797 [salt.state       :300 ][INFO    ][6870] No changes needed to be made
2019-09-01 03:19:59,797 [salt.state       :1951][INFO    ][6870] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:19:59.797452 duration_in_ms=23.229
2019-09-01 03:19:59,798 [salt.state       :1780][INFO    ][6870] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:19:59.798127
2019-09-01 03:19:59,798 [salt.state       :1813][INFO    ][6870] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-09-01 03:19:59,829 [salt.state       :300 ][INFO    ][6870] No changes needed to be made
2019-09-01 03:19:59,830 [salt.state       :1951][INFO    ][6870] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:19:59.830222 duration_in_ms=32.095
2019-09-01 03:19:59,830 [salt.state       :1780][INFO    ][6870] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:19:59.830800
2019-09-01 03:19:59,831 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-09-01 03:19:59,842 [salt.state       :300 ][INFO    ][6870] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-09-01 03:19:59,843 [salt.state       :1951][INFO    ][6870] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:19:59.843022 duration_in_ms=12.223
2019-09-01 03:19:59,844 [salt.state       :1780][INFO    ][6870] Running state [a2enmod headers] at time 03:19:59.844446
2019-09-01 03:19:59,844 [salt.state       :1813][INFO    ][6870] Executing state cmd.run for [a2enmod headers]
2019-09-01 03:19:59,845 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command 'a2enmod headers' in directory '/root'
2019-09-01 03:19:59,919 [salt.state       :300 ][INFO    ][6870] {'pid': 6906, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-09-01 03:19:59,919 [salt.state       :1951][INFO    ][6870] Completed state [a2enmod headers] at time 03:19:59.919601 duration_in_ms=75.155
2019-09-01 03:19:59,920 [salt.state       :1780][INFO    ][6870] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:19:59.920122
2019-09-01 03:19:59,920 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-09-01 03:19:59,939 [salt.state       :300 ][INFO    ][6870] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-09-01 03:19:59,939 [salt.state       :1951][INFO    ][6870] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:19:59.939413 duration_in_ms=19.291
2019-09-01 03:19:59,940 [salt.state       :1780][INFO    ][6870] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:19:59.940241
2019-09-01 03:19:59,940 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-09-01 03:20:00,203 [salt.state       :300 ][INFO    ][6870] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-09-01 03:20:00,203 [salt.state       :1951][INFO    ][6870] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:20:00.203578 duration_in_ms=263.336
2019-09-01 03:20:00,204 [salt.state       :1780][INFO    ][6870] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:00.204406
2019-09-01 03:20:00,204 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-09-01 03:20:00,299 [salt.state       :300 ][INFO    ][6870] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-09-01 03:20:00,300 [salt.state       :1951][INFO    ][6870] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:00.300058 duration_in_ms=95.64
2019-09-01 03:20:00,301 [salt.state       :1780][INFO    ][6870] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:00.301369
2019-09-01 03:20:00,302 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-09-01 03:20:00,388 [salt.state       :300 ][INFO    ][6870] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-09-01 03:20:00,388 [salt.state       :1951][INFO    ][6870] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:00.388669 duration_in_ms=87.299
2019-09-01 03:20:00,389 [salt.state       :1780][INFO    ][6870] Running state [/root/.pgpass] at time 03:20:00.389189
2019-09-01 03:20:00,389 [salt.state       :1813][INFO    ][6870] Executing state file.managed for [/root/.pgpass]
2019-09-01 03:20:00,441 [salt.state       :300 ][INFO    ][6870] File /root/.pgpass is in the correct state
2019-09-01 03:20:00,442 [salt.state       :1951][INFO    ][6870] Completed state [/root/.pgpass] at time 03:20:00.442226 duration_in_ms=53.037
2019-09-01 03:20:00,448 [salt.state       :1780][INFO    ][6870] Running state [maas-region syncdb --noinput] at time 03:20:00.448274
2019-09-01 03:20:00,448 [salt.state       :1813][INFO    ][6870] Executing state cmd.run for [maas-region syncdb --noinput]
2019-09-01 03:20:00,449 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-09-01 03:20:02,360 [salt.state       :300 ][INFO    ][6870] {'pid': 6921, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, contenttypes, sessions, sites, auth, metadataserver, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-09-01 03:20:02,360 [salt.state       :1951][INFO    ][6870] Completed state [maas-region syncdb --noinput] at time 03:20:02.360510 duration_in_ms=1912.235
2019-09-01 03:20:02,360 [salt.state       :2022][WARNING ][6870] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-09-01 03:20:02,363 [salt.state       :1780][INFO    ][6870] Running state [maas-regiond] at time 03:20:02.363425
2019-09-01 03:20:02,363 [salt.state       :1813][INFO    ][6870] Executing state service.running for [maas-regiond]
2019-09-01 03:20:02,365 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-09-01 03:20:02,406 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-09-01 03:20:02,424 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-09-01 03:20:02,441 [salt.state       :300 ][INFO    ][6870] The service maas-regiond is already running
2019-09-01 03:20:02,441 [salt.state       :1951][INFO    ][6870] Completed state [maas-regiond] at time 03:20:02.441642 duration_in_ms=78.217
2019-09-01 03:20:02,443 [salt.state       :1780][INFO    ][6870] Running state [bind9] at time 03:20:02.443701
2019-09-01 03:20:02,444 [salt.state       :1813][INFO    ][6870] Executing state service.running for [bind9]
2019-09-01 03:20:02,444 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-09-01 03:20:02,462 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-09-01 03:20:02,478 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-09-01 03:20:02,494 [salt.state       :300 ][INFO    ][6870] The service bind9 is already running
2019-09-01 03:20:02,495 [salt.state       :1951][INFO    ][6870] Completed state [bind9] at time 03:20:02.495218 duration_in_ms=51.516
2019-09-01 03:20:02,497 [salt.state       :1780][INFO    ][6870] Running state [apache2] at time 03:20:02.497112
2019-09-01 03:20:02,497 [salt.state       :1813][INFO    ][6870] Executing state service.running for [apache2]
2019-09-01 03:20:02,498 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-09-01 03:20:02,516 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-09-01 03:20:02,531 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-09-01 03:20:02,551 [salt.state       :300 ][INFO    ][6870] The service apache2 is already running
2019-09-01 03:20:02,552 [salt.state       :1951][INFO    ][6870] Completed state [apache2] at time 03:20:02.552318 duration_in_ms=55.206
2019-09-01 03:20:02,554 [salt.state       :1780][INFO    ][6870] Running state [maasng.wait_for_http_code] at time 03:20:02.554217
2019-09-01 03:20:02,554 [salt.state       :1813][INFO    ][6870] Executing state module.run for [maasng.wait_for_http_code]
2019-09-01 03:20:02,555 [salt.utils.decorators:613 ][WARNING ][6870] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:20:02,668 [salt.state       :300 ][INFO    ][6870] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-09-01 03:20:02,668 [salt.state       :1951][INFO    ][6870] Completed state [maasng.wait_for_http_code] at time 03:20:02.668471 duration_in_ms=114.254
2019-09-01 03:20:02,669 [salt.state       :1780][INFO    ][6870] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:02.669694
2019-09-01 03:20:02,670 [salt.state       :1813][INFO    ][6870] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-09-01 03:20:02,670 [salt.state       :300 ][INFO    ][6870] /var/lib/maas/.setup_admin exists
2019-09-01 03:20:02,671 [salt.state       :1951][INFO    ][6870] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:02.671087 duration_in_ms=1.392
2019-09-01 03:20:02,672 [salt.state       :1780][INFO    ][6870] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:02.672053
2019-09-01 03:20:02,672 [salt.state       :1813][INFO    ][6870] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:20:02,673 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6870] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:20:04,066 [salt.state       :300 ][INFO    ][6870] {'pid': 6965, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:20:04,067 [salt.state       :1951][INFO    ][6870] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:04.067733 duration_in_ms=1395.68
2019-09-01 03:20:04,076 [salt.state       :1780][INFO    ][6870] Running state [maas_region_boot_source_resources_mirror] at time 03:20:04.076672
2019-09-01 03:20:04,077 [salt.state       :1813][INFO    ][6870] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-09-01 03:20:04,189 [salt.state       :300 ][INFO    ][6870] {'changes': {}}
2019-09-01 03:20:04,190 [salt.state       :1951][INFO    ][6870] Completed state [maas_region_boot_source_resources_mirror] at time 03:20:04.190204 duration_in_ms=113.533
2019-09-01 03:20:04,191 [salt.state       :1780][INFO    ][6870] Running state [maasng.boot_resources_import] at time 03:20:04.191335
2019-09-01 03:20:04,191 [salt.state       :1813][INFO    ][6870] Executing state module.run for [maasng.boot_resources_import]
2019-09-01 03:20:04,192 [salt.utils.decorators:613 ][WARNING ][6870] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:20:04,337 [salt.loaded.ext.module.maasng:1600][INFO    ][6870] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-09-01 03:20:09,395 [salt.loaded.ext.module.maasng:1600][INFO    ][6870] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-09-01 03:20:13,369 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032013356313
2019-09-01 03:20:13,392 [salt.minion      :1432][INFO    ][7009] Starting a new job with PID 7009
2019-09-01 03:20:13,416 [salt.minion      :1711][INFO    ][7009] Returning information for job: 20190901032013356313
2019-09-01 03:20:14,431 [salt.loaded.ext.module.maasng:1600][INFO    ][6870] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-09-01 03:20:19,539 [salt.state       :300 ][INFO    ][6870] {'ret': True}
2019-09-01 03:20:19,540 [salt.state       :1951][INFO    ][6870] Completed state [maasng.boot_resources_import] at time 03:20:19.540124 duration_in_ms=15348.788
2019-09-01 03:20:19,541 [salt.state       :1780][INFO    ][6870] Running state [maas_region_boot_sources_selection_xenial] at time 03:20:19.541281
2019-09-01 03:20:19,541 [salt.state       :1813][INFO    ][6870] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-09-01 03:20:19,748 [salt.state       :300 ][INFO    ][6870] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-09-01 03:20:19,749 [salt.state       :1951][INFO    ][6870] Completed state [maas_region_boot_sources_selection_xenial] at time 03:20:19.749208 duration_in_ms=207.925
2019-09-01 03:20:19,750 [salt.state       :1780][INFO    ][6870] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:20:19.750832
2019-09-01 03:20:19,751 [salt.state       :1813][INFO    ][6870] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-09-01 03:20:19,752 [salt.utils.decorators:613 ][WARNING ][6870] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:20:19,752 [salt.loaded.ext.module.maasng:1771][INFO    ][6870] boot-sources sync initiated for ALL Rack's
2019-09-01 03:20:20,763 [salt.state       :300 ][INFO    ][6870] {'ret': True}
2019-09-01 03:20:20,764 [salt.state       :1951][INFO    ][6870] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:20:20.764416 duration_in_ms=1013.584
2019-09-01 03:20:20,767 [salt.state       :1780][INFO    ][6870] Running state [maas.process_maas_config] at time 03:20:20.767024
2019-09-01 03:20:20,767 [salt.state       :1813][INFO    ][6870] Executing state module.run for [maas.process_maas_config]
2019-09-01 03:20:20,768 [salt.utils.decorators:613 ][WARNING ][6870] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:20:20,769 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=enable_http_proxy value=True
2019-09-01 03:20:20,825 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=upstream_dns value=8.8.8.8
2019-09-01 03:20:23,940 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=commissioning_distro_series value=xenial
2019-09-01 03:20:24,021 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=default_osystem value=ubuntu
2019-09-01 03:20:24,082 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=active_discovery_interval value=600
2019-09-01 03:20:24,147 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=dnssec_validation value=no
2019-09-01 03:20:24,201 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=maas_name value=mas01
2019-09-01 03:20:24,273 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=network_discovery value=enabled
2019-09-01 03:20:24,390 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=enable_third_party_drivers value=True
2019-09-01 03:20:24,465 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=default_storage_layout value=lvm
2019-09-01 03:20:24,523 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=ntp_external_only value=True
2019-09-01 03:20:24,563 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=disk_erase_with_secure_erase value=False
2019-09-01 03:20:24,617 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=default_distro_series value=xenial
2019-09-01 03:20:24,698 [salt.loaded.ext.module.maas:92  ][INFO    ][6870] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-09-01 03:20:24,824 [salt.state       :300 ][INFO    ][6870] {'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-09-01 03:20:24,825 [salt.state       :1951][INFO    ][6870] Completed state [maas.process_maas_config] at time 03:20:24.824999 duration_in_ms=4057.975
2019-09-01 03:20:24,825 [salt.state       :1780][INFO    ][6870] Running state [pxe_admin] at time 03:20:24.825793
2019-09-01 03:20:24,826 [salt.state       :1813][INFO    ][6870] Executing state maasng.fabric_present for [pxe_admin]
2019-09-01 03:20:24,886 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-01 03:20:24,955 [salt.loaded.ext.module.maasng:1008][WARNING ][6870] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-09-01 03:20:24,956 [salt.loaded.ext.module.maasng:1011][WARNING ][6870] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-09-01 03:20:25,009 [salt.state       :300 ][INFO    ][6870] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-09-01 03:20:25,010 [salt.state       :1951][INFO    ][6870] Completed state [pxe_admin] at time 03:20:25.010069 duration_in_ms=184.274
2019-09-01 03:20:25,010 [salt.state       :1780][INFO    ][6870] Running state [vlan 0] at time 03:20:25.010563
2019-09-01 03:20:25,011 [salt.state       :1813][INFO    ][6870] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-01 03:20:25,069 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{u'name': u'fabric-0', 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'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-09-01 03:20:25,213 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'id': 1, u'name': u'fabric-1'}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', 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'primary_rack': u'4tfh7h', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'id': 2, u'name': u'pxe_admin'}]
2019-09-01 03:20:25,497 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-01 03:20:25,593 [salt.state       :300 ][INFO    ][6870] {'new': 'Vlan untagged was updated'}
2019-09-01 03:20:25,593 [salt.state       :1951][INFO    ][6870] Completed state [vlan 0] at time 03:20:25.593796 duration_in_ms=583.233
2019-09-01 03:20:25,594 [salt.state       :1780][INFO    ][6870] Running state [192.168.11.0/24] at time 03:20:25.594566
2019-09-01 03:20:25,594 [salt.state       :1813][INFO    ][6870] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-09-01 03:20:25,770 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-01 03:20:25,770 [salt.loaded.ext.module.maasng:1235][WARNING ][6870] Ignoring parameter vlan:0
2019-09-01 03:20:25,848 [salt.state       :300 ][INFO    ][6870] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-09-01 03:20:25,849 [salt.state       :1951][INFO    ][6870] Completed state [192.168.11.0/24] at time 03:20:25.849241 duration_in_ms=254.673
2019-09-01 03:20:25,850 [salt.state       :1780][INFO    ][6870] Running state [maas_create_iprange_1] at time 03:20:25.850420
2019-09-01 03:20:25,850 [salt.state       :1813][INFO    ][6870] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-09-01 03:20:25,926 [salt.state       :300 ][INFO    ][6870] Iprange maas_create_iprange_1 already exist.
2019-09-01 03:20:25,926 [salt.state       :1951][INFO    ][6870] Completed state [maas_create_iprange_1] at time 03:20:25.926377 duration_in_ms=75.958
2019-09-01 03:20:25,926 [salt.state       :1780][INFO    ][6870] Running state [vlan 0] at time 03:20:25.926604
2019-09-01 03:20:25,926 [salt.state       :1813][INFO    ][6870] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-09-01 03:20:25,986 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4tfh7h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-09-01 03:20:26,109 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{u'name': u'fabric-0', 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'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-09-01 03:20:26,263 [salt.loaded.ext.module.maasng:945 ][INFO    ][6870] [{u'name': u'fabric-0', 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'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'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'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4tfh7h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2019-09-01 03:20:26,360 [salt.state       :300 ][INFO    ][6870] {'new': 'Vlan untagged was updated'}
2019-09-01 03:20:26,361 [salt.state       :1951][INFO    ][6870] Completed state [vlan 0] at time 03:20:26.361137 duration_in_ms=434.532
2019-09-01 03:20:26,362 [salt.state       :1780][INFO    ][6870] Running state [opnfv] at time 03:20:26.362099
2019-09-01 03:20:26,362 [salt.state       :1813][INFO    ][6870] Executing state maasng.sshkey_present for [opnfv]
2019-09-01 03:20:26,402 [salt.loaded.ext.module.maasng:1903][INFO    ][6870] [{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-09-01 03:20:26,402 [salt.state       :300 ][INFO    ][6870] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-09-01 03:20:26,402 [salt.state       :1951][INFO    ][6870] Completed state [opnfv] at time 03:20:26.402910 duration_in_ms=40.811
2019-09-01 03:20:26,407 [salt.minion      :1711][INFO    ][6870] Returning information for job: 20190901031958238279
2019-09-01 03:20:26,927 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901032026915904
2019-09-01 03:20:26,943 [salt.minion      :1432][INFO    ][7404] Starting a new job with PID 7404
2019-09-01 03:20:30,540 [salt.state       :915 ][INFO    ][7404] Loading fresh modules for state activity
2019-09-01 03:20:30,631 [salt.state       :1780][INFO    ][7404] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:30.631877
2019-09-01 03:20:30,632 [salt.state       :1813][INFO    ][7404] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:20:30,634 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7404] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:20:32,081 [salt.state       :300 ][INFO    ][7404] {'pid': 7436, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:20:32,081 [salt.state       :1951][INFO    ][7404] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:32.081467 duration_in_ms=1449.591
2019-09-01 03:20:32,082 [salt.state       :1780][INFO    ][7404] Running state [maas.process_machines] at time 03:20:32.082635
2019-09-01 03:20:32,082 [salt.state       :1813][INFO    ][7404] Executing state module.run for [maas.process_machines]
2019-09-01 03:20:32,083 [salt.utils.decorators:613 ][WARNING ][7404] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:20:32,827 [salt.loaded.ext.module.maas:412 ][WARNING ][7404] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:20:32,828 [salt.loaded.ext.module.maas:92  ][INFO    ][7404] 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=cn4wby architecture=amd64/generic power_parameters_power_user=admin
2019-09-01 03:20:34,200 [salt.loaded.ext.module.maas:412 ][WARNING ][7404] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:20:34,201 [salt.loaded.ext.module.maas:92  ][INFO    ][7404] 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=bh6cka architecture=amd64/generic power_parameters_power_user=admin
2019-09-01 03:20:35,181 [salt.loaded.ext.module.maas:412 ][WARNING ][7404] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:20:35,182 [salt.loaded.ext.module.maas:92  ][INFO    ][7404] 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=tadx3w architecture=amd64/generic power_parameters_power_user=admin
2019-09-01 03:20:36,403 [salt.loaded.ext.module.maas:412 ][WARNING ][7404] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:20:36,404 [salt.loaded.ext.module.maas:92  ][INFO    ][7404] 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=d3gr6c architecture=amd64/generic power_parameters_power_user=admin
2019-09-01 03:20:37,693 [salt.loaded.ext.module.maas:412 ][WARNING ][7404] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-09-01 03:20:37,694 [salt.loaded.ext.module.maas:92  ][INFO    ][7404] 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=pqhsph architecture=amd64/generic power_parameters_power_user=admin
2019-09-01 03:20:39,149 [salt.state       :300 ][INFO    ][7404] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-01 03:20:39,150 [salt.state       :1951][INFO    ][7404] Completed state [maas.process_machines] at time 03:20:39.150348 duration_in_ms=7067.711
2019-09-01 03:20:39,154 [salt.minion      :1711][INFO    ][7404] Returning information for job: 20190901032026915904
2019-09-01 03:21:11,246 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901032111233071
2019-09-01 03:21:11,267 [salt.minion      :1432][INFO    ][8035] Starting a new job with PID 8035
2019-09-01 03:21:14,998 [salt.state       :915 ][INFO    ][8035] Loading fresh modules for state activity
2019-09-01 03:21:15,085 [salt.state       :1780][INFO    ][8035] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:15.085902
2019-09-01 03:21:15,086 [salt.state       :1813][INFO    ][8035] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:21:15,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8035] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:21:16,533 [salt.state       :300 ][INFO    ][8035] {'pid': 8043, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:21:16,534 [salt.state       :1951][INFO    ][8035] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:16.534253 duration_in_ms=1448.352
2019-09-01 03:21:16,535 [salt.state       :1780][INFO    ][8035] Running state [maas.wait_for_machine_status] at time 03:21:16.535767
2019-09-01 03:21:16,536 [salt.state       :1813][INFO    ][8035] Executing state module.run for [maas.wait_for_machine_status]
2019-09-01 03:21:16,536 [salt.utils.decorators:613 ][WARNING ][8035] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:21:19,648 [salt.loaded.ext.module.maas:1023][INFO    ][8035] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1496.892838s left)
2019-09-01 03:21:26,282 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032126269823
2019-09-01 03:21:26,305 [salt.minion      :1432][INFO    ][8062] Starting a new job with PID 8062
2019-09-01 03:21:26,329 [salt.minion      :1711][INFO    ][8062] Returning information for job: 20190901032126269823
2019-09-01 03:21:52,869 [salt.loaded.ext.module.maas:1023][INFO    ][8035] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1463.67132497s left)
2019-09-01 03:21:56,329 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032156315609
2019-09-01 03:21:56,352 [salt.minion      :1432][INFO    ][8097] Starting a new job with PID 8097
2019-09-01 03:21:56,376 [salt.minion      :1711][INFO    ][8097] Returning information for job: 20190901032156315609
2019-09-01 03:22:26,007 [salt.loaded.ext.module.maas:1023][INFO    ][8035] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1430.53339314s left)
2019-09-01 03:22:26,417 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032226357689
2019-09-01 03:22:26,438 [salt.minion      :1432][INFO    ][8344] Starting a new job with PID 8344
2019-09-01 03:22:26,462 [salt.minion      :1711][INFO    ][8344] Returning information for job: 20190901032226357689
2019-09-01 03:22:56,589 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032256575262
2019-09-01 03:22:56,611 [salt.minion      :1432][INFO    ][8389] Starting a new job with PID 8389
2019-09-01 03:22:56,639 [salt.minion      :1711][INFO    ][8389] Returning information for job: 20190901032256575262
2019-09-01 03:22:58,940 [salt.loaded.ext.module.maas:1023][INFO    ][8035] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm02']
sleep for:30s Timeout:1500s (1397.60100293s left)
2019-09-01 03:23:26,654 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032326640365
2019-09-01 03:23:26,676 [salt.minion      :1432][INFO    ][8576] Starting a new job with PID 8576
2019-09-01 03:23:26,699 [salt.minion      :1711][INFO    ][8576] Returning information for job: 20190901032326640365
2019-09-01 03:23:32,773 [salt.loaded.ext.module.maas:1023][INFO    ][8035] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm02']
sleep for:30s Timeout:1500s (1363.76790094s left)
2019-09-01 03:23:56,691 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command saltutil.find_job with jid 20190901032356680415
2019-09-01 03:23:56,710 [salt.minion      :1432][INFO    ][8688] Starting a new job with PID 8688
2019-09-01 03:23:56,731 [salt.minion      :1711][INFO    ][8688] Returning information for job: 20190901032356680415
2019-09-01 03:24:05,893 [salt.state       :300 ][INFO    ][8035] {'ret': True}
2019-09-01 03:24:05,894 [salt.state       :1951][INFO    ][8035] Completed state [maas.wait_for_machine_status] at time 03:24:05.894216 duration_in_ms=169358.447
2019-09-01 03:24:05,897 [salt.minion      :1711][INFO    ][8035] Returning information for job: 20190901032111233071
2019-09-01 03:24:06,574 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901032406561184
2019-09-01 03:24:06,596 [salt.minion      :1432][INFO    ][8783] Starting a new job with PID 8783
2019-09-01 03:24:10,348 [salt.state       :915 ][INFO    ][8783] Loading fresh modules for state activity
2019-09-01 03:24:10,484 [salt.state       :1780][INFO    ][8783] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:10.484026
2019-09-01 03:24:10,484 [salt.state       :1813][INFO    ][8783] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:24:10,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8783] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:24:11,912 [salt.state       :300 ][INFO    ][8783] {'pid': 8807, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:24:11,912 [salt.state       :1951][INFO    ][8783] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:11.912707 duration_in_ms=1428.682
2019-09-01 03:24:11,914 [salt.state       :1780][INFO    ][8783] Running state [maas_machines_storage_cmp002_lvm] at time 03:24:11.914220
2019-09-01 03:24:11,914 [salt.state       :1813][INFO    ][8783] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-09-01 03:24:12,493 [salt.state       :300 ][INFO    ][8783] Machine cmp002 is not in Ready state.
2019-09-01 03:24:12,493 [salt.state       :1951][INFO    ][8783] Completed state [maas_machines_storage_cmp002_lvm] at time 03:24:12.493729 duration_in_ms=579.506
2019-09-01 03:24:12,494 [salt.state       :1780][INFO    ][8783] Running state [maas_machines_storage_cmp001_lvm] at time 03:24:12.494265
2019-09-01 03:24:12,494 [salt.state       :1813][INFO    ][8783] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-09-01 03:24:13,041 [salt.state       :300 ][INFO    ][8783] Machine cmp001 is not in Ready state.
2019-09-01 03:24:13,041 [salt.state       :1951][INFO    ][8783] Completed state [maas_machines_storage_cmp001_lvm] at time 03:24:13.041588 duration_in_ms=547.323
2019-09-01 03:24:13,044 [salt.minion      :1711][INFO    ][8783] Returning information for job: 20190901032406561184
2019-09-01 03:24:13,491 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901032413479767
2019-09-01 03:24:13,508 [salt.minion      :1432][INFO    ][8819] Starting a new job with PID 8819
2019-09-01 03:24:14,251 [salt.state       :915 ][INFO    ][8819] Loading fresh modules for state activity
2019-09-01 03:24:14,330 [salt.state       :1780][INFO    ][8819] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:14.330249
2019-09-01 03:24:14,330 [salt.state       :1813][INFO    ][8819] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:24:14,332 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8819] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:24:15,639 [salt.state       :300 ][INFO    ][8819] {'pid': 8826, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:24:15,639 [salt.state       :1951][INFO    ][8819] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:15.639737 duration_in_ms=1309.487
2019-09-01 03:24:15,642 [salt.state       :1780][INFO    ][8819] Running state [maas.deploy_machines] at time 03:24:15.642103
2019-09-01 03:24:15,642 [salt.state       :1813][INFO    ][8819] Executing state module.run for [maas.deploy_machines]
2019-09-01 03:24:15,643 [salt.utils.decorators:613 ][WARNING ][8819] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:24:16,396 [salt.state       :300 ][INFO    ][8819] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-09-01 03:24:16,397 [salt.state       :1951][INFO    ][8819] Completed state [maas.deploy_machines] at time 03:24:16.397435 duration_in_ms=755.332
2019-09-01 03:24:16,400 [salt.minion      :1711][INFO    ][8819] Returning information for job: 20190901032413479767
2019-09-01 03:24:17,026 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command state.apply with jid 20190901032417017187
2019-09-01 03:24:17,048 [salt.minion      :1432][INFO    ][8836] Starting a new job with PID 8836
2019-09-01 03:24:17,797 [salt.state       :915 ][INFO    ][8836] Loading fresh modules for state activity
2019-09-01 03:24:17,886 [salt.state       :1780][INFO    ][8836] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:17.886782
2019-09-01 03:24:17,887 [salt.state       :1813][INFO    ][8836] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-09-01 03:24:17,889 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8836] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-09-01 03:24:19,392 [salt.state       :300 ][INFO    ][8836] {'pid': 8843, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-09-01 03:24:19,393 [salt.state       :1951][INFO    ][8836] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:24:19.393414 duration_in_ms=1506.633
2019-09-01 03:24:19,395 [salt.state       :1780][INFO    ][8836] Running state [maas.wait_for_machine_status] at time 03:24:19.395417
2019-09-01 03:24:19,395 [salt.state       :1813][INFO    ][8836] Executing state module.run for [maas.wait_for_machine_status]
2019-09-01 03:24:19,396 [salt.utils.decorators:613 ][WARNING ][8836] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-09-01 03:24:22,726 [salt.state       :300 ][INFO    ][8836] {'ret': True}
2019-09-01 03:24:22,726 [salt.state       :1951][INFO    ][8836] Completed state [maas.wait_for_machine_status] at time 03:24:22.726840 duration_in_ms=3331.42
2019-09-01 03:24:22,730 [salt.minion      :1711][INFO    ][8836] Returning information for job: 20190901032417017187
2019-09-01 04:07:37,114 [salt.utils.schedule:1377][INFO    ][2089] Running scheduled job: __mine_interval
2019-09-01 04:52:27,971 [salt.minion      :1308][INFO    ][2089] User sudo_ubuntu Executing command cp.push_dir with jid 20190901045227958760
2019-09-01 04:52:27,996 [salt.minion      :1432][INFO    ][15072] Starting a new job with PID 15072
