2019-05-26 05:03:03,149 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-26 05:03:53,199 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-26 05:04:43,241 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-26 05:05:33,270 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-26 05:06:23,316 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-26 05:08:31,550 [salt.utils.decorators:613 ][WARNING ][2712] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:08:32,123 [salt.utils.decorators:613 ][WARNING ][2712] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:08:34,287 [salt.loaded.int.states.file:2298][WARNING ][2851] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-26 05:08:40,051 [salt.state       :2022][WARNING ][2961] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-26 05:08:42,633 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:08:55,765 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:09:31,714 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:09:32,774 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:09:36,066 [salt.loaded.ext.module.maasng:1008][WARNING ][2961] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-26 05:09:36,066 [salt.loaded.ext.module.maasng:1011][WARNING ][2961] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-26 05:09:36,678 [salt.loaded.ext.module.maasng:1235][WARNING ][2961] Ignoring parameter vlan:0
2019-05-26 05:09:38,150 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:09:43,865 [salt.utils.decorators:613 ][WARNING ][5941] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:09:43,933 [salt.loaded.ext.module.maas:412 ][WARNING ][5941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:09:45,317 [salt.loaded.ext.module.maas:412 ][WARNING ][5941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:09:46,509 [salt.loaded.ext.module.maas:412 ][WARNING ][5941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:09:47,802 [salt.loaded.ext.module.maas:412 ][WARNING ][5941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:09:49,070 [salt.loaded.ext.module.maas:412 ][WARNING ][5941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:09:53,949 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6576] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-26 05:09:53,982 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6576] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-26 05:09:54,005 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-05-26 05:09:55,004 [salt.cli.daemons :293 ][INFO    ][6627] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-05-26 05:09:55,100 [salt.cli.daemons :82  ][INFO    ][6627] Starting up the Salt Minion
2019-05-26 05:09:55,101 [salt.utils.event :1017][INFO    ][6627] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-05-26 05:09:55,980 [salt.minion      :976 ][INFO    ][6627] Creating minion process manager
2019-05-26 05:09:57,459 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6627] Executing command ['date', '+%z'] in directory '/root'
2019-05-26 05:09:57,478 [salt.utils.schedule:568 ][INFO    ][6627] Updating job settings for scheduled job: __mine_interval
2019-05-26 05:09:57,479 [salt.minion      :1108][INFO    ][6627] Added mine.update to scheduler
2019-05-26 05:09:57,483 [salt.minion      :1975][INFO    ][6627] Minion is starting as user 'root'
2019-05-26 05:09:57,497 [salt.minion      :2336][INFO    ][6627] Minion is ready to receive requests!
2019-05-26 05:10:21,395 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526051021383777
2019-05-26 05:10:21,417 [salt.minion      :1432][INFO    ][6716] Starting a new job with PID 6716
2019-05-26 05:10:25,203 [salt.state       :915 ][INFO    ][6716] Loading fresh modules for state activity
2019-05-26 05:10:25,254 [salt.fileclient  :1219][INFO    ][6716] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-26 05:10:25,297 [salt.state       :1780][INFO    ][6716] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:10:25.297628
2019-05-26 05:10:25,298 [salt.state       :1813][INFO    ][6716] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:10:25,300 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6716] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:10:26,763 [salt.state       :300 ][INFO    ][6716] {'pid': 6723, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:10:26,763 [salt.state       :1951][INFO    ][6716] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:10:26.763429 duration_in_ms=1465.802
2019-05-26 05:10:26,764 [salt.state       :1780][INFO    ][6716] Running state [maas.wait_for_machine_status] at time 05:10:26.764807
2019-05-26 05:10:26,765 [salt.state       :1813][INFO    ][6716] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 05:10:26,765 [salt.utils.decorators:613 ][WARNING ][6716] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:10:27,745 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.02396703s left)
2019-05-26 05:10:36,487 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051036471067
2019-05-26 05:10:36,509 [salt.minion      :1432][INFO    ][6751] Starting a new job with PID 6751
2019-05-26 05:10:36,532 [salt.minion      :1711][INFO    ][6751] Returning information for job: 20190526051036471067
2019-05-26 05:10:58,833 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1467.93556404s left)
2019-05-26 05:11:06,542 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051106529761
2019-05-26 05:11:06,564 [salt.minion      :1432][INFO    ][6798] Starting a new job with PID 6798
2019-05-26 05:11:06,584 [salt.minion      :1711][INFO    ][6798] Returning information for job: 20190526051106529761
2019-05-26 05:11:29,999 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.77040911s left)
2019-05-26 05:11:36,573 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051136561020
2019-05-26 05:11:36,592 [salt.minion      :1432][INFO    ][6948] Starting a new job with PID 6948
2019-05-26 05:11:36,612 [salt.minion      :1711][INFO    ][6948] Returning information for job: 20190526051136561020
2019-05-26 05:12:01,369 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.40051103s left)
2019-05-26 05:12:06,617 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051206602145
2019-05-26 05:12:06,640 [salt.minion      :1432][INFO    ][7085] Starting a new job with PID 7085
2019-05-26 05:12:06,664 [salt.minion      :1711][INFO    ][7085] Returning information for job: 20190526051206602145
2019-05-26 05:12:32,990 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.778584s left)
2019-05-26 05:12:36,673 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051236660262
2019-05-26 05:12:36,695 [salt.minion      :1432][INFO    ][7259] Starting a new job with PID 7259
2019-05-26 05:12:36,718 [salt.minion      :1711][INFO    ][7259] Returning information for job: 20190526051236660262
2019-05-26 05:13:04,871 [salt.loaded.ext.module.maas:1023][INFO    ][6716] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1341.89801908s left)
2019-05-26 05:13:06,732 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051306716279
2019-05-26 05:13:06,754 [salt.minion      :1432][INFO    ][7846] Starting a new job with PID 7846
2019-05-26 05:13:06,778 [salt.minion      :1711][INFO    ][7846] Returning information for job: 20190526051306716279
2019-05-26 05:13:36,798 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051336783191
2019-05-26 05:13:36,821 [salt.minion      :1432][INFO    ][7995] Starting a new job with PID 7995
2019-05-26 05:13:36,840 [salt.minion      :1711][INFO    ][7995] Returning information for job: 20190526051336783191
2019-05-26 05:13:38,225 [salt.state       :300 ][INFO    ][6716] {'ret': True}
2019-05-26 05:13:38,225 [salt.state       :1951][INFO    ][6716] Completed state [maas.wait_for_machine_status] at time 05:13:38.225866 duration_in_ms=191461.058
2019-05-26 05:13:38,229 [salt.minion      :1711][INFO    ][6716] Returning information for job: 20190526051021383777
2019-05-26 05:13:38,864 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526051338848043
2019-05-26 05:13:38,885 [salt.minion      :1432][INFO    ][8003] Starting a new job with PID 8003
2019-05-26 05:13:42,460 [salt.state       :915 ][INFO    ][8003] Loading fresh modules for state activity
2019-05-26 05:13:42,495 [salt.fileclient  :1219][INFO    ][8003] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-26 05:13:42,563 [salt.state       :1780][INFO    ][8003] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:13:42.563689
2019-05-26 05:13:42,563 [salt.state       :1813][INFO    ][8003] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:13:42,565 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8003] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:13:43,891 [salt.state       :300 ][INFO    ][8003] {'pid': 8042, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:13:43,892 [salt.state       :1951][INFO    ][8003] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:13:43.892064 duration_in_ms=1328.375
2019-05-26 05:13:43,895 [salt.state       :1780][INFO    ][8003] Running state [maas_machines_storage_cmp002_lvm] at time 05:13:43.895176
2019-05-26 05:13:43,895 [salt.state       :1813][INFO    ][8003] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-26 05:13:45,182 [salt.loaded.ext.module.maasng:610 ][INFO    ][8003] msk4aw
2019-05-26 05:13:45,182 [salt.loaded.ext.module.maasng:626 ][INFO    ][8003] sda
2019-05-26 05:13:45,942 [salt.loaded.ext.module.maasng:361 ][INFO    ][8003] msk4aw
2019-05-26 05:13:46,074 [salt.loaded.ext.module.maasng:367 ][INFO    ][8003] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'c4ba277d-02b1-494c-b46c-d52c9d2ce445', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'msk4aw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'89e8814c-eead-4fe5-99fb-9edd8f7f6fd7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/partition/4', u'type': u'partition', u'id': 4, u'device_id': 4}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'msk4aw', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/'}, {u'size': 2397988454400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'43ecb342-2d95-491b-b880-489c3c504b26', u'fstype': u'ext4'}, u'uuid': u'ef8b02df-9bf3-4899-889d-3645a89b99ce', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'msk4aw', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/9/'}]
2019-05-26 05:13:46,075 [salt.loaded.ext.module.maasng:632 ][INFO    ][8003] vgroot
2019-05-26 05:13:46,075 [salt.loaded.ext.module.maasng:635 ][INFO    ][8003] lvroot
2019-05-26 05:13:46,075 [salt.loaded.ext.module.maasng:639 ][INFO    ][8003] 107374182400
2019-05-26 05:13:46,796 [salt.loaded.ext.module.maasng:645 ][INFO    ][8003] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'msk4aw', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'size': 2397992648704, u'uuid': u'0ad4d1e3-c8fe-4841-b105-1b394f09bd12', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'msk4aw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'6ee7904c-f13f-49f5-b232-aa991d4aaeec', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/partition/8', u'type': u'partition', u'id': 8, u'device_id': 4}]}, u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'msk4aw', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"From 'Testing' to 'Ready'", u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'msk4aw', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'size': 2397992648704, u'uuid': u'0ad4d1e3-c8fe-4841-b105-1b394f09bd12', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'msk4aw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'6ee7904c-f13f-49f5-b232-aa991d4aaeec', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/partition/8', u'type': u'partition', u'id': 8, u'device_id': 4}]}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'filesystem': None, u'name': u'sda', u'system_id': u'msk4aw', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'size': 2397992648704, u'uuid': u'0ad4d1e3-c8fe-4841-b105-1b394f09bd12', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'msk4aw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'6ee7904c-f13f-49f5-b232-aa991d4aaeec', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/partition/8', u'type': u'partition', u'id': 8, u'device_id': 4}], u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/4/'}, {u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'94e5baf9-fd2b-4336-9d22-0a58bca0f9e3', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'089ebea7-4431-4c64-a7ed-5035b0c98a26', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'msk4aw', 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'used_size': 107374182400, u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/13/'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'on', u'owner_data': {}, u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'msk4aw', u'id': 8}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 28, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'enabled': True, u'mac_address': u'00:25:b5:a0:00:6a', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'children': [], u'system_id': u'msk4aw', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/interfaces/4/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 28, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'enabled': True, u'mac_address': u'00:25:b5:a0:00:6a', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'children': [], u'system_id': u'msk4aw', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'id': 29, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'discovered': None, u'children': [], u'system_id': u'msk4aw', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/interfaces/18/'}, {u'name': u'enp9s0', u'links': [{u'id': 31, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'discovered': None, u'children': [], u'system_id': u'msk4aw', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/interfaces/19/'}, {u'name': u'enp8s0', u'links': [{u'id': 32, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'discovered': None, u'children': [], u'system_id': u'msk4aw', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, 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'block_size': 4096, u'uuid': u'94e5baf9-fd2b-4336-9d22-0a58bca0f9e3', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'089ebea7-4431-4c64-a7ed-5035b0c98a26', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'msk4aw', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/msk4aw/blockdevices/13/', u'used_size': 107374182400, u'id': 13, u'serial': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'current_commissioning_result_id': 2, u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/msk4aw/'}
2019-05-26 05:13:46,798 [salt.state       :300 ][INFO    ][8003] {'new': {'storage_layout': 'lvm'}}
2019-05-26 05:13:46,798 [salt.state       :1951][INFO    ][8003] Completed state [maas_machines_storage_cmp002_lvm] at time 05:13:46.798541 duration_in_ms=2903.364
2019-05-26 05:13:46,799 [salt.state       :1780][INFO    ][8003] Running state [maas_machines_storage_cmp001_lvm] at time 05:13:46.799004
2019-05-26 05:13:46,799 [salt.state       :1813][INFO    ][8003] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-26 05:13:48,165 [salt.loaded.ext.module.maasng:610 ][INFO    ][8003] cpmhen
2019-05-26 05:13:48,165 [salt.loaded.ext.module.maasng:626 ][INFO    ][8003] sda
2019-05-26 05:13:48,644 [salt.loaded.ext.module.maasng:361 ][INFO    ][8003] cpmhen
2019-05-26 05:13:48,735 [salt.loaded.ext.module.maasng:367 ][INFO    ][8003] [{u'block_size': 4096, u'type': u'physical', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/', u'partitions': [{u'uuid': u'523d2f71-c491-450a-a314-280f63cdc99d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cpmhen', u'device_id': 3, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'2aa00b2a-805e-4263-a16a-75ac6cf582e9', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/partition/6'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cpmhen', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 3, u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}, {u'block_size': 4096, u'type': u'virtual', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/11/', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cpmhen', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'c01dd6db-ac59-4da0-92b9-e073673d981e', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 2397988454400, u'used_size': 2397988454400, u'id': 11, u'serial': None, u'uuid': u'e49fd619-5ba3-4899-bccd-517303d38e79'}]
2019-05-26 05:13:48,736 [salt.loaded.ext.module.maasng:632 ][INFO    ][8003] vgroot
2019-05-26 05:13:48,736 [salt.loaded.ext.module.maasng:635 ][INFO    ][8003] lvroot
2019-05-26 05:13:48,736 [salt.loaded.ext.module.maasng:639 ][INFO    ][8003] 107374182400
2019-05-26 05:13:49,257 [salt.loaded.ext.module.maasng:645 ][INFO    ][8003] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'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': 39, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cpmhen', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/cpmhen/', u'current_commissioning_result_id': 4, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'cpmhen', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'86ab761f-f955-4ecc-a534-f9fbf5369856', u'fstype': u'ext4'}, u'uuid': u'cb9eed90-0155-4ae6-9e72-3d09e57356b0', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cpmhen', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/14/', u'used_size': 107374182400, u'id': 14, u'size': 107374182400}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'18dd3ce0-ec47-4266-a0a2-b555575d5c9f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cpmhen', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b207cdc6-d6a7-4466-8837-cf4a93dd6ae7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/partition/9', u'type': u'partition', u'id': 9, u'device_id': 3}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cpmhen', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/'}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'86ab761f-f955-4ecc-a534-f9fbf5369856', u'fstype': u'ext4'}, u'uuid': u'cb9eed90-0155-4ae6-9e72-3d09e57356b0', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cpmhen', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/14/'}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cpmhen', u'id': 9}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'18dd3ce0-ec47-4266-a0a2-b555575d5c9f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cpmhen', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b207cdc6-d6a7-4466-8837-cf4a93dd6ae7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/partition/9', u'type': u'partition', u'id': 9, u'device_id': 3}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cpmhen', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'size': 2397998940160}, u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'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': 39, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cpmhen', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/interfaces/5/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 40}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cpmhen', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/interfaces/12/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 41}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cpmhen', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/interfaces/14/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 42}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cpmhen', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/interfaces/15/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'18dd3ce0-ec47-4266-a0a2-b555575d5c9f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cpmhen', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b207cdc6-d6a7-4466-8837-cf4a93dd6ae7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/partition/9', u'type': u'partition', u'id': 9, u'device_id': 3}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cpmhen', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/cpmhen/blockdevices/3/', u'used_size': 2397998940160, u'id': 3, u'size': 2397998940160}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'ip_addresses': [u'192.168.11.38'], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-05-26 05:13:49,259 [salt.state       :300 ][INFO    ][8003] {'new': {'storage_layout': 'lvm'}}
2019-05-26 05:13:49,260 [salt.state       :1951][INFO    ][8003] Completed state [maas_machines_storage_cmp001_lvm] at time 05:13:49.259974 duration_in_ms=2460.968
2019-05-26 05:13:49,263 [salt.minion      :1711][INFO    ][8003] Returning information for job: 20190526051338848043
2019-05-26 05:13:49,909 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526051349892114
2019-05-26 05:13:49,931 [salt.minion      :1432][INFO    ][8110] Starting a new job with PID 8110
2019-05-26 05:13:50,672 [salt.state       :915 ][INFO    ][8110] Loading fresh modules for state activity
2019-05-26 05:13:50,730 [salt.fileclient  :1219][INFO    ][8110] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-26 05:13:50,779 [salt.state       :1780][INFO    ][8110] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:13:50.779897
2019-05-26 05:13:50,780 [salt.state       :1813][INFO    ][8110] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:13:50,782 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8110] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:13:52,182 [salt.state       :300 ][INFO    ][8110] {'pid': 8118, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:13:52,183 [salt.state       :1951][INFO    ][8110] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:13:52.183204 duration_in_ms=1403.306
2019-05-26 05:13:52,185 [salt.state       :1780][INFO    ][8110] Running state [maas.deploy_machines] at time 05:13:52.185795
2019-05-26 05:13:52,186 [salt.state       :1813][INFO    ][8110] Executing state module.run for [maas.deploy_machines]
2019-05-26 05:13:52,187 [salt.utils.decorators:613 ][WARNING ][8110] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:13:52,916 [salt.loaded.ext.module.maas:684 ][INFO    ][8110] deploymachines hwe_kernel=hwe-16.04 system_id=msk4aw distro_series=xenial
2019-05-26 05:13:55,659 [salt.loaded.ext.module.maas:684 ][INFO    ][8110] deploymachines hwe_kernel=hwe-16.04 system_id=cpmhen distro_series=xenial
2019-05-26 05:13:58,246 [salt.loaded.ext.module.maas:684 ][INFO    ][8110] deploymachines hwe_kernel=hwe-16.04 system_id=cgkbns distro_series=xenial
2019-05-26 05:14:00,799 [salt.loaded.ext.module.maas:684 ][INFO    ][8110] deploymachines hwe_kernel=hwe-16.04 system_id=hxw4da distro_series=xenial
2019-05-26 05:14:03,399 [salt.loaded.ext.module.maas:684 ][INFO    ][8110] deploymachines hwe_kernel=hwe-16.04 system_id=7d38ta distro_series=xenial
2019-05-26 05:14:04,948 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051404935865
2019-05-26 05:14:04,968 [salt.minion      :1432][INFO    ][8370] Starting a new job with PID 8370
2019-05-26 05:14:04,992 [salt.minion      :1711][INFO    ][8370] Returning information for job: 20190526051404935865
2019-05-26 05:14:06,142 [salt.state       :300 ][INFO    ][8110] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-26 05:14:06,143 [salt.state       :1951][INFO    ][8110] Completed state [maas.deploy_machines] at time 05:14:06.143454 duration_in_ms=13957.657
2019-05-26 05:14:06,147 [salt.minion      :1711][INFO    ][8110] Returning information for job: 20190526051349892114
2019-05-26 05:14:06,775 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526051406758300
2019-05-26 05:14:06,796 [salt.minion      :1432][INFO    ][8393] Starting a new job with PID 8393
2019-05-26 05:14:10,514 [salt.state       :915 ][INFO    ][8393] Loading fresh modules for state activity
2019-05-26 05:14:10,568 [salt.fileclient  :1219][INFO    ][8393] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-26 05:14:10,611 [salt.state       :1780][INFO    ][8393] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:10.611446
2019-05-26 05:14:10,611 [salt.state       :1813][INFO    ][8393] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:14:10,613 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8393] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:14:12,113 [salt.state       :300 ][INFO    ][8393] {'pid': 8408, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:14:12,114 [salt.state       :1951][INFO    ][8393] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:14:12.114259 duration_in_ms=1502.813
2019-05-26 05:14:12,115 [salt.state       :1780][INFO    ][8393] Running state [maas.wait_for_machine_status] at time 05:14:12.115885
2019-05-26 05:14:12,116 [salt.state       :1813][INFO    ][8393] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 05:14:12,116 [salt.utils.decorators:613 ][WARNING ][8393] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:14:15,645 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.47595096s left)
2019-05-26 05:14:21,799 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051421784674
2019-05-26 05:14:21,819 [salt.minion      :1432][INFO    ][8421] Starting a new job with PID 8421
2019-05-26 05:14:21,843 [salt.minion      :1711][INFO    ][8421] Returning information for job: 20190526051421784674
2019-05-26 05:14:49,261 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.86018801s left)
2019-05-26 05:14:51,851 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051451838030
2019-05-26 05:14:51,874 [salt.minion      :1432][INFO    ][8479] Starting a new job with PID 8479
2019-05-26 05:14:51,897 [salt.minion      :1711][INFO    ][8479] Returning information for job: 20190526051451838030
2019-05-26 05:15:21,950 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051521937619
2019-05-26 05:15:21,972 [salt.minion      :1432][INFO    ][8497] Starting a new job with PID 8497
2019-05-26 05:15:21,995 [salt.minion      :1711][INFO    ][8497] Returning information for job: 20190526051521937619
2019-05-26 05:15:22,865 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.25602102s left)
2019-05-26 05:15:51,987 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051551975319
2019-05-26 05:15:52,006 [salt.minion      :1432][INFO    ][8640] Starting a new job with PID 8640
2019-05-26 05:15:52,027 [salt.minion      :1711][INFO    ][8640] Returning information for job: 20190526051551975319
2019-05-26 05:15:56,286 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2145.83528399s left)
2019-05-26 05:16:22,035 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051622021992
2019-05-26 05:16:22,057 [salt.minion      :1432][INFO    ][8806] Starting a new job with PID 8806
2019-05-26 05:16:22,080 [salt.minion      :1711][INFO    ][8806] Returning information for job: 20190526051622021992
2019-05-26 05:16:29,484 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.63635397s left)
2019-05-26 05:16:52,086 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051652068866
2019-05-26 05:16:52,108 [salt.minion      :1432][INFO    ][9584] Starting a new job with PID 9584
2019-05-26 05:16:52,131 [salt.minion      :1711][INFO    ][9584] Returning information for job: 20190526051652068866
2019-05-26 05:17:02,750 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.37113094s left)
2019-05-26 05:17:22,139 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051722125994
2019-05-26 05:17:22,161 [salt.minion      :1432][INFO    ][9608] Starting a new job with PID 9608
2019-05-26 05:17:22,184 [salt.minion      :1711][INFO    ][9608] Returning information for job: 20190526051722125994
2019-05-26 05:17:36,043 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.07814693s left)
2019-05-26 05:17:52,200 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051752187312
2019-05-26 05:17:52,223 [salt.minion      :1432][INFO    ][9763] Starting a new job with PID 9763
2019-05-26 05:17:52,246 [salt.minion      :1711][INFO    ][9763] Returning information for job: 20190526051752187312
2019-05-26 05:18:09,600 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.52035999s left)
2019-05-26 05:18:22,265 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051822250001
2019-05-26 05:18:22,288 [salt.minion      :1432][INFO    ][9793] Starting a new job with PID 9793
2019-05-26 05:18:22,312 [salt.minion      :1711][INFO    ][9793] Returning information for job: 20190526051822250001
2019-05-26 05:18:42,655 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.46603894s left)
2019-05-26 05:18:52,336 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051852320121
2019-05-26 05:18:52,358 [salt.minion      :1432][INFO    ][10346] Starting a new job with PID 10346
2019-05-26 05:18:52,382 [salt.minion      :1711][INFO    ][10346] Returning information for job: 20190526051852320121
2019-05-26 05:19:16,218 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.90249491s left)
2019-05-26 05:19:22,408 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051922394655
2019-05-26 05:19:22,430 [salt.minion      :1432][INFO    ][10378] Starting a new job with PID 10378
2019-05-26 05:19:22,452 [salt.minion      :1711][INFO    ][10378] Returning information for job: 20190526051922394655
2019-05-26 05:19:50,005 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.11543012s left)
2019-05-26 05:19:52,477 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526051952465106
2019-05-26 05:19:52,499 [salt.minion      :1432][INFO    ][10859] Starting a new job with PID 10859
2019-05-26 05:19:52,523 [salt.minion      :1711][INFO    ][10859] Returning information for job: 20190526051952465106
2019-05-26 05:20:22,556 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052022544473
2019-05-26 05:20:22,580 [salt.minion      :1432][INFO    ][10876] Starting a new job with PID 10876
2019-05-26 05:20:22,602 [salt.minion      :1711][INFO    ][10876] Returning information for job: 20190526052022544473
2019-05-26 05:20:23,369 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.75205708s left)
2019-05-26 05:20:52,640 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052052628287
2019-05-26 05:20:52,663 [salt.minion      :1432][INFO    ][10931] Starting a new job with PID 10931
2019-05-26 05:20:52,686 [salt.minion      :1711][INFO    ][10931] Returning information for job: 20190526052052628287
2019-05-26 05:20:56,757 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.36431193s left)
2019-05-26 05:21:22,732 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052122719916
2019-05-26 05:21:22,752 [salt.minion      :1432][INFO    ][10997] Starting a new job with PID 10997
2019-05-26 05:21:22,778 [salt.minion      :1711][INFO    ][10997] Returning information for job: 20190526052122719916
2019-05-26 05:21:30,299 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1811.82204103s left)
2019-05-26 05:21:52,848 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052152835962
2019-05-26 05:21:52,865 [salt.minion      :1432][INFO    ][11320] Starting a new job with PID 11320
2019-05-26 05:21:52,886 [salt.minion      :1711][INFO    ][11320] Returning information for job: 20190526052152835962
2019-05-26 05:22:03,766 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1778.35494399s left)
2019-05-26 05:22:22,886 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052222873691
2019-05-26 05:22:22,909 [salt.minion      :1432][INFO    ][11392] Starting a new job with PID 11392
2019-05-26 05:22:22,933 [salt.minion      :1711][INFO    ][11392] Returning information for job: 20190526052222873691
2019-05-26 05:22:37,394 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1744.72643304s left)
2019-05-26 05:22:53,000 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052252987515
2019-05-26 05:22:53,023 [salt.minion      :1432][INFO    ][11754] Starting a new job with PID 11754
2019-05-26 05:22:53,047 [salt.minion      :1711][INFO    ][11754] Returning information for job: 20190526052252987515
2019-05-26 05:23:10,865 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1711.25627613s left)
2019-05-26 05:23:23,121 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052323108457
2019-05-26 05:23:23,144 [salt.minion      :1432][INFO    ][11773] Starting a new job with PID 11773
2019-05-26 05:23:23,166 [salt.minion      :1711][INFO    ][11773] Returning information for job: 20190526052323108457
2019-05-26 05:23:44,322 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1677.79879808s left)
2019-05-26 05:23:53,245 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052353232475
2019-05-26 05:23:53,267 [salt.minion      :1432][INFO    ][11830] Starting a new job with PID 11830
2019-05-26 05:23:53,291 [salt.minion      :1711][INFO    ][11830] Returning information for job: 20190526052353232475
2019-05-26 05:24:17,655 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1644.46615005s left)
2019-05-26 05:24:23,380 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052423367907
2019-05-26 05:24:23,402 [salt.minion      :1432][INFO    ][11850] Starting a new job with PID 11850
2019-05-26 05:24:23,424 [salt.minion      :1711][INFO    ][11850] Returning information for job: 20190526052423367907
2019-05-26 05:24:51,099 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1611.0216651s left)
2019-05-26 05:24:53,526 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052453510902
2019-05-26 05:24:53,548 [salt.minion      :1432][INFO    ][11908] Starting a new job with PID 11908
2019-05-26 05:24:53,573 [salt.minion      :1711][INFO    ][11908] Returning information for job: 20190526052453510902
2019-05-26 05:25:23,683 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052523670361
2019-05-26 05:25:23,702 [salt.minion      :1432][INFO    ][11927] Starting a new job with PID 11927
2019-05-26 05:25:23,726 [salt.minion      :1711][INFO    ][11927] Returning information for job: 20190526052523670361
2019-05-26 05:25:24,674 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1577.44687104s left)
2019-05-26 05:25:53,841 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052553828682
2019-05-26 05:25:53,865 [salt.minion      :1432][INFO    ][11982] Starting a new job with PID 11982
2019-05-26 05:25:53,887 [salt.minion      :1711][INFO    ][11982] Returning information for job: 20190526052553828682
2019-05-26 05:25:58,184 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1543.93696713s left)
2019-05-26 05:26:24,013 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052624000839
2019-05-26 05:26:24,036 [salt.minion      :1432][INFO    ][12008] Starting a new job with PID 12008
2019-05-26 05:26:24,060 [salt.minion      :1711][INFO    ][12008] Returning information for job: 20190526052624000839
2019-05-26 05:26:31,578 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1510.54248691s left)
2019-05-26 05:26:54,197 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052654184846
2019-05-26 05:26:54,220 [salt.minion      :1432][INFO    ][12076] Starting a new job with PID 12076
2019-05-26 05:26:54,243 [salt.minion      :1711][INFO    ][12076] Returning information for job: 20190526052654184846
2019-05-26 05:27:04,944 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1477.17644596s left)
2019-05-26 05:27:24,388 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052724375221
2019-05-26 05:27:24,410 [salt.minion      :1432][INFO    ][12096] Starting a new job with PID 12096
2019-05-26 05:27:24,435 [salt.minion      :1711][INFO    ][12096] Returning information for job: 20190526052724375221
2019-05-26 05:27:38,257 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1443.86426806s left)
2019-05-26 05:27:54,591 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052754577858
2019-05-26 05:27:54,613 [salt.minion      :1432][INFO    ][12153] Starting a new job with PID 12153
2019-05-26 05:27:54,637 [salt.minion      :1711][INFO    ][12153] Returning information for job: 20190526052754577858
2019-05-26 05:28:11,659 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1410.46183896s left)
2019-05-26 05:28:24,802 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052824789444
2019-05-26 05:28:24,825 [salt.minion      :1432][INFO    ][12173] Starting a new job with PID 12173
2019-05-26 05:28:24,849 [salt.minion      :1711][INFO    ][12173] Returning information for job: 20190526052824789444
2019-05-26 05:28:45,147 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1376.97399902s left)
2019-05-26 05:28:55,024 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052855012333
2019-05-26 05:28:55,046 [salt.minion      :1432][INFO    ][12371] Starting a new job with PID 12371
2019-05-26 05:28:55,068 [salt.minion      :1711][INFO    ][12371] Returning information for job: 20190526052855012333
2019-05-26 05:29:18,637 [salt.loaded.ext.module.maas:1023][INFO    ][8393] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1343.48413205s left)
2019-05-26 05:29:25,041 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052925028915
2019-05-26 05:29:25,064 [salt.minion      :1432][INFO    ][12402] Starting a new job with PID 12402
2019-05-26 05:29:25,088 [salt.minion      :1711][INFO    ][12402] Returning information for job: 20190526052925028915
2019-05-26 05:29:50,675 [salt.loaded.ext.module.maas:993 ][INFO    ][8393] Machine cgkbns mark broken
2019-05-26 05:29:51,450 [salt.loaded.ext.module.maas:996 ][INFO    ][8393] Machine cgkbns mark fixed
2019-05-26 05:29:52,690 [salt.loaded.ext.module.maas:684 ][INFO    ][8393] deploymachines hwe_kernel=hwe-16.04 system_id=cgkbns distro_series=xenial
2019-05-26 05:29:55,078 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526052955065188
2019-05-26 05:29:55,098 [salt.minion      :1432][INFO    ][12510] Starting a new job with PID 12510
2019-05-26 05:29:55,123 [salt.minion      :1711][INFO    ][12510] Returning information for job: 20190526052955065188
2019-05-26 05:29:55,450 [salt.loaded.ext.module.maas:160 ][ERROR   ][8393] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-05-26 05:29:55,451 [salt.state       :302 ][ERROR   ][8393] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-05-26 05:29:55,452 [salt.state       :1951][INFO    ][8393] Completed state [maas.wait_for_machine_status] at time 05:29:55.452184 duration_in_ms=943336.294
2019-05-26 05:29:55,457 [salt.minion      :1711][INFO    ][8393] Returning information for job: 20190526051406758300
2019-05-26 05:30:06,243 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command pillar.get with jid 20190526053006230683
2019-05-26 05:30:06,265 [salt.minion      :1432][INFO    ][12542] Starting a new job with PID 12542
2019-05-26 05:30:06,273 [salt.minion      :1711][INFO    ][12542] Returning information for job: 20190526053006230683
2019-05-26 05:30:06,832 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command service.status with jid 20190526053006819457
2019-05-26 05:30:06,853 [salt.minion      :1432][INFO    ][12548] Starting a new job with PID 12548
2019-05-26 05:30:07,240 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12548] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:07,279 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12548] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-26 05:30:07,297 [salt.minion      :1711][INFO    ][12548] Returning information for job: 20190526053006819457
2019-05-26 05:30:07,886 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053007873332
2019-05-26 05:30:07,909 [salt.minion      :1432][INFO    ][12559] Starting a new job with PID 12559
2019-05-26 05:30:11,663 [salt.state       :915 ][INFO    ][12559] Loading fresh modules for state activity
2019-05-26 05:30:12,067 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 05:30:12,392 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 05:30:13,237 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 05:30:13,551 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 05:30:14,892 [salt.state       :1780][INFO    ][12559] Running state [salt-minion] at time 05:30:14.892286
2019-05-26 05:30:14,892 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [salt-minion]
2019-05-26 05:30:14,893 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 05:30:14,982 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:14,982 [salt.state       :1951][INFO    ][12559] Completed state [salt-minion] at time 05:30:14.982431 duration_in_ms=90.145
2019-05-26 05:30:14,982 [salt.state       :1780][INFO    ][12559] Running state [salt_minion_dependency_packages] at time 05:30:14.982822
2019-05-26 05:30:14,983 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-26 05:30:14,990 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:14,990 [salt.state       :1951][INFO    ][12559] Completed state [salt_minion_dependency_packages] at time 05:30:14.990332 duration_in_ms=7.509
2019-05-26 05:30:14,993 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/minion.d/minion.conf] at time 05:30:14.993671
2019-05-26 05:30:14,994 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-26 05:30:15,201 [salt.state       :300 ][INFO    ][12559] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-26 05:30:15,201 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/minion.d/minion.conf] at time 05:30:15.201861 duration_in_ms=208.189
2019-05-26 05:30:15,202 [salt.state       :1780][INFO    ][12559] Running state [python-netaddr] at time 05:30:15.202241
2019-05-26 05:30:15,202 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [python-netaddr]
2019-05-26 05:30:15,209 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:15,209 [salt.state       :1951][INFO    ][12559] Completed state [python-netaddr] at time 05:30:15.209904 duration_in_ms=7.662
2019-05-26 05:30:15,213 [salt.state       :1780][INFO    ][12559] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:30:15.213218
2019-05-26 05:30:15,213 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-26 05:30:15,224 [salt.state       :300 ][INFO    ][12559] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-26 05:30:15,224 [salt.state       :1951][INFO    ][12559] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 05:30:15.224288 duration_in_ms=11.071
2019-05-26 05:30:15,225 [salt.state       :1780][INFO    ][12559] Running state [salt-minion] at time 05:30:15.225367
2019-05-26 05:30:15,225 [salt.state       :1813][INFO    ][12559] Executing state service.running for [salt-minion]
2019-05-26 05:30:15,226 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:15,263 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-26 05:30:15,280 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-26 05:30:15,297 [salt.state       :300 ][INFO    ][12559] The service salt-minion is already running
2019-05-26 05:30:15,297 [salt.state       :1951][INFO    ][12559] Completed state [salt-minion] at time 05:30:15.297680 duration_in_ms=72.312
2019-05-26 05:30:15,299 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains.d] at time 05:30:15.299231
2019-05-26 05:30:15,299 [salt.state       :1813][INFO    ][12559] Executing state file.directory for [/etc/salt/grains.d]
2019-05-26 05:30:15,300 [salt.state       :300 ][INFO    ][12559] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-26 05:30:15,301 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains.d] at time 05:30:15.300984 duration_in_ms=1.752
2019-05-26 05:30:15,301 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains] at time 05:30:15.301870
2019-05-26 05:30:15,302 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/grains]
2019-05-26 05:30:15,302 [salt.state       :300 ][INFO    ][12559] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-26 05:30:15,303 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains] at time 05:30:15.303181 duration_in_ms=1.31
2019-05-26 05:30:15,303 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains.d/placeholder] at time 05:30:15.303806
2019-05-26 05:30:15,304 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-26 05:30:15,304 [salt.state       :300 ][INFO    ][12559] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-26 05:30:15,305 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains.d/placeholder] at time 05:30:15.305082 duration_in_ms=1.276
2019-05-26 05:30:15,305 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains.d/sphinx] at time 05:30:15.305686
2019-05-26 05:30:15,306 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-26 05:30:15,321 [salt.state       :300 ][INFO    ][12559] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-26 05:30:15,321 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains.d/sphinx] at time 05:30:15.321594 duration_in_ms=15.908
2019-05-26 05:30:15,323 [salt.state       :1780][INFO    ][12559] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.323787
2019-05-26 05:30:15,324 [salt.state       :1813][INFO    ][12559] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 05:30:15,324 [salt.state       :300 ][INFO    ][12559] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-26 05:30:15,324 [salt.state       :1951][INFO    ][12559] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.324872 duration_in_ms=1.084
2019-05-26 05:30:15,325 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains.d/dns_records] at time 05:30:15.325474
2019-05-26 05:30:15,325 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-26 05:30:15,339 [salt.state       :300 ][INFO    ][12559] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-26 05:30:15,339 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains.d/dns_records] at time 05:30:15.339306 duration_in_ms=13.831
2019-05-26 05:30:15,340 [salt.state       :1780][INFO    ][12559] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.340344
2019-05-26 05:30:15,340 [salt.state       :1813][INFO    ][12559] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 05:30:15,341 [salt.state       :300 ][INFO    ][12559] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-26 05:30:15,341 [salt.state       :1951][INFO    ][12559] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.341405 duration_in_ms=1.06
2019-05-26 05:30:15,342 [salt.state       :1780][INFO    ][12559] Running state [/etc/salt/grains.d/salt] at time 05:30:15.342017
2019-05-26 05:30:15,342 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-26 05:30:15,357 [salt.state       :300 ][INFO    ][12559] File /etc/salt/grains.d/salt is in the correct state
2019-05-26 05:30:15,357 [salt.state       :1951][INFO    ][12559] Completed state [/etc/salt/grains.d/salt] at time 05:30:15.357326 duration_in_ms=15.308
2019-05-26 05:30:15,358 [salt.state       :1780][INFO    ][12559] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.358279
2019-05-26 05:30:15,358 [salt.state       :1813][INFO    ][12559] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 05:30:15,359 [salt.state       :300 ][INFO    ][12559] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-26 05:30:15,359 [salt.state       :1951][INFO    ][12559] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 05:30:15.359343 duration_in_ms=1.063
2019-05-26 05:30:15,361 [salt.state       :1780][INFO    ][12559] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:30:15.361173
2019-05-26 05:30:15,361 [salt.state       :1813][INFO    ][12559] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-26 05:30:15,362 [salt.state       :300 ][INFO    ][12559] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-26 05:30:15,362 [salt.state       :1951][INFO    ][12559] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 05:30:15.362250 duration_in_ms=1.077
2019-05-26 05:30:15,363 [salt.state       :1780][INFO    ][12559] Running state [mine.update] at time 05:30:15.363037
2019-05-26 05:30:15,363 [salt.state       :1813][INFO    ][12559] Executing state module.wait for [mine.update]
2019-05-26 05:30:15,363 [salt.state       :300 ][INFO    ][12559] No changes made for mine.update
2019-05-26 05:30:15,364 [salt.state       :1951][INFO    ][12559] Completed state [mine.update] at time 05:30:15.364051 duration_in_ms=1.013
2019-05-26 05:30:15,364 [salt.state       :1780][INFO    ][12559] Running state [ca-certificates] at time 05:30:15.364408
2019-05-26 05:30:15,364 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [ca-certificates]
2019-05-26 05:30:15,371 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:15,371 [salt.state       :1951][INFO    ][12559] Completed state [ca-certificates] at time 05:30:15.371679 duration_in_ms=7.272
2019-05-26 05:30:15,372 [salt.state       :1780][INFO    ][12559] Running state [update-ca-certificates] at time 05:30:15.372431
2019-05-26 05:30:15,372 [salt.state       :1813][INFO    ][12559] Executing state cmd.wait for [update-ca-certificates]
2019-05-26 05:30:15,373 [salt.state       :300 ][INFO    ][12559] No changes made for update-ca-certificates
2019-05-26 05:30:15,373 [salt.state       :1951][INFO    ][12559] Completed state [update-ca-certificates] at time 05:30:15.373413 duration_in_ms=0.982
2019-05-26 05:30:15,373 [salt.state       :1780][INFO    ][12559] Running state [iptables] at time 05:30:15.373781
2019-05-26 05:30:15,374 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [iptables]
2019-05-26 05:30:15,380 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:15,380 [salt.state       :1951][INFO    ][12559] Completed state [iptables] at time 05:30:15.380316 duration_in_ms=6.535
2019-05-26 05:30:15,380 [salt.state       :1780][INFO    ][12559] Running state [iptables-persistent] at time 05:30:15.380664
2019-05-26 05:30:15,381 [salt.state       :1813][INFO    ][12559] Executing state pkg.installed for [iptables-persistent]
2019-05-26 05:30:15,386 [salt.state       :300 ][INFO    ][12559] All specified packages are already installed
2019-05-26 05:30:15,387 [salt.state       :1951][INFO    ][12559] Completed state [iptables-persistent] at time 05:30:15.386999 duration_in_ms=6.336
2019-05-26 05:30:15,388 [salt.state       :1780][INFO    ][12559] Running state [iptables_modules_v4_load] at time 05:30:15.388001
2019-05-26 05:30:15,388 [salt.state       :1813][INFO    ][12559] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-26 05:30:15,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'lsmod' in directory '/root'
2019-05-26 05:30:15,411 [salt.state       :300 ][INFO    ][12559] Kernel modules iptable_filter, ip_tables are already present
2019-05-26 05:30:15,412 [salt.state       :1951][INFO    ][12559] Completed state [iptables_modules_v4_load] at time 05:30:15.411970 duration_in_ms=23.969
2019-05-26 05:30:15,412 [salt.state       :1780][INFO    ][12559] Running state [/etc/iptables/rules.v4] at time 05:30:15.412624
2019-05-26 05:30:15,413 [salt.state       :1813][INFO    ][12559] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-26 05:30:15,488 [salt.state       :300 ][INFO    ][12559] File /etc/iptables/rules.v4 is in the correct state
2019-05-26 05:30:15,489 [salt.state       :1951][INFO    ][12559] Completed state [/etc/iptables/rules.v4] at time 05:30:15.489139 duration_in_ms=76.514
2019-05-26 05:30:15,490 [salt.state       :1780][INFO    ][12559] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:30:15.489987
2019-05-26 05:30:15,490 [salt.state       :1813][INFO    ][12559] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-26 05:30:15,490 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-26 05:30:15,507 [salt.state       :300 ][INFO    ][12559] onlyif execution failed
2019-05-26 05:30:15,508 [salt.state       :1951][INFO    ][12559] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 05:30:15.508128 duration_in_ms=18.141
2019-05-26 05:30:15,508 [salt.state       :1780][INFO    ][12559] Running state [netfilter-persistent] at time 05:30:15.508910
2019-05-26 05:30:15,509 [salt.state       :1813][INFO    ][12559] Executing state service.running for [netfilter-persistent]
2019-05-26 05:30:15,509 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:15,528 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-26 05:30:15,546 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-26 05:30:15,563 [salt.state       :300 ][INFO    ][12559] The service netfilter-persistent is already running
2019-05-26 05:30:15,563 [salt.state       :1951][INFO    ][12559] Completed state [netfilter-persistent] at time 05:30:15.563644 duration_in_ms=54.733
2019-05-26 05:30:15,564 [salt.state       :1780][INFO    ][12559] Running state [iptables_extra.remove_stale_tables] at time 05:30:15.564766
2019-05-26 05:30:15,565 [salt.state       :1813][INFO    ][12559] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-26 05:30:15,565 [salt.state       :300 ][INFO    ][12559] No changes made for iptables_extra.remove_stale_tables
2019-05-26 05:30:15,566 [salt.state       :1951][INFO    ][12559] Completed state [iptables_extra.remove_stale_tables] at time 05:30:15.565954 duration_in_ms=1.188
2019-05-26 05:30:15,566 [salt.state       :1780][INFO    ][12559] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:30:15.566274
2019-05-26 05:30:15,566 [salt.state       :1813][INFO    ][12559] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-26 05:30:15,567 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12559] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-26 05:30:15,582 [salt.state       :300 ][INFO    ][12559] onlyif execution failed
2019-05-26 05:30:15,582 [salt.state       :1951][INFO    ][12559] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 05:30:15.582870 duration_in_ms=16.596
2019-05-26 05:30:15,584 [salt.state       :1780][INFO    ][12559] Running state [/etc/iptables/rules.v6] at time 05:30:15.584117
2019-05-26 05:30:15,584 [salt.state       :1813][INFO    ][12559] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-26 05:30:15,585 [salt.state       :300 ][INFO    ][12559] File /etc/iptables/rules.v6 is not present
2019-05-26 05:30:15,585 [salt.state       :1951][INFO    ][12559] Completed state [/etc/iptables/rules.v6] at time 05:30:15.585433 duration_in_ms=1.316
2019-05-26 05:30:15,586 [salt.state       :1780][INFO    ][12559] Running state [iptables_extra.flush_all] at time 05:30:15.586334
2019-05-26 05:30:15,586 [salt.state       :1813][INFO    ][12559] Executing state module.wait for [iptables_extra.flush_all]
2019-05-26 05:30:15,587 [salt.state       :300 ][INFO    ][12559] No changes made for iptables_extra.flush_all
2019-05-26 05:30:15,587 [salt.state       :1951][INFO    ][12559] Completed state [iptables_extra.flush_all] at time 05:30:15.587376 duration_in_ms=1.042
2019-05-26 05:30:15,591 [salt.minion      :1711][INFO    ][12559] Returning information for job: 20190526053007873332
2019-05-26 05:30:16,226 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053016213604
2019-05-26 05:30:16,248 [salt.minion      :1432][INFO    ][12635] Starting a new job with PID 12635
2019-05-26 05:30:16,980 [salt.state       :915 ][INFO    ][12635] Loading fresh modules for state activity
2019-05-26 05:30:17,582 [salt.state       :1780][INFO    ][12635] Running state [maas-rack-controller] at time 05:30:17.582216
2019-05-26 05:30:17,582 [salt.state       :1813][INFO    ][12635] Executing state pkg.installed for [maas-rack-controller]
2019-05-26 05:30:17,583 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12635] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 05:30:17,679 [salt.state       :300 ][INFO    ][12635] All specified packages are already installed
2019-05-26 05:30:17,679 [salt.state       :1951][INFO    ][12635] Completed state [maas-rack-controller] at time 05:30:17.679584 duration_in_ms=97.367
2019-05-26 05:30:17,679 [salt.state       :1780][INFO    ][12635] Running state [ipmitool] at time 05:30:17.679943
2019-05-26 05:30:17,680 [salt.state       :1813][INFO    ][12635] Executing state pkg.installed for [ipmitool]
2019-05-26 05:30:17,687 [salt.state       :300 ][INFO    ][12635] All specified packages are already installed
2019-05-26 05:30:17,687 [salt.state       :1951][INFO    ][12635] Completed state [ipmitool] at time 05:30:17.687258 duration_in_ms=7.315
2019-05-26 05:30:17,690 [salt.state       :1780][INFO    ][12635] Running state [/etc/maas/rackd.conf] at time 05:30:17.690478
2019-05-26 05:30:17,690 [salt.state       :1813][INFO    ][12635] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-26 05:30:17,691 [salt.state       :300 ][INFO    ][12635] No changes needed to be made
2019-05-26 05:30:17,692 [salt.state       :1951][INFO    ][12635] Completed state [/etc/maas/rackd.conf] at time 05:30:17.692125 duration_in_ms=1.647
2019-05-26 05:30:17,692 [salt.state       :1780][INFO    ][12635] Running state [/etc/maas/rackd.conf] at time 05:30:17.692375
2019-05-26 05:30:17,692 [salt.state       :1813][INFO    ][12635] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-26 05:30:17,693 [salt.loaded.int.states.file:2298][WARNING ][12635] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-26 05:30:17,693 [salt.state       :300 ][INFO    ][12635] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-26 05:30:17,693 [salt.state       :1951][INFO    ][12635] Completed state [/etc/maas/rackd.conf] at time 05:30:17.693734 duration_in_ms=1.359
2019-05-26 05:30:17,694 [salt.state       :1780][INFO    ][12635] Running state [maas-rackd] at time 05:30:17.694722
2019-05-26 05:30:17,695 [salt.state       :1813][INFO    ][12635] Executing state service.running for [maas-rackd]
2019-05-26 05:30:17,695 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12635] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:17,729 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12635] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-26 05:30:17,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12635] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-26 05:30:17,763 [salt.state       :300 ][INFO    ][12635] The service maas-rackd is already running
2019-05-26 05:30:17,764 [salt.state       :1951][INFO    ][12635] Completed state [maas-rackd] at time 05:30:17.764086 duration_in_ms=69.364
2019-05-26 05:30:17,765 [salt.minion      :1711][INFO    ][12635] Returning information for job: 20190526053016213604
2019-05-26 05:30:18,361 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053018348460
2019-05-26 05:30:18,384 [salt.minion      :1432][INFO    ][12658] Starting a new job with PID 12658
2019-05-26 05:30:19,119 [salt.state       :915 ][INFO    ][12658] Loading fresh modules for state activity
2019-05-26 05:30:19,823 [salt.state       :1780][INFO    ][12658] Running state [maas-region-controller] at time 05:30:19.823196
2019-05-26 05:30:19,823 [salt.state       :1813][INFO    ][12658] Executing state pkg.installed for [maas-region-controller]
2019-05-26 05:30:19,824 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 05:30:19,906 [salt.state       :300 ][INFO    ][12658] All specified packages are already installed
2019-05-26 05:30:19,906 [salt.state       :1951][INFO    ][12658] Completed state [maas-region-controller] at time 05:30:19.906881 duration_in_ms=83.685
2019-05-26 05:30:19,907 [salt.state       :1780][INFO    ][12658] Running state [python-oauth] at time 05:30:19.907177
2019-05-26 05:30:19,907 [salt.state       :1813][INFO    ][12658] Executing state pkg.installed for [python-oauth]
2019-05-26 05:30:19,913 [salt.state       :300 ][INFO    ][12658] All specified packages are already installed
2019-05-26 05:30:19,913 [salt.state       :1951][INFO    ][12658] Completed state [python-oauth] at time 05:30:19.913280 duration_in_ms=6.102
2019-05-26 05:30:19,916 [salt.state       :1780][INFO    ][12658] Running state [/etc/maas/regiond.conf] at time 05:30:19.916014
2019-05-26 05:30:19,916 [salt.state       :1813][INFO    ][12658] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-26 05:30:19,962 [salt.state       :300 ][INFO    ][12658] No changes needed to be made
2019-05-26 05:30:19,962 [salt.state       :1951][INFO    ][12658] Completed state [/etc/maas/regiond.conf] at time 05:30:19.962929 duration_in_ms=46.915
2019-05-26 05:30:19,963 [salt.state       :1780][INFO    ][12658] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:30:19.963409
2019-05-26 05:30:19,963 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-26 05:30:20,022 [salt.state       :300 ][INFO    ][12658] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-26 05:30:20,022 [salt.state       :1951][INFO    ][12658] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:30:20.022332 duration_in_ms=58.923
2019-05-26 05:30:20,022 [salt.state       :1780][INFO    ][12658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:30:20.022853
2019-05-26 05:30:20,023 [salt.state       :1813][INFO    ][12658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 05:30:20,035 [salt.state       :300 ][INFO    ][12658] No changes needed to be made
2019-05-26 05:30:20,035 [salt.state       :1951][INFO    ][12658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:30:20.035734 duration_in_ms=12.88
2019-05-26 05:30:20,036 [salt.state       :1780][INFO    ][12658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:30:20.036216
2019-05-26 05:30:20,036 [salt.state       :1813][INFO    ][12658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 05:30:20,060 [salt.state       :300 ][INFO    ][12658] No changes needed to be made
2019-05-26 05:30:20,060 [salt.state       :1951][INFO    ][12658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:30:20.060825 duration_in_ms=24.608
2019-05-26 05:30:20,061 [salt.state       :1780][INFO    ][12658] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:30:20.061607
2019-05-26 05:30:20,062 [salt.state       :1813][INFO    ][12658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-26 05:30:20,097 [salt.state       :300 ][INFO    ][12658] No changes needed to be made
2019-05-26 05:30:20,097 [salt.state       :1951][INFO    ][12658] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:30:20.097639 duration_in_ms=36.033
2019-05-26 05:30:20,098 [salt.state       :1780][INFO    ][12658] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:30:20.098297
2019-05-26 05:30:20,098 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-26 05:30:20,116 [salt.state       :300 ][INFO    ][12658] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-26 05:30:20,118 [salt.state       :1951][INFO    ][12658] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:30:20.118048 duration_in_ms=19.749
2019-05-26 05:30:20,123 [salt.state       :1780][INFO    ][12658] Running state [a2enmod headers] at time 05:30:20.123785
2019-05-26 05:30:20,124 [salt.state       :1813][INFO    ][12658] Executing state cmd.run for [a2enmod headers]
2019-05-26 05:30:20,125 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command 'a2enmod headers' in directory '/root'
2019-05-26 05:30:20,198 [salt.state       :300 ][INFO    ][12658] {'pid': 12677, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-26 05:30:20,199 [salt.state       :1951][INFO    ][12658] Completed state [a2enmod headers] at time 05:30:20.199179 duration_in_ms=75.393
2019-05-26 05:30:20,199 [salt.state       :1780][INFO    ][12658] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:30:20.199794
2019-05-26 05:30:20,200 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-26 05:30:20,223 [salt.state       :300 ][INFO    ][12658] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-26 05:30:20,223 [salt.state       :1951][INFO    ][12658] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:30:20.223677 duration_in_ms=23.883
2019-05-26 05:30:20,224 [salt.state       :1780][INFO    ][12658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:30:20.224603
2019-05-26 05:30:20,225 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-26 05:30:20,308 [salt.state       :300 ][INFO    ][12658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-26 05:30:20,308 [salt.state       :1951][INFO    ][12658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:30:20.308381 duration_in_ms=83.779
2019-05-26 05:30:20,309 [salt.state       :1780][INFO    ][12658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:30:20.309027
2019-05-26 05:30:20,309 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-26 05:30:20,373 [salt.state       :300 ][INFO    ][12658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-26 05:30:20,374 [salt.state       :1951][INFO    ][12658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:30:20.374157 duration_in_ms=65.13
2019-05-26 05:30:20,374 [salt.state       :1780][INFO    ][12658] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:30:20.374718
2019-05-26 05:30:20,375 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-26 05:30:20,440 [salt.state       :300 ][INFO    ][12658] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-26 05:30:20,440 [salt.state       :1951][INFO    ][12658] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:30:20.440376 duration_in_ms=65.657
2019-05-26 05:30:20,440 [salt.state       :1780][INFO    ][12658] Running state [/root/.pgpass] at time 05:30:20.440831
2019-05-26 05:30:20,441 [salt.state       :1813][INFO    ][12658] Executing state file.managed for [/root/.pgpass]
2019-05-26 05:30:20,489 [salt.state       :300 ][INFO    ][12658] File /root/.pgpass is in the correct state
2019-05-26 05:30:20,490 [salt.state       :1951][INFO    ][12658] Completed state [/root/.pgpass] at time 05:30:20.490140 duration_in_ms=49.309
2019-05-26 05:30:20,497 [salt.state       :1780][INFO    ][12658] Running state [maas-region syncdb --noinput] at time 05:30:20.497404
2019-05-26 05:30:20,497 [salt.state       :1813][INFO    ][12658] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-26 05:30:20,498 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-26 05:30:22,818 [salt.state       :300 ][INFO    ][12658] {'pid': 12690, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: auth, sessions, contenttypes, maasserver, metadataserver, piston3, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-26 05:30:22,819 [salt.state       :1951][INFO    ][12658] Completed state [maas-region syncdb --noinput] at time 05:30:22.818880 duration_in_ms=2321.474
2019-05-26 05:30:22,819 [salt.state       :2022][WARNING ][12658] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-26 05:30:22,822 [salt.state       :1780][INFO    ][12658] Running state [maas-regiond] at time 05:30:22.822164
2019-05-26 05:30:22,822 [salt.state       :1813][INFO    ][12658] Executing state service.running for [maas-regiond]
2019-05-26 05:30:22,824 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:22,863 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-26 05:30:22,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-26 05:30:22,904 [salt.state       :300 ][INFO    ][12658] The service maas-regiond is already running
2019-05-26 05:30:22,904 [salt.state       :1951][INFO    ][12658] Completed state [maas-regiond] at time 05:30:22.904551 duration_in_ms=82.387
2019-05-26 05:30:22,907 [salt.state       :1780][INFO    ][12658] Running state [bind9] at time 05:30:22.907094
2019-05-26 05:30:22,907 [salt.state       :1813][INFO    ][12658] Executing state service.running for [bind9]
2019-05-26 05:30:22,908 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:22,930 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-26 05:30:22,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-26 05:30:22,965 [salt.state       :300 ][INFO    ][12658] The service bind9 is already running
2019-05-26 05:30:22,965 [salt.state       :1951][INFO    ][12658] Completed state [bind9] at time 05:30:22.965462 duration_in_ms=58.369
2019-05-26 05:30:22,967 [salt.state       :1780][INFO    ][12658] Running state [apache2] at time 05:30:22.967848
2019-05-26 05:30:22,968 [salt.state       :1813][INFO    ][12658] Executing state service.running for [apache2]
2019-05-26 05:30:22,969 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-26 05:30:22,986 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-26 05:30:23,001 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-26 05:30:23,019 [salt.state       :300 ][INFO    ][12658] The service apache2 is already running
2019-05-26 05:30:23,020 [salt.state       :1951][INFO    ][12658] Completed state [apache2] at time 05:30:23.019972 duration_in_ms=52.123
2019-05-26 05:30:23,022 [salt.state       :1780][INFO    ][12658] Running state [maasng.wait_for_http_code] at time 05:30:23.021953
2019-05-26 05:30:23,022 [salt.state       :1813][INFO    ][12658] Executing state module.run for [maasng.wait_for_http_code]
2019-05-26 05:30:23,023 [salt.utils.decorators:613 ][WARNING ][12658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:23,031 [salt.state       :300 ][INFO    ][12658] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-26 05:30:23,031 [salt.state       :1951][INFO    ][12658] Completed state [maasng.wait_for_http_code] at time 05:30:23.031784 duration_in_ms=9.831
2019-05-26 05:30:23,032 [salt.state       :1780][INFO    ][12658] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:30:23.032686
2019-05-26 05:30:23,033 [salt.state       :1813][INFO    ][12658] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-26 05:30:23,033 [salt.state       :300 ][INFO    ][12658] /var/lib/maas/.setup_admin exists
2019-05-26 05:30:23,033 [salt.state       :1951][INFO    ][12658] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:30:23.033811 duration_in_ms=1.125
2019-05-26 05:30:23,034 [salt.state       :1780][INFO    ][12658] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:30:23.034599
2019-05-26 05:30:23,034 [salt.state       :1813][INFO    ][12658] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:30:23,035 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12658] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:30:24,280 [salt.state       :300 ][INFO    ][12658] {'pid': 12710, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:30:24,281 [salt.state       :1951][INFO    ][12658] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:30:24.281342 duration_in_ms=1246.743
2019-05-26 05:30:24,284 [salt.state       :1780][INFO    ][12658] Running state [maas_region_boot_source_resources_mirror] at time 05:30:24.284835
2019-05-26 05:30:24,285 [salt.state       :1813][INFO    ][12658] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-26 05:30:24,390 [salt.state       :300 ][INFO    ][12658] {'changes': {}}
2019-05-26 05:30:24,391 [salt.state       :1951][INFO    ][12658] Completed state [maas_region_boot_source_resources_mirror] at time 05:30:24.390896 duration_in_ms=106.058
2019-05-26 05:30:24,392 [salt.state       :1780][INFO    ][12658] Running state [maasng.boot_resources_import] at time 05:30:24.392056
2019-05-26 05:30:24,392 [salt.state       :1813][INFO    ][12658] Executing state module.run for [maasng.boot_resources_import]
2019-05-26 05:30:24,393 [salt.utils.decorators:613 ][WARNING ][12658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:24,485 [salt.loaded.ext.module.maasng:1600][INFO    ][12658] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-26 05:30:29,542 [salt.loaded.ext.module.maasng:1600][INFO    ][12658] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-26 05:30:33,390 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053033377616
2019-05-26 05:30:33,414 [salt.minion      :1432][INFO    ][12738] Starting a new job with PID 12738
2019-05-26 05:30:33,438 [salt.minion      :1711][INFO    ][12738] Returning information for job: 20190526053033377616
2019-05-26 05:30:34,615 [salt.loaded.ext.module.maasng:1600][INFO    ][12658] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-26 05:30:39,722 [salt.state       :300 ][INFO    ][12658] {'ret': True}
2019-05-26 05:30:39,723 [salt.state       :1951][INFO    ][12658] Completed state [maasng.boot_resources_import] at time 05:30:39.722918 duration_in_ms=15330.862
2019-05-26 05:30:39,723 [salt.state       :1780][INFO    ][12658] Running state [maas_region_boot_sources_selection_xenial] at time 05:30:39.723927
2019-05-26 05:30:39,724 [salt.state       :1813][INFO    ][12658] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-26 05:30:39,967 [salt.state       :300 ][INFO    ][12658] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-26 05:30:39,967 [salt.state       :1951][INFO    ][12658] Completed state [maas_region_boot_sources_selection_xenial] at time 05:30:39.967707 duration_in_ms=243.779
2019-05-26 05:30:39,969 [salt.state       :1780][INFO    ][12658] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:30:39.969113
2019-05-26 05:30:39,969 [salt.state       :1813][INFO    ][12658] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-26 05:30:39,970 [salt.utils.decorators:613 ][WARNING ][12658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:39,970 [salt.loaded.ext.module.maasng:1771][INFO    ][12658] boot-sources sync initiated for ALL Rack's
2019-05-26 05:30:41,015 [salt.state       :300 ][INFO    ][12658] {'ret': True}
2019-05-26 05:30:41,015 [salt.state       :1951][INFO    ][12658] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:30:41.015641 duration_in_ms=1046.527
2019-05-26 05:30:41,017 [salt.state       :1780][INFO    ][12658] Running state [maas.process_maas_config] at time 05:30:41.017350
2019-05-26 05:30:41,017 [salt.state       :1813][INFO    ][12658] Executing state module.run for [maas.process_maas_config]
2019-05-26 05:30:41,018 [salt.utils.decorators:613 ][WARNING ][12658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:41,019 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=enable_http_proxy value=True
2019-05-26 05:30:41,076 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=upstream_dns value=8.8.8.8
2019-05-26 05:30:41,141 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=commissioning_distro_series value=xenial
2019-05-26 05:30:41,213 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=default_osystem value=ubuntu
2019-05-26 05:30:41,278 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=active_discovery_interval value=600
2019-05-26 05:30:41,333 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=dnssec_validation value=no
2019-05-26 05:30:41,387 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=maas_name value=mas01
2019-05-26 05:30:41,447 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=network_discovery value=enabled
2019-05-26 05:30:44,279 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=enable_third_party_drivers value=True
2019-05-26 05:30:44,339 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=default_storage_layout value=lvm
2019-05-26 05:30:44,392 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=ntp_external_only value=True
2019-05-26 05:30:44,446 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-26 05:30:44,500 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=default_distro_series value=xenial
2019-05-26 05:30:44,587 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-26 05:30:44,729 [salt.state       :300 ][INFO    ][12658] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-26 05:30:44,729 [salt.state       :1951][INFO    ][12658] Completed state [maas.process_maas_config] at time 05:30:44.729380 duration_in_ms=3712.029
2019-05-26 05:30:44,730 [salt.state       :1780][INFO    ][12658] Running state [pxe_admin] at time 05:30:44.730352
2019-05-26 05:30:44,730 [salt.state       :1813][INFO    ][12658] Executing state maasng.fabric_present for [pxe_admin]
2019-05-26 05:30:44,800 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-26 05:30:44,865 [salt.loaded.ext.module.maasng:1008][WARNING ][12658] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-26 05:30:44,866 [salt.loaded.ext.module.maasng:1011][WARNING ][12658] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-26 05:30:44,926 [salt.state       :300 ][INFO    ][12658] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-26 05:30:44,926 [salt.state       :1951][INFO    ][12658] Completed state [pxe_admin] at time 05:30:44.926719 duration_in_ms=196.366
2019-05-26 05:30:44,927 [salt.state       :1780][INFO    ][12658] Running state [vlan 0] at time 05:30:44.927195
2019-05-26 05:30:44,927 [salt.state       :1813][INFO    ][12658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 05:30:44,997 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-26 05:30:45,110 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-26 05:30:45,344 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-26 05:30:45,429 [salt.state       :300 ][INFO    ][12658] {'new': 'Vlan untagged was updated'}
2019-05-26 05:30:45,429 [salt.state       :1951][INFO    ][12658] Completed state [vlan 0] at time 05:30:45.429744 duration_in_ms=502.549
2019-05-26 05:30:45,431 [salt.state       :1780][INFO    ][12658] Running state [192.168.11.0/24] at time 05:30:45.431167
2019-05-26 05:30:45,431 [salt.state       :1813][INFO    ][12658] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-26 05:30:45,626 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-05-26 05:30:45,627 [salt.loaded.ext.module.maasng:1235][WARNING ][12658] Ignoring parameter vlan:0
2019-05-26 05:30:45,705 [salt.state       :300 ][INFO    ][12658] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-26 05:30:45,706 [salt.state       :1951][INFO    ][12658] Completed state [192.168.11.0/24] at time 05:30:45.706020 duration_in_ms=274.852
2019-05-26 05:30:45,708 [salt.state       :1780][INFO    ][12658] Running state [maas_create_iprange_1] at time 05:30:45.707923
2019-05-26 05:30:45,708 [salt.state       :1813][INFO    ][12658] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-26 05:30:45,758 [salt.state       :300 ][INFO    ][12658] Iprange maas_create_iprange_1 already exist.
2019-05-26 05:30:45,758 [salt.state       :1951][INFO    ][12658] Completed state [maas_create_iprange_1] at time 05:30:45.758694 duration_in_ms=50.771
2019-05-26 05:30:45,759 [salt.state       :1780][INFO    ][12658] Running state [vlan 0] at time 05:30:45.759079
2019-05-26 05:30:45,759 [salt.state       :1813][INFO    ][12658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 05:30:45,799 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-26 05:30:45,889 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'4mr4qc', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-05-26 05:30:46,057 [salt.loaded.ext.module.maasng:945 ][INFO    ][12658] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'4mr4qc', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-26 05:30:46,141 [salt.state       :300 ][INFO    ][12658] {'new': 'Vlan untagged was updated'}
2019-05-26 05:30:46,142 [salt.state       :1951][INFO    ][12658] Completed state [vlan 0] at time 05:30:46.142094 duration_in_ms=383.014
2019-05-26 05:30:46,142 [salt.state       :1780][INFO    ][12658] Running state [opnfv] at time 05:30:46.142826
2019-05-26 05:30:46,143 [salt.state       :1813][INFO    ][12658] Executing state maasng.sshkey_present for [opnfv]
2019-05-26 05:30:46,195 [salt.loaded.ext.module.maasng:1903][INFO    ][12658] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-26 05:30:46,196 [salt.state       :300 ][INFO    ][12658] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-26 05:30:46,196 [salt.state       :1951][INFO    ][12658] Completed state [opnfv] at time 05:30:46.196670 duration_in_ms=53.843
2019-05-26 05:30:46,197 [salt.state       :1780][INFO    ][12658] Running state [maas.process_tags] at time 05:30:46.197533
2019-05-26 05:30:46,198 [salt.state       :1813][INFO    ][12658] Executing state module.run for [maas.process_tags]
2019-05-26 05:30:46,198 [salt.utils.decorators:613 ][WARNING ][12658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:46,243 [salt.loaded.ext.module.maas:92  ][INFO    ][12658] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-26 05:30:46,292 [salt.state       :300 ][INFO    ][12658] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-26 05:30:46,292 [salt.state       :1951][INFO    ][12658] Completed state [maas.process_tags] at time 05:30:46.292529 duration_in_ms=94.995
2019-05-26 05:30:46,296 [salt.minion      :1711][INFO    ][12658] Returning information for job: 20190526053018348460
2019-05-26 05:30:46,762 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053046750862
2019-05-26 05:30:46,779 [salt.minion      :1432][INFO    ][13143] Starting a new job with PID 13143
2019-05-26 05:30:50,471 [salt.state       :915 ][INFO    ][13143] Loading fresh modules for state activity
2019-05-26 05:30:50,561 [salt.state       :1780][INFO    ][13143] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:30:50.561400
2019-05-26 05:30:50,561 [salt.state       :1813][INFO    ][13143] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:30:50,563 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13143] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:30:51,971 [salt.state       :300 ][INFO    ][13143] {'pid': 13168, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:30:51,972 [salt.state       :1951][INFO    ][13143] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:30:51.971947 duration_in_ms=1410.547
2019-05-26 05:30:51,974 [salt.state       :1780][INFO    ][13143] Running state [maas.process_machines] at time 05:30:51.974354
2019-05-26 05:30:51,974 [salt.state       :1813][INFO    ][13143] Executing state module.run for [maas.process_machines]
2019-05-26 05:30:51,976 [salt.utils.decorators:613 ][WARNING ][13143] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:30:52,676 [salt.loaded.ext.module.maas:412 ][WARNING ][13143] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:30:52,676 [salt.loaded.ext.module.maas:92  ][INFO    ][13143] 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=msk4aw architecture=amd64/generic power_parameters_power_user=admin
2019-05-26 05:30:53,664 [salt.loaded.ext.module.maas:412 ][WARNING ][13143] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:30:53,665 [salt.loaded.ext.module.maas:92  ][INFO    ][13143] 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=cpmhen architecture=amd64/generic power_parameters_power_user=admin
2019-05-26 05:30:54,610 [salt.loaded.ext.module.maas:412 ][WARNING ][13143] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:30:54,611 [salt.loaded.ext.module.maas:92  ][INFO    ][13143] 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=cgkbns architecture=amd64/generic power_parameters_power_user=admin
2019-05-26 05:30:55,844 [salt.loaded.ext.module.maas:412 ][WARNING ][13143] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:30:55,845 [salt.loaded.ext.module.maas:92  ][INFO    ][13143] 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=hxw4da architecture=amd64/generic power_parameters_power_user=admin
2019-05-26 05:30:57,185 [salt.loaded.ext.module.maas:412 ][WARNING ][13143] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 05:30:57,186 [salt.loaded.ext.module.maas:92  ][INFO    ][13143] 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=7d38ta architecture=amd64/generic power_parameters_power_user=admin
2019-05-26 05:30:58,425 [salt.state       :300 ][INFO    ][13143] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-26 05:30:58,426 [salt.state       :1951][INFO    ][13143] Completed state [maas.process_machines] at time 05:30:58.426293 duration_in_ms=6451.938
2019-05-26 05:30:58,429 [salt.minion      :1711][INFO    ][13143] Returning information for job: 20190526053046750862
2019-05-26 05:31:30,825 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053130813331
2019-05-26 05:31:30,843 [salt.minion      :1432][INFO    ][13398] Starting a new job with PID 13398
2019-05-26 05:31:34,591 [salt.state       :915 ][INFO    ][13398] Loading fresh modules for state activity
2019-05-26 05:31:34,679 [salt.state       :1780][INFO    ][13398] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:34.679364
2019-05-26 05:31:34,679 [salt.state       :1813][INFO    ][13398] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:31:34,681 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13398] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:31:36,158 [salt.state       :300 ][INFO    ][13398] {'pid': 13405, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:31:36,159 [salt.state       :1951][INFO    ][13398] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:31:36.159232 duration_in_ms=1479.868
2019-05-26 05:31:36,162 [salt.state       :1780][INFO    ][13398] Running state [maas.wait_for_machine_status] at time 05:31:36.162449
2019-05-26 05:31:36,163 [salt.state       :1813][INFO    ][13398] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 05:31:36,163 [salt.utils.decorators:613 ][WARNING ][13398] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:31:38,135 [salt.loaded.ext.module.maas:993 ][INFO    ][13398] Machine cgkbns mark broken
2019-05-26 05:31:38,634 [salt.loaded.ext.module.maas:996 ][INFO    ][13398] Machine cgkbns mark fixed
2019-05-26 05:31:39,902 [salt.loaded.ext.module.maas:684 ][INFO    ][13398] deploymachines hwe_kernel=hwe-16.04 system_id=cgkbns distro_series=xenial
2019-05-26 05:31:44,010 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.16292405s left)
2019-05-26 05:31:45,925 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053145864787
2019-05-26 05:31:45,948 [salt.minion      :1432][INFO    ][13521] Starting a new job with PID 13521
2019-05-26 05:31:45,976 [salt.minion      :1711][INFO    ][13521] Returning information for job: 20190526053145864787
2019-05-26 05:32:15,971 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053215958720
2019-05-26 05:32:15,994 [salt.minion      :1432][INFO    ][13547] Starting a new job with PID 13547
2019-05-26 05:32:16,019 [salt.minion      :1711][INFO    ][13547] Returning information for job: 20190526053215958720
2019-05-26 05:32:16,939 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1459.23420405s left)
2019-05-26 05:32:46,053 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053246041258
2019-05-26 05:32:46,076 [salt.minion      :1432][INFO    ][13600] Starting a new job with PID 13600
2019-05-26 05:32:46,102 [salt.minion      :1711][INFO    ][13600] Returning information for job: 20190526053246041258
2019-05-26 05:32:50,282 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.89090014s left)
2019-05-26 05:33:16,103 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053316089075
2019-05-26 05:33:16,125 [salt.minion      :1432][INFO    ][13621] Starting a new job with PID 13621
2019-05-26 05:33:16,151 [salt.minion      :1711][INFO    ][13621] Returning information for job: 20190526053316089075
2019-05-26 05:33:23,317 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.856601s left)
2019-05-26 05:33:46,147 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053346133903
2019-05-26 05:33:46,170 [salt.minion      :1432][INFO    ][13769] Starting a new job with PID 13769
2019-05-26 05:33:46,195 [salt.minion      :1711][INFO    ][13769] Returning information for job: 20190526053346133903
2019-05-26 05:33:56,921 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.25237203s left)
2019-05-26 05:34:16,201 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053416188136
2019-05-26 05:34:16,224 [salt.minion      :1432][INFO    ][13795] Starting a new job with PID 13795
2019-05-26 05:34:16,248 [salt.minion      :1711][INFO    ][13795] Returning information for job: 20190526053416188136
2019-05-26 05:34:30,353 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.82061911s left)
2019-05-26 05:34:46,256 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053446243896
2019-05-26 05:34:46,279 [salt.minion      :1432][INFO    ][13959] Starting a new job with PID 13959
2019-05-26 05:34:46,306 [salt.minion      :1711][INFO    ][13959] Returning information for job: 20190526053446243896
2019-05-26 05:35:04,074 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.09934115s left)
2019-05-26 05:35:16,320 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053516307938
2019-05-26 05:35:16,343 [salt.minion      :1432][INFO    ][13984] Starting a new job with PID 13984
2019-05-26 05:35:16,369 [salt.minion      :1711][INFO    ][13984] Returning information for job: 20190526053516307938
2019-05-26 05:35:37,822 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.35084701s left)
2019-05-26 05:35:46,384 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053546371545
2019-05-26 05:35:46,405 [salt.minion      :1432][INFO    ][14063] Starting a new job with PID 14063
2019-05-26 05:35:46,430 [salt.minion      :1711][INFO    ][14063] Returning information for job: 20190526053546371545
2019-05-26 05:36:11,236 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1224.93763494s left)
2019-05-26 05:36:16,452 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053616439205
2019-05-26 05:36:16,475 [salt.minion      :1432][INFO    ][14083] Starting a new job with PID 14083
2019-05-26 05:36:16,502 [salt.minion      :1711][INFO    ][14083] Returning information for job: 20190526053616439205
2019-05-26 05:36:44,362 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.81098199s left)
2019-05-26 05:36:46,531 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053646519316
2019-05-26 05:36:46,553 [salt.minion      :1432][INFO    ][14243] Starting a new job with PID 14243
2019-05-26 05:36:46,581 [salt.minion      :1711][INFO    ][14243] Returning information for job: 20190526053646519316
2019-05-26 05:37:16,609 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053716597357
2019-05-26 05:37:16,633 [salt.minion      :1432][INFO    ][14266] Starting a new job with PID 14266
2019-05-26 05:37:16,657 [salt.minion      :1711][INFO    ][14266] Returning information for job: 20190526053716597357
2019-05-26 05:37:18,213 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1157.96034193s left)
2019-05-26 05:37:46,693 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053746681086
2019-05-26 05:37:46,715 [salt.minion      :1432][INFO    ][14386] Starting a new job with PID 14386
2019-05-26 05:37:46,740 [salt.minion      :1711][INFO    ][14386] Returning information for job: 20190526053746681086
2019-05-26 05:37:51,825 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.34878206s left)
2019-05-26 05:38:16,781 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053816768460
2019-05-26 05:38:16,804 [salt.minion      :1432][INFO    ][14406] Starting a new job with PID 14406
2019-05-26 05:38:16,830 [salt.minion      :1711][INFO    ][14406] Returning information for job: 20190526053816768460
2019-05-26 05:38:25,367 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1090.80640197s left)
2019-05-26 05:38:46,879 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053846867311
2019-05-26 05:38:46,902 [salt.minion      :1432][INFO    ][14477] Starting a new job with PID 14477
2019-05-26 05:38:46,929 [salt.minion      :1711][INFO    ][14477] Returning information for job: 20190526053846867311
2019-05-26 05:38:58,484 [salt.loaded.ext.module.maas:1023][INFO    ][13398] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1057.68949008s left)
2019-05-26 05:39:17,038 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526053917025104
2019-05-26 05:39:17,061 [salt.minion      :1432][INFO    ][14552] Starting a new job with PID 14552
2019-05-26 05:39:17,085 [salt.minion      :1711][INFO    ][14552] Returning information for job: 20190526053917025104
2019-05-26 05:39:31,680 [salt.state       :300 ][INFO    ][13398] {'ret': True}
2019-05-26 05:39:31,681 [salt.state       :1951][INFO    ][13398] Completed state [maas.wait_for_machine_status] at time 05:39:31.681010 duration_in_ms=475518.558
2019-05-26 05:39:31,684 [salt.minion      :1711][INFO    ][13398] Returning information for job: 20190526053130813331
2019-05-26 05:39:32,361 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053932348350
2019-05-26 05:39:32,384 [salt.minion      :1432][INFO    ][14582] Starting a new job with PID 14582
2019-05-26 05:39:36,079 [salt.state       :915 ][INFO    ][14582] Loading fresh modules for state activity
2019-05-26 05:39:36,219 [salt.state       :1780][INFO    ][14582] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:36.219257
2019-05-26 05:39:36,219 [salt.state       :1813][INFO    ][14582] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:39:36,221 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14582] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:39:37,700 [salt.state       :300 ][INFO    ][14582] {'pid': 14603, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:39:37,701 [salt.state       :1951][INFO    ][14582] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:37.701615 duration_in_ms=1482.358
2019-05-26 05:39:37,704 [salt.state       :1780][INFO    ][14582] Running state [maas_machines_storage_cmp002_lvm] at time 05:39:37.704777
2019-05-26 05:39:37,705 [salt.state       :1813][INFO    ][14582] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-26 05:39:38,424 [salt.state       :300 ][INFO    ][14582] Machine cmp002 is not in Ready state.
2019-05-26 05:39:38,424 [salt.state       :1951][INFO    ][14582] Completed state [maas_machines_storage_cmp002_lvm] at time 05:39:38.424880 duration_in_ms=720.101
2019-05-26 05:39:38,425 [salt.state       :1780][INFO    ][14582] Running state [maas_machines_storage_cmp001_lvm] at time 05:39:38.425529
2019-05-26 05:39:38,426 [salt.state       :1813][INFO    ][14582] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-26 05:39:39,171 [salt.state       :300 ][INFO    ][14582] Machine cmp001 is not in Ready state.
2019-05-26 05:39:39,171 [salt.state       :1951][INFO    ][14582] Completed state [maas_machines_storage_cmp001_lvm] at time 05:39:39.171760 duration_in_ms=746.23
2019-05-26 05:39:39,175 [salt.minion      :1711][INFO    ][14582] Returning information for job: 20190526053932348350
2019-05-26 05:39:39,806 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053939792339
2019-05-26 05:39:39,828 [salt.minion      :1432][INFO    ][14613] Starting a new job with PID 14613
2019-05-26 05:39:40,588 [salt.state       :915 ][INFO    ][14613] Loading fresh modules for state activity
2019-05-26 05:39:40,673 [salt.state       :1780][INFO    ][14613] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:40.673415
2019-05-26 05:39:40,673 [salt.state       :1813][INFO    ][14613] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:39:40,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14613] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:39:42,273 [salt.state       :300 ][INFO    ][14613] {'pid': 14620, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:39:42,273 [salt.state       :1951][INFO    ][14613] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:42.273585 duration_in_ms=1600.171
2019-05-26 05:39:42,274 [salt.state       :1780][INFO    ][14613] Running state [maas.deploy_machines] at time 05:39:42.274745
2019-05-26 05:39:42,274 [salt.state       :1813][INFO    ][14613] Executing state module.run for [maas.deploy_machines]
2019-05-26 05:39:42,275 [salt.utils.decorators:613 ][WARNING ][14613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:39:42,772 [salt.state       :300 ][INFO    ][14613] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-26 05:39:42,773 [salt.state       :1951][INFO    ][14613] Completed state [maas.deploy_machines] at time 05:39:42.772975 duration_in_ms=498.229
2019-05-26 05:39:42,774 [salt.minion      :1711][INFO    ][14613] Returning information for job: 20190526053939792339
2019-05-26 05:39:43,370 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command state.apply with jid 20190526053943354336
2019-05-26 05:39:43,392 [salt.minion      :1432][INFO    ][14773] Starting a new job with PID 14773
2019-05-26 05:39:44,149 [salt.state       :915 ][INFO    ][14773] Loading fresh modules for state activity
2019-05-26 05:39:44,244 [salt.state       :1780][INFO    ][14773] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:44.244122
2019-05-26 05:39:44,244 [salt.state       :1813][INFO    ][14773] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 05:39:44,246 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14773] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 05:39:45,722 [salt.state       :300 ][INFO    ][14773] {'pid': 14780, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 05:39:45,723 [salt.state       :1951][INFO    ][14773] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:39:45.723753 duration_in_ms=1479.63
2019-05-26 05:39:45,727 [salt.state       :1780][INFO    ][14773] Running state [maas.wait_for_machine_status] at time 05:39:45.727189
2019-05-26 05:39:45,727 [salt.state       :1813][INFO    ][14773] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 05:39:45,728 [salt.utils.decorators:613 ][WARNING ][14773] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 05:39:49,343 [salt.state       :300 ][INFO    ][14773] {'ret': True}
2019-05-26 05:39:49,343 [salt.state       :1951][INFO    ][14773] Completed state [maas.wait_for_machine_status] at time 05:39:49.343580 duration_in_ms=3616.391
2019-05-26 05:39:49,346 [salt.minion      :1711][INFO    ][14773] Returning information for job: 20190526053943354336
2019-05-26 06:09:58,499 [salt.utils.schedule:1377][INFO    ][6627] Running scheduled job: __mine_interval
2019-05-26 07:05:01,165 [salt.minion      :1308][INFO    ][6627] User sudo_ubuntu Executing command cp.push_dir with jid 20190526070501156099
2019-05-26 07:05:01,192 [salt.minion      :1432][INFO    ][20903] Starting a new job with PID 20903
