2019-07-03 20:07:17,248 [salt.utils.decorators:613 ][WARNING ][2309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:07:18,165 [salt.utils.decorators:613 ][WARNING ][2309] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:07:21,800 [salt.loaded.int.states.file:2298][WARNING ][2531] 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-07-03 20:07:46,712 [salt.state       :2022][WARNING ][2842] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-03 20:07:50,087 [salt.utils.decorators:613 ][WARNING ][2842] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:22:59,549 [salt.utils.decorators:613 ][WARNING ][2842] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:28:03,178 [salt.utils.decorators:613 ][WARNING ][2842] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:30:32,432 [salt.utils.decorators:613 ][WARNING ][2842] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:30:35,536 [salt.loaded.ext.module.maasng:1008][WARNING ][2842] Detected cidr:192.168.11.0/24 in fabric:fabric-3
2019-07-03 20:30:35,537 [salt.loaded.ext.module.maasng:1011][WARNING ][2842] Guessing, that fabric with current name:fabric-3
 should be renamed to:pxe_admin
2019-07-03 20:30:36,387 [salt.loaded.ext.module.maasng:1235][WARNING ][2842] Ignoring parameter vlan:0
2019-07-03 20:30:37,416 [salt.utils.decorators:613 ][WARNING ][2842] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:30:50,380 [salt.utils.decorators:613 ][WARNING ][36536] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:30:50,471 [salt.loaded.ext.module.maas:412 ][WARNING ][36536] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 20:30:51,989 [salt.loaded.ext.module.maas:412 ][WARNING ][36536] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 20:30:53,399 [salt.loaded.ext.module.maas:412 ][WARNING ][36536] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 20:30:54,848 [salt.loaded.ext.module.maas:412 ][WARNING ][36536] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 20:30:59,078 [salt.loaded.int.module.cmdmod:395 ][INFO    ][37088] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-03 20:30:59,122 [salt.loaded.int.module.cmdmod:395 ][INFO    ][37088] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-07-03 20:30:59,198 [salt.utils.parsers:1051][WARNING ][387] Minion received a SIGTERM. Exiting.
2019-07-03 20:31:00,839 [salt.cli.daemons :293 ][INFO    ][37143] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-07-03 20:31:00,958 [salt.cli.daemons :82  ][INFO    ][37143] Starting up the Salt Minion
2019-07-03 20:31:00,959 [salt.utils.event :1017][INFO    ][37143] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-07-03 20:31:02,184 [salt.minion      :976 ][INFO    ][37143] Creating minion process manager
2019-07-03 20:31:04,256 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][37143] Executing command ['date', '+%z'] in directory '/root'
2019-07-03 20:31:04,287 [salt.utils.schedule:568 ][INFO    ][37143] Updating job settings for scheduled job: __mine_interval
2019-07-03 20:31:04,289 [salt.minion      :1108][INFO    ][37143] Added mine.update to scheduler
2019-07-03 20:31:04,294 [salt.minion      :1975][INFO    ][37143] Minion is starting as user 'root'
2019-07-03 20:31:04,317 [salt.minion      :2336][INFO    ][37143] Minion is ready to receive requests!
2019-07-03 20:31:27,262 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703203127246845
2019-07-03 20:31:27,294 [salt.minion      :1432][INFO    ][37239] Starting a new job with PID 37239
2019-07-03 20:31:35,525 [salt.state       :915 ][INFO    ][37239] Loading fresh modules for state activity
2019-07-03 20:31:35,595 [salt.fileclient  :1219][INFO    ][37239] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-07-03 20:31:35,646 [salt.state       :1780][INFO    ][37239] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:31:35.646587
2019-07-03 20:31:35,646 [salt.state       :1813][INFO    ][37239] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 20:31:35,648 [salt.loaded.int.module.cmdmod:395 ][INFO    ][37239] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 20:31:37,434 [salt.state       :300 ][INFO    ][37239] {'pid': 37257, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 20:31:37,436 [salt.state       :1951][INFO    ][37239] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:31:37.435865 duration_in_ms=1789.278
2019-07-03 20:31:37,439 [salt.state       :1780][INFO    ][37239] Running state [maas.wait_for_machine_status] at time 20:31:37.439745
2019-07-03 20:31:37,440 [salt.state       :1813][INFO    ][37239] Executing state module.run for [maas.wait_for_machine_status]
2019-07-03 20:31:37,441 [salt.utils.decorators:613 ][WARNING ][37239] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:31:38,093 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.35728097s left)
2019-07-03 20:31:42,392 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203142376358
2019-07-03 20:31:42,420 [salt.minion      :1432][INFO    ][37269] Starting a new job with PID 37269
2019-07-03 20:31:42,443 [salt.minion      :1711][INFO    ][37269] Returning information for job: 20190703203142376358
2019-07-03 20:32:08,812 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.63882995s left)
2019-07-03 20:32:12,463 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203212450193
2019-07-03 20:32:12,492 [salt.minion      :1432][INFO    ][37309] Starting a new job with PID 37309
2019-07-03 20:32:12,516 [salt.minion      :1711][INFO    ][37309] Returning information for job: 20190703203212450193
2019-07-03 20:32:39,447 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1438.00307798s left)
2019-07-03 20:32:42,586 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203242569422
2019-07-03 20:32:42,617 [salt.minion      :1432][INFO    ][37343] Starting a new job with PID 37343
2019-07-03 20:32:42,637 [salt.minion      :1711][INFO    ][37343] Returning information for job: 20190703203242569422
2019-07-03 20:33:10,058 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1407.39306688s left)
2019-07-03 20:33:12,668 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203312651753
2019-07-03 20:33:12,697 [salt.minion      :1432][INFO    ][37387] Starting a new job with PID 37387
2019-07-03 20:33:12,724 [salt.minion      :1711][INFO    ][37387] Returning information for job: 20190703203312651753
2019-07-03 20:33:40,889 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1376.56159306s left)
2019-07-03 20:33:42,762 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203342746219
2019-07-03 20:33:42,791 [salt.minion      :1432][INFO    ][37444] Starting a new job with PID 37444
2019-07-03 20:33:42,813 [salt.minion      :1711][INFO    ][37444] Returning information for job: 20190703203342746219
2019-07-03 20:34:11,727 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1345.72382689s left)
2019-07-03 20:34:12,856 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203412847363
2019-07-03 20:34:12,875 [salt.minion      :1432][INFO    ][37542] Starting a new job with PID 37542
2019-07-03 20:34:12,898 [salt.minion      :1711][INFO    ][37542] Returning information for job: 20190703203412847363
2019-07-03 20:34:42,627 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1314.82310104s left)
2019-07-03 20:34:42,967 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203442953128
2019-07-03 20:34:42,989 [salt.minion      :1432][INFO    ][37648] Starting a new job with PID 37648
2019-07-03 20:34:43,012 [salt.minion      :1711][INFO    ][37648] Returning information for job: 20190703203442953128
2019-07-03 20:35:13,056 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203513045346
2019-07-03 20:35:13,075 [salt.minion      :1432][INFO    ][37923] Starting a new job with PID 37923
2019-07-03 20:35:13,098 [salt.minion      :1711][INFO    ][37923] Returning information for job: 20190703203513045346
2019-07-03 20:35:13,499 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1283.95112491s left)
2019-07-03 20:35:43,159 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203543146061
2019-07-03 20:35:43,186 [salt.minion      :1432][INFO    ][38013] Starting a new job with PID 38013
2019-07-03 20:35:43,208 [salt.minion      :1711][INFO    ][38013] Returning information for job: 20190703203543146061
2019-07-03 20:35:44,718 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1252.73309588s left)
2019-07-03 20:36:13,296 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203613288483
2019-07-03 20:36:13,318 [salt.minion      :1432][INFO    ][38172] Starting a new job with PID 38172
2019-07-03 20:36:13,343 [salt.minion      :1711][INFO    ][38172] Returning information for job: 20190703203613288483
2019-07-03 20:36:16,060 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1221.39029694s left)
2019-07-03 20:36:43,413 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203643404290
2019-07-03 20:36:43,439 [salt.minion      :1432][INFO    ][38307] Starting a new job with PID 38307
2019-07-03 20:36:43,459 [salt.minion      :1711][INFO    ][38307] Returning information for job: 20190703203643404290
2019-07-03 20:36:47,731 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1189.7198s left)
2019-07-03 20:37:13,542 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203713527290
2019-07-03 20:37:13,572 [salt.minion      :1432][INFO    ][38416] Starting a new job with PID 38416
2019-07-03 20:37:13,593 [salt.minion      :1711][INFO    ][38416] Returning information for job: 20190703203713527290
2019-07-03 20:37:19,423 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1158.02772903s left)
2019-07-03 20:37:43,691 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203743678768
2019-07-03 20:37:43,714 [salt.minion      :1432][INFO    ][38517] Starting a new job with PID 38517
2019-07-03 20:37:43,737 [salt.minion      :1711][INFO    ][38517] Returning information for job: 20190703203743678768
2019-07-03 20:37:52,056 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1125.39435792s left)
2019-07-03 20:38:13,845 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203813828124
2019-07-03 20:38:13,876 [salt.minion      :1432][INFO    ][38679] Starting a new job with PID 38679
2019-07-03 20:38:13,897 [salt.minion      :1711][INFO    ][38679] Returning information for job: 20190703203813828124
2019-07-03 20:38:23,884 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1093.56608009s left)
2019-07-03 20:38:43,973 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203843953341
2019-07-03 20:38:44,001 [salt.minion      :1432][INFO    ][38756] Starting a new job with PID 38756
2019-07-03 20:38:44,024 [salt.minion      :1711][INFO    ][38756] Returning information for job: 20190703203843953341
2019-07-03 20:38:55,729 [salt.loaded.ext.module.maas:1023][INFO    ][37239] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1061.72127295s left)
2019-07-03 20:39:14,121 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703203914106445
2019-07-03 20:39:14,152 [salt.minion      :1432][INFO    ][38851] Starting a new job with PID 38851
2019-07-03 20:39:14,176 [salt.minion      :1711][INFO    ][38851] Returning information for job: 20190703203914106445
2019-07-03 20:39:27,718 [salt.state       :300 ][INFO    ][37239] {'ret': True}
2019-07-03 20:39:27,719 [salt.state       :1951][INFO    ][37239] Completed state [maas.wait_for_machine_status] at time 20:39:27.718995 duration_in_ms=470279.248
2019-07-03 20:39:27,725 [salt.minion      :1711][INFO    ][37239] Returning information for job: 20190703203127246845
2019-07-03 20:39:28,315 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703203928302843
2019-07-03 20:39:28,344 [salt.minion      :1432][INFO    ][38881] Starting a new job with PID 38881
2019-07-03 20:39:36,416 [salt.state       :915 ][INFO    ][38881] Loading fresh modules for state activity
2019-07-03 20:39:36,477 [salt.fileclient  :1219][INFO    ][38881] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-07-03 20:39:36,580 [salt.state       :1780][INFO    ][38881] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:39:36.580170
2019-07-03 20:39:36,580 [salt.state       :1813][INFO    ][38881] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 20:39:36,582 [salt.loaded.int.module.cmdmod:395 ][INFO    ][38881] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 20:39:38,324 [salt.state       :300 ][INFO    ][38881] {'pid': 38901, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 20:39:38,325 [salt.state       :1951][INFO    ][38881] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:39:38.325070 duration_in_ms=1744.899
2019-07-03 20:39:38,332 [salt.state       :1780][INFO    ][38881] Running state [maas_machines_storage_cmp002_lvm] at time 20:39:38.332152
2019-07-03 20:39:38,332 [salt.state       :1813][INFO    ][38881] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-07-03 20:39:39,480 [salt.loaded.ext.module.maasng:610 ][INFO    ][38881] 4wpq8m
2019-07-03 20:39:39,481 [salt.loaded.ext.module.maasng:626 ][INFO    ][38881] sda
2019-07-03 20:39:39,973 [salt.loaded.ext.module.maasng:361 ][INFO    ][38881] 4wpq8m
2019-07-03 20:39:40,070 [salt.loaded.ext.module.maasng:367 ][INFO    ][38881] [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'0ec16369-dfd1-48c2-a12d-c0cd30d2a773', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4wpq8m', u'device_id': 1, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'79cdcc41-97f3-4407-b249-ff31ebfa0f2a', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/partition/1'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'4wpq8m', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/', u'type': u'physical', u'id': 1, u'name': u'sda'}, {u'size': 800097042432, u'model': None, u'block_size': 4096, u'uuid': u'93c78606-1e09-40d0-b40f-b55414a55095', u'tags': [], u'used_size': 800097042432, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'cd353c60-d92f-437c-a5b8-f88f448ce2f7', u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4wpq8m', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/3/', u'type': u'virtual', u'id': 3, u'name': u'vgroot-lvroot'}]
2019-07-03 20:39:40,071 [salt.loaded.ext.module.maasng:632 ][INFO    ][38881] vgroot
2019-07-03 20:39:40,071 [salt.loaded.ext.module.maasng:635 ][INFO    ][38881] lvroot
2019-07-03 20:39:40,071 [salt.loaded.ext.module.maasng:639 ][INFO    ][38881] 107374182400
2019-07-03 20:39:40,672 [salt.loaded.ext.module.maasng:645 ][INFO    ][38881] {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'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 40, u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.38', u'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/5/'}, u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'4wpq8m', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'blockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'def3c865-d98c-41f1-9abd-e722b1adbd7b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4wpq8m', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'430179a4-2649-4816-b820-624c9fe4c245', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'device_id': 1}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'4wpq8m', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'uuid': None}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/9/', 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'be16624a-88ca-4d65-8a57-fd85b905df4a', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4wpq8m', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'serial': None, u'uuid': u'f8a5de97-cc2c-4d9c-b22b-4a2cc4266b77'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'4wpq8m', u'id': 5}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'def3c865-d98c-41f1-9abd-e722b1adbd7b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4wpq8m', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'430179a4-2649-4816-b820-624c9fe4c245', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'device_id': 1}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'4wpq8m', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'uuid': None}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'def3c865-d98c-41f1-9abd-e722b1adbd7b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'4wpq8m', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'430179a4-2649-4816-b820-624c9fe4c245', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'device_id': 1}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'4wpq8m', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'uuid': None}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/blockdevices/9/', 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'be16624a-88ca-4d65-8a57-fd85b905df4a', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'4wpq8m', 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'block_size': 4096, u'type': u'virtual', u'id': 9, u'serial': None, u'uuid': u'f8a5de97-cc2c-4d9c-b22b-4a2cc4266b77'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.38', u'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/5/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 12, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:07:51', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/12/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 13, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:07:50', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/13/'}, {u'name': u'ens2f0', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 10, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:12:48', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/10/'}, {u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'id': 20, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 11, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.40'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:1c', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/11/'}, {u'name': u'ens2f1', u'links': [{u'id': 21, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 14, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:12:49', u'system_id': u'4wpq8m', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/4wpq8m/interfaces/14/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/4wpq8m/'}
2019-07-03 20:39:40,676 [salt.state       :300 ][INFO    ][38881] {'new': {'storage_layout': 'lvm'}}
2019-07-03 20:39:40,677 [salt.state       :1951][INFO    ][38881] Completed state [maas_machines_storage_cmp002_lvm] at time 20:39:40.677268 duration_in_ms=2345.113
2019-07-03 20:39:40,678 [salt.state       :1780][INFO    ][38881] Running state [maas_machines_storage_cmp001_lvm] at time 20:39:40.678278
2019-07-03 20:39:40,678 [salt.state       :1813][INFO    ][38881] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-07-03 20:39:41,660 [salt.loaded.ext.module.maasng:610 ][INFO    ][38881] fsmsmb
2019-07-03 20:39:41,661 [salt.loaded.ext.module.maasng:626 ][INFO    ][38881] sda
2019-07-03 20:39:42,139 [salt.loaded.ext.module.maasng:361 ][INFO    ][38881] fsmsmb
2019-07-03 20:39:42,236 [salt.loaded.ext.module.maasng:367 ][INFO    ][38881] [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'0a275dcd-8efd-4cb3-88ea-1888380d265d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsmsmb', u'device_id': 2, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'7db61ce2-c8d4-4790-ac9e-5f6c4d6cef15', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/partition/2'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'fsmsmb', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/', u'type': u'physical', u'id': 2, u'name': u'sda'}, {u'size': 800097042432, u'model': None, u'block_size': 4096, u'uuid': u'07764935-400f-4631-a764-5ba6c0d1b258', u'tags': [], u'used_size': 800097042432, u'partitions': [], u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'2962c9e8-18f4-4c0c-a1c2-57f63053ea7e', u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'fsmsmb', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/4/', u'type': u'virtual', u'id': 4, u'name': u'vgroot-lvroot'}]
2019-07-03 20:39:42,237 [salt.loaded.ext.module.maasng:632 ][INFO    ][38881] vgroot
2019-07-03 20:39:42,238 [salt.loaded.ext.module.maasng:635 ][INFO    ][38881] lvroot
2019-07-03 20:39:42,238 [salt.loaded.ext.module.maasng:639 ][INFO    ][38881] 107374182400
2019-07-03 20:39:42,836 [salt.loaded.ext.module.maasng:645 ][INFO    ][38881] {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'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 40, u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.39', u'id': 24, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 6, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/6/'}, u'fqdn': u'cmp001.maas', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'fsmsmb', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.39', u'192.168.11.42'], u'blockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'45559506-e9e5-44fa-a31a-9e35ba1e5f33', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsmsmb', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'dac39024-9e70-4612-87f8-ef4fafee46c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'device_id': 2}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'fsmsmb', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'uuid': None}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/10/', 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'f6b97c25-d075-45b8-9a39-0d92fdd4c88a', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'fsmsmb', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'serial': None, u'uuid': u'21294bf9-676d-4df3-a3ca-fe7bc0f70ed8'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'fsmsmb', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 6, u'boot_disk': {u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'45559506-e9e5-44fa-a31a-9e35ba1e5f33', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsmsmb', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'dac39024-9e70-4612-87f8-ef4fafee46c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'device_id': 2}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'fsmsmb', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'uuid': None}, u'current_testing_result_id': 7, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 800109715456, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'45559506-e9e5-44fa-a31a-9e35ba1e5f33', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'fsmsmb', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'dac39024-9e70-4612-87f8-ef4fafee46c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'device_id': 2}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'fsmsmb', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'uuid': None}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/blockdevices/10/', 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'f6b97c25-d075-45b8-9a39-0d92fdd4c88a', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'fsmsmb', 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'block_size': 4096, u'type': u'virtual', u'id': 10, u'serial': None, u'uuid': u'21294bf9-676d-4df3-a3ca-fe7bc0f70ed8'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.39', u'id': 24, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 6, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/6/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 16, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d4', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/16/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 17, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d5', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/17/'}, {u'name': u'ens2f0', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 15, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cc', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/15/'}, {u'name': u'ens2f1', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 18, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cd', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/18/'}, {u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'id': 27, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 19, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/subnets/5/'}, u'ip_address': u'192.168.11.42'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a4', u'system_id': u'fsmsmb', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/fsmsmb/interfaces/19/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/fsmsmb/'}
2019-07-03 20:39:42,839 [salt.state       :300 ][INFO    ][38881] {'new': {'storage_layout': 'lvm'}}
2019-07-03 20:39:42,839 [salt.state       :1951][INFO    ][38881] Completed state [maas_machines_storage_cmp001_lvm] at time 20:39:42.839774 duration_in_ms=2161.495
2019-07-03 20:39:42,846 [salt.minion      :1711][INFO    ][38881] Returning information for job: 20190703203928302843
2019-07-03 20:39:43,399 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703203943386714
2019-07-03 20:39:43,426 [salt.minion      :1432][INFO    ][38927] Starting a new job with PID 38927
2019-07-03 20:39:44,523 [salt.state       :915 ][INFO    ][38927] Loading fresh modules for state activity
2019-07-03 20:39:44,587 [salt.fileclient  :1219][INFO    ][38927] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-07-03 20:39:44,636 [salt.state       :1780][INFO    ][38927] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:39:44.636419
2019-07-03 20:39:44,636 [salt.state       :1813][INFO    ][38927] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 20:39:44,639 [salt.loaded.int.module.cmdmod:395 ][INFO    ][38927] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 20:39:46,408 [salt.state       :300 ][INFO    ][38927] {'pid': 38934, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 20:39:46,409 [salt.state       :1951][INFO    ][38927] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:39:46.409827 duration_in_ms=1773.408
2019-07-03 20:39:46,412 [salt.state       :1780][INFO    ][38927] Running state [maas.deploy_machines] at time 20:39:46.412824
2019-07-03 20:39:46,413 [salt.state       :1813][INFO    ][38927] Executing state module.run for [maas.deploy_machines]
2019-07-03 20:39:46,415 [salt.utils.decorators:613 ][WARNING ][38927] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:39:46,907 [salt.loaded.ext.module.maas:684 ][INFO    ][38927] deploymachines hwe_kernel=hwe-16.04 system_id=dschpq distro_series=xenial
2019-07-03 20:39:49,437 [salt.loaded.ext.module.maas:684 ][INFO    ][38927] deploymachines hwe_kernel=hwe-16.04 system_id=4wpq8m distro_series=xenial
2019-07-03 20:39:52,188 [salt.loaded.ext.module.maas:684 ][INFO    ][38927] deploymachines hwe_kernel=hwe-16.04 system_id=fsmsmb distro_series=xenial
2019-07-03 20:39:54,752 [salt.loaded.ext.module.maas:684 ][INFO    ][38927] deploymachines hwe_kernel=hwe-16.04 system_id=rg86q3 distro_series=xenial
2019-07-03 20:39:57,342 [salt.state       :300 ][INFO    ][38927] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-07-03 20:39:57,343 [salt.state       :1951][INFO    ][38927] Completed state [maas.deploy_machines] at time 20:39:57.343038 duration_in_ms=10930.214
2019-07-03 20:39:57,347 [salt.minion      :1711][INFO    ][38927] Returning information for job: 20190703203943386714
2019-07-03 20:39:57,922 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703203957905291
2019-07-03 20:39:57,942 [salt.minion      :1432][INFO    ][39170] Starting a new job with PID 39170
2019-07-03 20:40:06,185 [salt.state       :915 ][INFO    ][39170] Loading fresh modules for state activity
2019-07-03 20:40:06,251 [salt.fileclient  :1219][INFO    ][39170] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-07-03 20:40:06,302 [salt.state       :1780][INFO    ][39170] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:40:06.302882
2019-07-03 20:40:06,303 [salt.state       :1813][INFO    ][39170] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 20:40:06,304 [salt.loaded.int.module.cmdmod:395 ][INFO    ][39170] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 20:40:08,129 [salt.state       :300 ][INFO    ][39170] {'pid': 39189, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 20:40:08,131 [salt.state       :1951][INFO    ][39170] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:40:08.131311 duration_in_ms=1828.429
2019-07-03 20:40:08,134 [salt.state       :1780][INFO    ][39170] Running state [maas.wait_for_machine_status] at time 20:40:08.134474
2019-07-03 20:40:08,135 [salt.state       :1813][INFO    ][39170] Executing state module.run for [maas.wait_for_machine_status]
2019-07-03 20:40:08,135 [salt.utils.decorators:613 ][WARNING ][39170] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 20:40:10,099 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2248.04669905s left)
2019-07-03 20:40:13,044 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204013033006
2019-07-03 20:40:13,067 [salt.minion      :1432][INFO    ][39199] Starting a new job with PID 39199
2019-07-03 20:40:13,088 [salt.minion      :1711][INFO    ][39199] Returning information for job: 20190703204013033006
2019-07-03 20:40:42,104 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2216.04162097s left)
2019-07-03 20:40:43,111 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204043101409
2019-07-03 20:40:43,133 [salt.minion      :1432][INFO    ][39241] Starting a new job with PID 39241
2019-07-03 20:40:43,157 [salt.minion      :1711][INFO    ][39241] Returning information for job: 20190703204043101409
2019-07-03 20:41:13,205 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204113187459
2019-07-03 20:41:13,231 [salt.minion      :1432][INFO    ][39283] Starting a new job with PID 39283
2019-07-03 20:41:13,254 [salt.minion      :1711][INFO    ][39283] Returning information for job: 20190703204113187459
2019-07-03 20:41:14,279 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2183.86703587s left)
2019-07-03 20:41:43,296 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204143280445
2019-07-03 20:41:43,328 [salt.minion      :1432][INFO    ][39312] Starting a new job with PID 39312
2019-07-03 20:41:43,350 [salt.minion      :1711][INFO    ][39312] Returning information for job: 20190703204143280445
2019-07-03 20:41:46,188 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2151.9575069s left)
2019-07-03 20:42:13,385 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204213363697
2019-07-03 20:42:13,421 [salt.minion      :1432][INFO    ][39353] Starting a new job with PID 39353
2019-07-03 20:42:13,444 [salt.minion      :1711][INFO    ][39353] Returning information for job: 20190703204213363697
2019-07-03 20:42:18,151 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2119.99440002s left)
2019-07-03 20:42:43,481 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204243456332
2019-07-03 20:42:43,509 [salt.minion      :1432][INFO    ][39403] Starting a new job with PID 39403
2019-07-03 20:42:43,530 [salt.minion      :1711][INFO    ][39403] Returning information for job: 20190703204243456332
2019-07-03 20:42:50,207 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2087.93886995s left)
2019-07-03 20:43:13,567 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204313550447
2019-07-03 20:43:13,595 [salt.minion      :1432][INFO    ][39496] Starting a new job with PID 39496
2019-07-03 20:43:13,618 [salt.minion      :1711][INFO    ][39496] Returning information for job: 20190703204313550447
2019-07-03 20:43:22,506 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2055.63961291s left)
2019-07-03 20:43:43,680 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204343657648
2019-07-03 20:43:43,704 [salt.minion      :1432][INFO    ][39588] Starting a new job with PID 39588
2019-07-03 20:43:43,727 [salt.minion      :1711][INFO    ][39588] Returning information for job: 20190703204343657648
2019-07-03 20:43:54,823 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2023.32253909s left)
2019-07-03 20:44:13,776 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204413768910
2019-07-03 20:44:13,798 [salt.minion      :1432][INFO    ][39847] Starting a new job with PID 39847
2019-07-03 20:44:13,819 [salt.minion      :1711][INFO    ][39847] Returning information for job: 20190703204413768910
2019-07-03 20:44:26,958 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1991.18779707s left)
2019-07-03 20:44:43,878 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204443862339
2019-07-03 20:44:43,907 [salt.minion      :1432][INFO    ][39971] Starting a new job with PID 39971
2019-07-03 20:44:43,931 [salt.minion      :1711][INFO    ][39971] Returning information for job: 20190703204443862339
2019-07-03 20:44:59,423 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1958.72300792s left)
2019-07-03 20:45:13,998 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204513990183
2019-07-03 20:45:14,024 [salt.minion      :1432][INFO    ][40148] Starting a new job with PID 40148
2019-07-03 20:45:14,047 [salt.minion      :1711][INFO    ][40148] Returning information for job: 20190703204513990183
2019-07-03 20:45:31,456 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1926.68955398s left)
2019-07-03 20:45:44,120 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204544106598
2019-07-03 20:45:44,149 [salt.minion      :1432][INFO    ][40269] Starting a new job with PID 40269
2019-07-03 20:45:44,178 [salt.minion      :1711][INFO    ][40269] Returning information for job: 20190703204544106598
2019-07-03 20:46:03,500 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1894.64528608s left)
2019-07-03 20:46:14,285 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204614267853
2019-07-03 20:46:14,312 [salt.minion      :1432][INFO    ][40561] Starting a new job with PID 40561
2019-07-03 20:46:14,336 [salt.minion      :1711][INFO    ][40561] Returning information for job: 20190703204614267853
2019-07-03 20:46:35,621 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1862.524755s left)
2019-07-03 20:46:44,432 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204644416095
2019-07-03 20:46:44,462 [salt.minion      :1432][INFO    ][40661] Starting a new job with PID 40661
2019-07-03 20:46:44,489 [salt.minion      :1711][INFO    ][40661] Returning information for job: 20190703204644416095
2019-07-03 20:47:07,773 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1830.37216401s left)
2019-07-03 20:47:14,608 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204714595825
2019-07-03 20:47:14,627 [salt.minion      :1432][INFO    ][40909] Starting a new job with PID 40909
2019-07-03 20:47:14,650 [salt.minion      :1711][INFO    ][40909] Returning information for job: 20190703204714595825
2019-07-03 20:47:39,911 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1798.23470688s left)
2019-07-03 20:47:44,752 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204744736899
2019-07-03 20:47:44,777 [salt.minion      :1432][INFO    ][41148] Starting a new job with PID 41148
2019-07-03 20:47:44,800 [salt.minion      :1711][INFO    ][41148] Returning information for job: 20190703204744736899
2019-07-03 20:48:12,065 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1766.08103609s left)
2019-07-03 20:48:14,925 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204814907331
2019-07-03 20:48:14,959 [salt.minion      :1432][INFO    ][41305] Starting a new job with PID 41305
2019-07-03 20:48:14,981 [salt.minion      :1711][INFO    ][41305] Returning information for job: 20190703204814907331
2019-07-03 20:48:43,991 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1734.15473795s left)
2019-07-03 20:48:45,072 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204845059391
2019-07-03 20:48:45,105 [salt.minion      :1432][INFO    ][41358] Starting a new job with PID 41358
2019-07-03 20:48:45,130 [salt.minion      :1711][INFO    ][41358] Returning information for job: 20190703204845059391
2019-07-03 20:49:15,260 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204915248643
2019-07-03 20:49:15,283 [salt.minion      :1432][INFO    ][41421] Starting a new job with PID 41421
2019-07-03 20:49:15,304 [salt.minion      :1711][INFO    ][41421] Returning information for job: 20190703204915248643
2019-07-03 20:49:15,991 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1702.15493894s left)
2019-07-03 20:49:45,456 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703204945439218
2019-07-03 20:49:45,486 [salt.minion      :1432][INFO    ][41477] Starting a new job with PID 41477
2019-07-03 20:49:45,512 [salt.minion      :1711][INFO    ][41477] Returning information for job: 20190703204945439218
2019-07-03 20:49:47,986 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1670.15928388s left)
2019-07-03 20:50:15,548 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205015533622
2019-07-03 20:50:15,576 [salt.minion      :1432][INFO    ][41652] Starting a new job with PID 41652
2019-07-03 20:50:15,604 [salt.minion      :1711][INFO    ][41652] Returning information for job: 20190703205015533622
2019-07-03 20:50:20,288 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1637.85713387s left)
2019-07-03 20:50:45,721 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205045706759
2019-07-03 20:50:45,750 [salt.minion      :1432][INFO    ][41714] Starting a new job with PID 41714
2019-07-03 20:50:45,780 [salt.minion      :1711][INFO    ][41714] Returning information for job: 20190703205045706759
2019-07-03 20:50:52,804 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1605.34133005s left)
2019-07-03 20:51:15,918 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205115903172
2019-07-03 20:51:15,951 [salt.minion      :1432][INFO    ][41817] Starting a new job with PID 41817
2019-07-03 20:51:15,976 [salt.minion      :1711][INFO    ][41817] Returning information for job: 20190703205115903172
2019-07-03 20:51:25,035 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1573.11011791s left)
2019-07-03 20:51:46,111 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205146095996
2019-07-03 20:51:46,139 [salt.minion      :1432][INFO    ][41850] Starting a new job with PID 41850
2019-07-03 20:51:46,160 [salt.minion      :1711][INFO    ][41850] Returning information for job: 20190703205146095996
2019-07-03 20:51:57,012 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1541.13399196s left)
2019-07-03 20:52:16,237 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205216221436
2019-07-03 20:52:16,267 [salt.minion      :1432][INFO    ][41928] Starting a new job with PID 41928
2019-07-03 20:52:16,289 [salt.minion      :1711][INFO    ][41928] Returning information for job: 20190703205216221436
2019-07-03 20:52:29,196 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1508.94979787s left)
2019-07-03 20:52:46,444 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205246431447
2019-07-03 20:52:46,473 [salt.minion      :1432][INFO    ][41994] Starting a new job with PID 41994
2019-07-03 20:52:46,511 [salt.minion      :1711][INFO    ][41994] Returning information for job: 20190703205246431447
2019-07-03 20:53:01,198 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1476.9480629s left)
2019-07-03 20:53:16,471 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205316455823
2019-07-03 20:53:16,499 [salt.minion      :1432][INFO    ][42131] Starting a new job with PID 42131
2019-07-03 20:53:16,528 [salt.minion      :1711][INFO    ][42131] Returning information for job: 20190703205316455823
2019-07-03 20:53:33,262 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1444.883816s left)
2019-07-03 20:53:46,697 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205346686113
2019-07-03 20:53:46,728 [salt.minion      :1432][INFO    ][42181] Starting a new job with PID 42181
2019-07-03 20:53:46,760 [salt.minion      :1711][INFO    ][42181] Returning information for job: 20190703205346686113
2019-07-03 20:54:05,272 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1412.87387991s left)
2019-07-03 20:54:16,732 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205416713370
2019-07-03 20:54:16,761 [salt.minion      :1432][INFO    ][42222] Starting a new job with PID 42222
2019-07-03 20:54:16,795 [salt.minion      :1711][INFO    ][42222] Returning information for job: 20190703205416713370
2019-07-03 20:54:37,329 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1380.81640291s left)
2019-07-03 20:54:46,788 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205446775381
2019-07-03 20:54:46,817 [salt.minion      :1432][INFO    ][42259] Starting a new job with PID 42259
2019-07-03 20:54:46,848 [salt.minion      :1711][INFO    ][42259] Returning information for job: 20190703205446775381
2019-07-03 20:55:09,417 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1348.72901487s left)
2019-07-03 20:55:16,827 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205516812296
2019-07-03 20:55:16,855 [salt.minion      :1432][INFO    ][42306] Starting a new job with PID 42306
2019-07-03 20:55:16,887 [salt.minion      :1711][INFO    ][42306] Returning information for job: 20190703205516812296
2019-07-03 20:55:41,337 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1316.80826306s left)
2019-07-03 20:55:46,913 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205546899128
2019-07-03 20:55:46,944 [salt.minion      :1432][INFO    ][42341] Starting a new job with PID 42341
2019-07-03 20:55:46,974 [salt.minion      :1711][INFO    ][42341] Returning information for job: 20190703205546899128
2019-07-03 20:56:13,272 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1284.87353086s left)
2019-07-03 20:56:16,997 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205616980570
2019-07-03 20:56:17,026 [salt.minion      :1432][INFO    ][42385] Starting a new job with PID 42385
2019-07-03 20:56:17,058 [salt.minion      :1711][INFO    ][42385] Returning information for job: 20190703205616980570
2019-07-03 20:56:45,174 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1252.97184801s left)
2019-07-03 20:56:47,108 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205647096866
2019-07-03 20:56:47,135 [salt.minion      :1432][INFO    ][42418] Starting a new job with PID 42418
2019-07-03 20:56:47,169 [salt.minion      :1711][INFO    ][42418] Returning information for job: 20190703205647096866
2019-07-03 20:57:17,037 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1221.10866809s left)
2019-07-03 20:57:17,221 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205717207040
2019-07-03 20:57:17,242 [salt.minion      :1432][INFO    ][42464] Starting a new job with PID 42464
2019-07-03 20:57:17,269 [salt.minion      :1711][INFO    ][42464] Returning information for job: 20190703205717207040
2019-07-03 20:57:47,347 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205747331959
2019-07-03 20:57:47,372 [salt.minion      :1432][INFO    ][42506] Starting a new job with PID 42506
2019-07-03 20:57:47,400 [salt.minion      :1711][INFO    ][42506] Returning information for job: 20190703205747331959
2019-07-03 20:57:48,956 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1189.18914509s left)
2019-07-03 20:58:17,468 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205817457029
2019-07-03 20:58:17,492 [salt.minion      :1432][INFO    ][42554] Starting a new job with PID 42554
2019-07-03 20:58:17,524 [salt.minion      :1711][INFO    ][42554] Returning information for job: 20190703205817457029
2019-07-03 20:58:21,085 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1157.06097102s left)
2019-07-03 20:58:47,615 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205847599305
2019-07-03 20:58:47,645 [salt.minion      :1432][INFO    ][42587] Starting a new job with PID 42587
2019-07-03 20:58:47,676 [salt.minion      :1711][INFO    ][42587] Returning information for job: 20190703205847599305
2019-07-03 20:58:53,172 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1124.97386408s left)
2019-07-03 20:59:17,785 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205917768832
2019-07-03 20:59:17,813 [salt.minion      :1432][INFO    ][42633] Starting a new job with PID 42633
2019-07-03 20:59:17,849 [salt.minion      :1711][INFO    ][42633] Returning information for job: 20190703205917768832
2019-07-03 20:59:25,159 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1092.98617697s left)
2019-07-03 20:59:47,940 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703205947924041
2019-07-03 20:59:47,971 [salt.minion      :1432][INFO    ][42666] Starting a new job with PID 42666
2019-07-03 20:59:48,000 [salt.minion      :1711][INFO    ][42666] Returning information for job: 20190703205947924041
2019-07-03 20:59:57,283 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1060.86243391s left)
2019-07-03 21:00:18,127 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210018111437
2019-07-03 21:00:18,155 [salt.minion      :1432][INFO    ][42714] Starting a new job with PID 42714
2019-07-03 21:00:18,187 [salt.minion      :1711][INFO    ][42714] Returning information for job: 20190703210018111437
2019-07-03 21:00:28,956 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1029.18933296s left)
2019-07-03 21:00:48,304 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210048291138
2019-07-03 21:00:48,331 [salt.minion      :1432][INFO    ][42746] Starting a new job with PID 42746
2019-07-03 21:00:48,361 [salt.minion      :1711][INFO    ][42746] Returning information for job: 20190703210048291138
2019-07-03 21:01:00,843 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (997.302222967s left)
2019-07-03 21:01:18,526 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210118510222
2019-07-03 21:01:18,553 [salt.minion      :1432][INFO    ][42786] Starting a new job with PID 42786
2019-07-03 21:01:18,589 [salt.minion      :1711][INFO    ][42786] Returning information for job: 20190703210118510222
2019-07-03 21:01:32,665 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (965.48041296s left)
2019-07-03 21:01:48,752 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210148736657
2019-07-03 21:01:48,784 [salt.minion      :1432][INFO    ][42819] Starting a new job with PID 42819
2019-07-03 21:01:48,814 [salt.minion      :1711][INFO    ][42819] Returning information for job: 20190703210148736657
2019-07-03 21:02:04,572 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (933.573636055s left)
2019-07-03 21:02:18,772 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210218758543
2019-07-03 21:02:18,797 [salt.minion      :1432][INFO    ][42862] Starting a new job with PID 42862
2019-07-03 21:02:18,828 [salt.minion      :1711][INFO    ][42862] Returning information for job: 20190703210218758543
2019-07-03 21:02:36,462 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (901.683398008s left)
2019-07-03 21:02:48,833 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210248816830
2019-07-03 21:02:48,862 [salt.minion      :1432][INFO    ][42896] Starting a new job with PID 42896
2019-07-03 21:02:48,892 [salt.minion      :1711][INFO    ][42896] Returning information for job: 20190703210248816830
2019-07-03 21:03:08,481 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (869.664821863s left)
2019-07-03 21:03:18,900 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210318884262
2019-07-03 21:03:18,931 [salt.minion      :1432][INFO    ][42939] Starting a new job with PID 42939
2019-07-03 21:03:18,963 [salt.minion      :1711][INFO    ][42939] Returning information for job: 20190703210318884262
2019-07-03 21:03:40,438 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (837.707334995s left)
2019-07-03 21:03:48,968 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210348957578
2019-07-03 21:03:48,994 [salt.minion      :1432][INFO    ][42971] Starting a new job with PID 42971
2019-07-03 21:03:49,025 [salt.minion      :1711][INFO    ][42971] Returning information for job: 20190703210348957578
2019-07-03 21:04:12,491 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (805.654058933s left)
2019-07-03 21:04:19,075 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210419061515
2019-07-03 21:04:19,109 [salt.minion      :1432][INFO    ][43019] Starting a new job with PID 43019
2019-07-03 21:04:19,147 [salt.minion      :1711][INFO    ][43019] Returning information for job: 20190703210419061515
2019-07-03 21:04:44,347 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (773.798198938s left)
2019-07-03 21:04:49,195 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210449187389
2019-07-03 21:04:49,221 [salt.minion      :1432][INFO    ][43050] Starting a new job with PID 43050
2019-07-03 21:04:49,251 [salt.minion      :1711][INFO    ][43050] Returning information for job: 20190703210449187389
2019-07-03 21:05:16,271 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (741.874527931s left)
2019-07-03 21:05:19,315 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210519298634
2019-07-03 21:05:19,344 [salt.minion      :1432][INFO    ][43098] Starting a new job with PID 43098
2019-07-03 21:05:19,381 [salt.minion      :1711][INFO    ][43098] Returning information for job: 20190703210519298634
2019-07-03 21:05:48,260 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (709.88568306s left)
2019-07-03 21:05:49,500 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210549490784
2019-07-03 21:05:49,525 [salt.minion      :1432][INFO    ][43130] Starting a new job with PID 43130
2019-07-03 21:05:49,556 [salt.minion      :1711][INFO    ][43130] Returning information for job: 20190703210549490784
2019-07-03 21:06:19,660 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210619647986
2019-07-03 21:06:19,680 [salt.minion      :1432][INFO    ][43176] Starting a new job with PID 43176
2019-07-03 21:06:19,723 [salt.minion      :1711][INFO    ][43176] Returning information for job: 20190703210619647986
2019-07-03 21:06:20,235 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (677.91009593s left)
2019-07-03 21:06:49,858 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210649843086
2019-07-03 21:06:49,888 [salt.minion      :1432][INFO    ][43203] Starting a new job with PID 43203
2019-07-03 21:06:49,930 [salt.minion      :1711][INFO    ][43203] Returning information for job: 20190703210649843086
2019-07-03 21:06:52,421 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (645.724502087s left)
2019-07-03 21:07:20,083 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210720067630
2019-07-03 21:07:20,111 [salt.minion      :1432][INFO    ][43252] Starting a new job with PID 43252
2019-07-03 21:07:20,145 [salt.minion      :1711][INFO    ][43252] Returning information for job: 20190703210720067630
2019-07-03 21:07:24,443 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (613.703043938s left)
2019-07-03 21:07:50,131 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210750118003
2019-07-03 21:07:50,159 [salt.minion      :1432][INFO    ][43418] Starting a new job with PID 43418
2019-07-03 21:07:50,192 [salt.minion      :1711][INFO    ][43418] Returning information for job: 20190703210750118003
2019-07-03 21:07:56,410 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (581.735109091s left)
2019-07-03 21:08:20,214 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210820198599
2019-07-03 21:08:20,242 [salt.minion      :1432][INFO    ][43615] Starting a new job with PID 43615
2019-07-03 21:08:20,280 [salt.minion      :1711][INFO    ][43615] Returning information for job: 20190703210820198599
2019-07-03 21:08:28,315 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (549.831009865s left)
2019-07-03 21:08:50,340 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210850325235
2019-07-03 21:08:50,370 [salt.minion      :1432][INFO    ][43645] Starting a new job with PID 43645
2019-07-03 21:08:50,400 [salt.minion      :1711][INFO    ][43645] Returning information for job: 20190703210850325235
2019-07-03 21:09:00,341 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (517.804847956s left)
2019-07-03 21:09:20,397 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210920379977
2019-07-03 21:09:20,424 [salt.minion      :1432][INFO    ][43692] Starting a new job with PID 43692
2019-07-03 21:09:20,455 [salt.minion      :1711][INFO    ][43692] Returning information for job: 20190703210920379977
2019-07-03 21:09:32,244 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (485.901839972s left)
2019-07-03 21:09:50,529 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703210950516628
2019-07-03 21:09:50,555 [salt.minion      :1432][INFO    ][43726] Starting a new job with PID 43726
2019-07-03 21:09:50,586 [salt.minion      :1711][INFO    ][43726] Returning information for job: 20190703210950516628
2019-07-03 21:10:04,328 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (453.817486048s left)
2019-07-03 21:10:20,601 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211020593578
2019-07-03 21:10:20,623 [salt.minion      :1432][INFO    ][43769] Starting a new job with PID 43769
2019-07-03 21:10:20,656 [salt.minion      :1711][INFO    ][43769] Returning information for job: 20190703211020593578
2019-07-03 21:10:36,207 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (421.938443899s left)
2019-07-03 21:10:50,748 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211050732057
2019-07-03 21:10:50,777 [salt.minion      :1432][INFO    ][43804] Starting a new job with PID 43804
2019-07-03 21:10:50,808 [salt.minion      :1711][INFO    ][43804] Returning information for job: 20190703211050732057
2019-07-03 21:11:08,252 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (389.893367052s left)
2019-07-03 21:11:20,956 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211120940060
2019-07-03 21:11:20,986 [salt.minion      :1432][INFO    ][43842] Starting a new job with PID 43842
2019-07-03 21:11:21,019 [salt.minion      :1711][INFO    ][43842] Returning information for job: 20190703211120940060
2019-07-03 21:11:40,314 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (357.831670046s left)
2019-07-03 21:11:51,137 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211151125558
2019-07-03 21:11:51,164 [salt.minion      :1432][INFO    ][43879] Starting a new job with PID 43879
2019-07-03 21:11:51,199 [salt.minion      :1711][INFO    ][43879] Returning information for job: 20190703211151125558
2019-07-03 21:12:12,165 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (325.980803967s left)
2019-07-03 21:12:21,356 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211221345413
2019-07-03 21:12:21,384 [salt.minion      :1432][INFO    ][43917] Starting a new job with PID 43917
2019-07-03 21:12:21,418 [salt.minion      :1711][INFO    ][43917] Returning information for job: 20190703211221345413
2019-07-03 21:12:44,122 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (294.023113966s left)
2019-07-03 21:12:51,552 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211251540345
2019-07-03 21:12:51,576 [salt.minion      :1432][INFO    ][43958] Starting a new job with PID 43958
2019-07-03 21:12:51,624 [salt.minion      :1711][INFO    ][43958] Returning information for job: 20190703211251540345
2019-07-03 21:13:16,019 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (262.126942873s left)
2019-07-03 21:13:21,632 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211321619341
2019-07-03 21:13:21,658 [salt.minion      :1432][INFO    ][43993] Starting a new job with PID 43993
2019-07-03 21:13:21,689 [salt.minion      :1711][INFO    ][43993] Returning information for job: 20190703211321619341
2019-07-03 21:13:48,045 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (230.10059309s left)
2019-07-03 21:13:51,703 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211351688821
2019-07-03 21:13:51,730 [salt.minion      :1432][INFO    ][44045] Starting a new job with PID 44045
2019-07-03 21:13:51,762 [salt.minion      :1711][INFO    ][44045] Returning information for job: 20190703211351688821
2019-07-03 21:14:20,060 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (198.085174084s left)
2019-07-03 21:14:21,799 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211421782484
2019-07-03 21:14:21,825 [salt.minion      :1432][INFO    ][44073] Starting a new job with PID 44073
2019-07-03 21:14:21,859 [salt.minion      :1711][INFO    ][44073] Returning information for job: 20190703211421782484
2019-07-03 21:14:51,929 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211451919356
2019-07-03 21:14:51,954 [salt.minion      :1432][INFO    ][44122] Starting a new job with PID 44122
2019-07-03 21:14:51,985 [salt.minion      :1711][INFO    ][44122] Returning information for job: 20190703211451919356
2019-07-03 21:14:52,100 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (166.045713902s left)
2019-07-03 21:15:22,096 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211522086628
2019-07-03 21:15:22,124 [salt.minion      :1432][INFO    ][44146] Starting a new job with PID 44146
2019-07-03 21:15:22,158 [salt.minion      :1711][INFO    ][44146] Returning information for job: 20190703211522086628
2019-07-03 21:15:23,970 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (134.175096035s left)
2019-07-03 21:15:52,168 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211552152066
2019-07-03 21:15:52,193 [salt.minion      :1432][INFO    ][44194] Starting a new job with PID 44194
2019-07-03 21:15:52,222 [salt.minion      :1711][INFO    ][44194] Returning information for job: 20190703211552152066
2019-07-03 21:15:55,986 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (102.160002947s left)
2019-07-03 21:16:22,326 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211622312416
2019-07-03 21:16:22,353 [salt.minion      :1432][INFO    ][44223] Starting a new job with PID 44223
2019-07-03 21:16:22,384 [salt.minion      :1711][INFO    ][44223] Returning information for job: 20190703211622312416
2019-07-03 21:16:27,880 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (70.2653360367s left)
2019-07-03 21:16:52,450 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211652443204
2019-07-03 21:16:52,472 [salt.minion      :1432][INFO    ][44271] Starting a new job with PID 44271
2019-07-03 21:16:52,503 [salt.minion      :1711][INFO    ][44271] Returning information for job: 20190703211652443204
2019-07-03 21:16:59,842 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (38.3036868572s left)
2019-07-03 21:17:22,641 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211722621388
2019-07-03 21:17:22,667 [salt.minion      :1432][INFO    ][44303] Starting a new job with PID 44303
2019-07-03 21:17:22,703 [salt.minion      :1711][INFO    ][44303] Returning information for job: 20190703211722621388
2019-07-03 21:17:31,760 [salt.loaded.ext.module.maas:1023][INFO    ][39170] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (6.38565087318s left)
2019-07-03 21:17:52,680 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211752664620
2019-07-03 21:17:52,708 [salt.minion      :1432][INFO    ][44366] Starting a new job with PID 44366
2019-07-03 21:17:52,737 [salt.minion      :1711][INFO    ][44366] Returning information for job: 20190703211752664620
2019-07-03 21:18:03,705 [salt.state       :302 ][ERROR   ][39170] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['gtw01']not in Deployed state
2019-07-03 21:18:03,706 [salt.state       :1951][INFO    ][39170] Completed state [maas.wait_for_machine_status] at time 21:18:03.706699 duration_in_ms=2275572.222
2019-07-03 21:18:03,714 [salt.minion      :1711][INFO    ][39170] Returning information for job: 20190703203957905291
2019-07-03 21:18:14,705 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command pillar.get with jid 20190703211814694394
2019-07-03 21:18:14,733 [salt.minion      :1432][INFO    ][44395] Starting a new job with PID 44395
2019-07-03 21:18:14,745 [salt.minion      :1711][INFO    ][44395] Returning information for job: 20190703211814694394
2019-07-03 21:18:15,460 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command service.status with jid 20190703211815447965
2019-07-03 21:18:15,486 [salt.minion      :1432][INFO    ][44400] Starting a new job with PID 44400
2019-07-03 21:18:16,273 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][44400] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:16,320 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][44400] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-07-03 21:18:16,343 [salt.minion      :1711][INFO    ][44400] Returning information for job: 20190703211815447965
2019-07-03 21:18:17,082 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703211817068278
2019-07-03 21:18:17,109 [salt.minion      :1432][INFO    ][44411] Starting a new job with PID 44411
2019-07-03 21:18:25,433 [salt.state       :915 ][INFO    ][44411] Loading fresh modules for state activity
2019-07-03 21:18:26,087 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'salt-minion --version' in directory '/root'
2019-07-03 21:18:26,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'salt-minion --version' in directory '/root'
2019-07-03 21:18:27,553 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'salt-minion --version' in directory '/root'
2019-07-03 21:18:27,894 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'salt-minion --version' in directory '/root'
2019-07-03 21:18:30,215 [salt.state       :1780][INFO    ][44411] Running state [salt-minion] at time 21:18:30.215821
2019-07-03 21:18:30,216 [salt.state       :1813][INFO    ][44411] Executing state pkg.installed for [salt-minion]
2019-07-03 21:18:30,217 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-03 21:18:30,357 [salt.state       :300 ][INFO    ][44411] All specified packages are already installed
2019-07-03 21:18:30,357 [salt.state       :1951][INFO    ][44411] Completed state [salt-minion] at time 21:18:30.357467 duration_in_ms=141.647
2019-07-03 21:18:30,357 [salt.state       :1780][INFO    ][44411] Running state [salt_minion_dependency_packages] at time 21:18:30.357891
2019-07-03 21:18:30,358 [salt.state       :1813][INFO    ][44411] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-07-03 21:18:30,369 [salt.state       :300 ][INFO    ][44411] All specified packages are already installed
2019-07-03 21:18:30,369 [salt.state       :1951][INFO    ][44411] Completed state [salt_minion_dependency_packages] at time 21:18:30.369393 duration_in_ms=11.502
2019-07-03 21:18:30,375 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/minion.d/minion.conf] at time 21:18:30.375034
2019-07-03 21:18:30,375 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-07-03 21:18:30,646 [salt.state       :300 ][INFO    ][44411] File /etc/salt/minion.d/minion.conf is in the correct state
2019-07-03 21:18:30,647 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/minion.d/minion.conf] at time 21:18:30.647150 duration_in_ms=272.116
2019-07-03 21:18:30,650 [salt.state       :1780][INFO    ][44411] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:18:30.650757
2019-07-03 21:18:30,651 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-07-03 21:18:30,667 [salt.state       :300 ][INFO    ][44411] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-07-03 21:18:30,667 [salt.state       :1951][INFO    ][44411] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:18:30.667495 duration_in_ms=16.736
2019-07-03 21:18:30,669 [salt.state       :1780][INFO    ][44411] Running state [salt-minion] at time 21:18:30.669148
2019-07-03 21:18:30,669 [salt.state       :1813][INFO    ][44411] Executing state service.running for [salt-minion]
2019-07-03 21:18:30,670 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:30,718 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-07-03 21:18:30,741 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-07-03 21:18:30,764 [salt.state       :300 ][INFO    ][44411] The service salt-minion is already running
2019-07-03 21:18:30,765 [salt.state       :1951][INFO    ][44411] Completed state [salt-minion] at time 21:18:30.765536 duration_in_ms=96.386
2019-07-03 21:18:30,768 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains.d] at time 21:18:30.768866
2019-07-03 21:18:30,769 [salt.state       :1813][INFO    ][44411] Executing state file.directory for [/etc/salt/grains.d]
2019-07-03 21:18:30,773 [salt.state       :300 ][INFO    ][44411] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-07-03 21:18:30,773 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains.d] at time 21:18:30.773710 duration_in_ms=4.844
2019-07-03 21:18:30,774 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains] at time 21:18:30.774649
2019-07-03 21:18:30,775 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/grains]
2019-07-03 21:18:30,775 [salt.state       :300 ][INFO    ][44411] File /etc/salt/grains exists with proper permissions. No changes made.
2019-07-03 21:18:30,776 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains] at time 21:18:30.776123 duration_in_ms=1.474
2019-07-03 21:18:30,776 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains.d/placeholder] at time 21:18:30.776772
2019-07-03 21:18:30,777 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-07-03 21:18:30,778 [salt.state       :300 ][INFO    ][44411] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-07-03 21:18:30,778 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains.d/placeholder] at time 21:18:30.778533 duration_in_ms=1.761
2019-07-03 21:18:30,779 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains.d/sphinx] at time 21:18:30.779198
2019-07-03 21:18:30,779 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-07-03 21:18:30,781 [salt.state       :300 ][INFO    ][44411] File /etc/salt/grains.d/sphinx is in the correct state
2019-07-03 21:18:30,783 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains.d/sphinx] at time 21:18:30.783890 duration_in_ms=4.692
2019-07-03 21:18:30,788 [salt.state       :1780][INFO    ][44411] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.788046
2019-07-03 21:18:30,788 [salt.state       :1813][INFO    ][44411] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-07-03 21:18:30,789 [salt.state       :300 ][INFO    ][44411] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-07-03 21:18:30,789 [salt.state       :1951][INFO    ][44411] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.789727 duration_in_ms=1.682
2019-07-03 21:18:30,790 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains.d/dns_records] at time 21:18:30.790614
2019-07-03 21:18:30,791 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-07-03 21:18:30,793 [salt.state       :300 ][INFO    ][44411] File /etc/salt/grains.d/dns_records is in the correct state
2019-07-03 21:18:30,796 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains.d/dns_records] at time 21:18:30.796260 duration_in_ms=5.645
2019-07-03 21:18:30,798 [salt.state       :1780][INFO    ][44411] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.798374
2019-07-03 21:18:30,798 [salt.state       :1813][INFO    ][44411] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-07-03 21:18:30,799 [salt.state       :300 ][INFO    ][44411] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-07-03 21:18:30,799 [salt.state       :1951][INFO    ][44411] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.799731 duration_in_ms=1.358
2019-07-03 21:18:30,800 [salt.state       :1780][INFO    ][44411] Running state [/etc/salt/grains.d/salt] at time 21:18:30.800540
2019-07-03 21:18:30,801 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-07-03 21:18:30,804 [salt.state       :300 ][INFO    ][44411] File /etc/salt/grains.d/salt is in the correct state
2019-07-03 21:18:30,805 [salt.state       :1951][INFO    ][44411] Completed state [/etc/salt/grains.d/salt] at time 21:18:30.805139 duration_in_ms=4.599
2019-07-03 21:18:30,808 [salt.state       :1780][INFO    ][44411] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.808820
2019-07-03 21:18:30,809 [salt.state       :1813][INFO    ][44411] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-07-03 21:18:30,809 [salt.state       :300 ][INFO    ][44411] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-07-03 21:18:30,809 [salt.state       :1951][INFO    ][44411] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:18:30.809684 duration_in_ms=0.863
2019-07-03 21:18:30,811 [salt.state       :1780][INFO    ][44411] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:18:30.811624
2019-07-03 21:18:30,811 [salt.state       :1813][INFO    ][44411] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-07-03 21:18:30,812 [salt.state       :300 ][INFO    ][44411] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-07-03 21:18:30,812 [salt.state       :1951][INFO    ][44411] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:18:30.812491 duration_in_ms=0.867
2019-07-03 21:18:30,813 [salt.state       :1780][INFO    ][44411] Running state [mine.update] at time 21:18:30.813194
2019-07-03 21:18:30,813 [salt.state       :1813][INFO    ][44411] Executing state module.wait for [mine.update]
2019-07-03 21:18:30,813 [salt.state       :300 ][INFO    ][44411] No changes made for mine.update
2019-07-03 21:18:30,814 [salt.state       :1951][INFO    ][44411] Completed state [mine.update] at time 21:18:30.814009 duration_in_ms=0.815
2019-07-03 21:18:30,814 [salt.state       :1780][INFO    ][44411] Running state [ca-certificates] at time 21:18:30.814299
2019-07-03 21:18:30,814 [salt.state       :1813][INFO    ][44411] Executing state pkg.installed for [ca-certificates]
2019-07-03 21:18:30,825 [salt.state       :300 ][INFO    ][44411] All specified packages are already installed
2019-07-03 21:18:30,826 [salt.state       :1951][INFO    ][44411] Completed state [ca-certificates] at time 21:18:30.826560 duration_in_ms=12.261
2019-07-03 21:18:30,827 [salt.state       :1780][INFO    ][44411] Running state [update-ca-certificates] at time 21:18:30.827528
2019-07-03 21:18:30,827 [salt.state       :1813][INFO    ][44411] Executing state cmd.wait for [update-ca-certificates]
2019-07-03 21:18:30,828 [salt.state       :300 ][INFO    ][44411] No changes made for update-ca-certificates
2019-07-03 21:18:30,828 [salt.state       :1951][INFO    ][44411] Completed state [update-ca-certificates] at time 21:18:30.828376 duration_in_ms=0.849
2019-07-03 21:18:30,828 [salt.state       :1780][INFO    ][44411] Running state [iptables] at time 21:18:30.828680
2019-07-03 21:18:30,828 [salt.state       :1813][INFO    ][44411] Executing state pkg.installed for [iptables]
2019-07-03 21:18:30,838 [salt.state       :300 ][INFO    ][44411] All specified packages are already installed
2019-07-03 21:18:30,839 [salt.state       :1951][INFO    ][44411] Completed state [iptables] at time 21:18:30.839081 duration_in_ms=10.401
2019-07-03 21:18:30,839 [salt.state       :1780][INFO    ][44411] Running state [iptables-persistent] at time 21:18:30.839374
2019-07-03 21:18:30,839 [salt.state       :1813][INFO    ][44411] Executing state pkg.installed for [iptables-persistent]
2019-07-03 21:18:30,849 [salt.state       :300 ][INFO    ][44411] All specified packages are already installed
2019-07-03 21:18:30,849 [salt.state       :1951][INFO    ][44411] Completed state [iptables-persistent] at time 21:18:30.849308 duration_in_ms=9.934
2019-07-03 21:18:30,851 [salt.state       :1780][INFO    ][44411] Running state [iptables_modules_v4_load] at time 21:18:30.851207
2019-07-03 21:18:30,851 [salt.state       :1813][INFO    ][44411] Executing state kmod.present for [iptables_modules_v4_load]
2019-07-03 21:18:30,853 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'lsmod' in directory '/root'
2019-07-03 21:18:30,881 [salt.state       :300 ][INFO    ][44411] Kernel modules iptable_filter, ip_tables are already present
2019-07-03 21:18:30,882 [salt.state       :1951][INFO    ][44411] Completed state [iptables_modules_v4_load] at time 21:18:30.881995 duration_in_ms=30.787
2019-07-03 21:18:30,883 [salt.state       :1780][INFO    ][44411] Running state [/etc/iptables/rules.v4] at time 21:18:30.883250
2019-07-03 21:18:30,883 [salt.state       :1813][INFO    ][44411] Executing state file.managed for [/etc/iptables/rules.v4]
2019-07-03 21:18:30,998 [salt.state       :300 ][INFO    ][44411] File /etc/iptables/rules.v4 is in the correct state
2019-07-03 21:18:30,998 [salt.state       :1951][INFO    ][44411] Completed state [/etc/iptables/rules.v4] at time 21:18:30.998425 duration_in_ms=115.176
2019-07-03 21:18:30,999 [salt.state       :1780][INFO    ][44411] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:18:30.999551
2019-07-03 21:18:30,999 [salt.state       :1813][INFO    ][44411] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-07-03 21:18:31,000 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-07-03 21:18:31,027 [salt.state       :300 ][INFO    ][44411] onlyif execution failed
2019-07-03 21:18:31,027 [salt.state       :1951][INFO    ][44411] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:18:31.027746 duration_in_ms=28.194
2019-07-03 21:18:31,030 [salt.state       :1780][INFO    ][44411] Running state [netfilter-persistent] at time 21:18:31.030040
2019-07-03 21:18:31,030 [salt.state       :1813][INFO    ][44411] Executing state service.running for [netfilter-persistent]
2019-07-03 21:18:31,032 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:31,060 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-07-03 21:18:31,084 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-07-03 21:18:31,110 [salt.state       :300 ][INFO    ][44411] The service netfilter-persistent is already running
2019-07-03 21:18:31,110 [salt.state       :1951][INFO    ][44411] Completed state [netfilter-persistent] at time 21:18:31.110847 duration_in_ms=80.806
2019-07-03 21:18:31,112 [salt.state       :1780][INFO    ][44411] Running state [iptables_extra.remove_stale_tables] at time 21:18:31.112270
2019-07-03 21:18:31,112 [salt.state       :1813][INFO    ][44411] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-07-03 21:18:31,113 [salt.state       :300 ][INFO    ][44411] No changes made for iptables_extra.remove_stale_tables
2019-07-03 21:18:31,113 [salt.state       :1951][INFO    ][44411] Completed state [iptables_extra.remove_stale_tables] at time 21:18:31.113771 duration_in_ms=1.501
2019-07-03 21:18:31,114 [salt.state       :1780][INFO    ][44411] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:18:31.114153
2019-07-03 21:18:31,114 [salt.state       :1813][INFO    ][44411] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-07-03 21:18:31,115 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44411] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-07-03 21:18:31,136 [salt.state       :300 ][INFO    ][44411] onlyif execution failed
2019-07-03 21:18:31,136 [salt.state       :1951][INFO    ][44411] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:18:31.136542 duration_in_ms=22.388
2019-07-03 21:18:31,138 [salt.state       :1780][INFO    ][44411] Running state [/etc/iptables/rules.v6] at time 21:18:31.138508
2019-07-03 21:18:31,139 [salt.state       :1813][INFO    ][44411] Executing state file.absent for [/etc/iptables/rules.v6]
2019-07-03 21:18:31,140 [salt.state       :300 ][INFO    ][44411] File /etc/iptables/rules.v6 is not present
2019-07-03 21:18:31,140 [salt.state       :1951][INFO    ][44411] Completed state [/etc/iptables/rules.v6] at time 21:18:31.140533 duration_in_ms=2.025
2019-07-03 21:18:31,144 [salt.state       :1780][INFO    ][44411] Running state [iptables_extra.flush_all] at time 21:18:31.144128
2019-07-03 21:18:31,144 [salt.state       :1813][INFO    ][44411] Executing state module.wait for [iptables_extra.flush_all]
2019-07-03 21:18:31,144 [salt.state       :300 ][INFO    ][44411] No changes made for iptables_extra.flush_all
2019-07-03 21:18:31,145 [salt.state       :1951][INFO    ][44411] Completed state [iptables_extra.flush_all] at time 21:18:31.145117 duration_in_ms=0.989
2019-07-03 21:18:31,148 [salt.minion      :1711][INFO    ][44411] Returning information for job: 20190703211817068278
2019-07-03 21:18:31,878 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703211831863905
2019-07-03 21:18:31,907 [salt.minion      :1432][INFO    ][44495] Starting a new job with PID 44495
2019-07-03 21:18:33,001 [salt.state       :915 ][INFO    ][44495] Loading fresh modules for state activity
2019-07-03 21:18:34,353 [salt.state       :1780][INFO    ][44495] Running state [maas-rack-controller] at time 21:18:34.353310
2019-07-03 21:18:34,354 [salt.state       :1813][INFO    ][44495] Executing state pkg.installed for [maas-rack-controller]
2019-07-03 21:18:34,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44495] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-03 21:18:34,488 [salt.state       :300 ][INFO    ][44495] All specified packages are already installed
2019-07-03 21:18:34,489 [salt.state       :1951][INFO    ][44495] Completed state [maas-rack-controller] at time 21:18:34.489195 duration_in_ms=135.884
2019-07-03 21:18:34,491 [salt.state       :1780][INFO    ][44495] Running state [ipmitool] at time 21:18:34.491299
2019-07-03 21:18:34,491 [salt.state       :1813][INFO    ][44495] Executing state pkg.installed for [ipmitool]
2019-07-03 21:18:34,500 [salt.state       :300 ][INFO    ][44495] All specified packages are already installed
2019-07-03 21:18:34,500 [salt.state       :1951][INFO    ][44495] Completed state [ipmitool] at time 21:18:34.500811 duration_in_ms=9.512
2019-07-03 21:18:34,504 [salt.state       :1780][INFO    ][44495] Running state [/etc/maas/rackd.conf] at time 21:18:34.504634
2019-07-03 21:18:34,504 [salt.state       :1813][INFO    ][44495] Executing state file.line for [/etc/maas/rackd.conf]
2019-07-03 21:18:34,506 [salt.state       :300 ][INFO    ][44495] No changes needed to be made
2019-07-03 21:18:34,506 [salt.state       :1951][INFO    ][44495] Completed state [/etc/maas/rackd.conf] at time 21:18:34.506564 duration_in_ms=1.93
2019-07-03 21:18:34,506 [salt.state       :1780][INFO    ][44495] Running state [/etc/maas/rackd.conf] at time 21:18:34.506858
2019-07-03 21:18:34,507 [salt.state       :1813][INFO    ][44495] Executing state file.managed for [/etc/maas/rackd.conf]
2019-07-03 21:18:34,507 [salt.loaded.int.states.file:2298][WARNING ][44495] 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-07-03 21:18:34,508 [salt.state       :300 ][INFO    ][44495] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-07-03 21:18:34,508 [salt.state       :1951][INFO    ][44495] Completed state [/etc/maas/rackd.conf] at time 21:18:34.508526 duration_in_ms=1.668
2019-07-03 21:18:34,509 [salt.state       :1780][INFO    ][44495] Running state [maas-rackd] at time 21:18:34.509586
2019-07-03 21:18:34,510 [salt.state       :1813][INFO    ][44495] Executing state service.running for [maas-rackd]
2019-07-03 21:18:34,510 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44495] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:34,555 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44495] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-07-03 21:18:34,577 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44495] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-07-03 21:18:34,601 [salt.state       :300 ][INFO    ][44495] The service maas-rackd is already running
2019-07-03 21:18:34,602 [salt.state       :1951][INFO    ][44495] Completed state [maas-rackd] at time 21:18:34.602486 duration_in_ms=92.899
2019-07-03 21:18:34,604 [salt.minion      :1711][INFO    ][44495] Returning information for job: 20190703211831863905
2019-07-03 21:18:35,321 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703211835305518
2019-07-03 21:18:35,352 [salt.minion      :1432][INFO    ][44531] Starting a new job with PID 44531
2019-07-03 21:18:36,471 [salt.state       :915 ][INFO    ][44531] Loading fresh modules for state activity
2019-07-03 21:18:37,948 [salt.state       :1780][INFO    ][44531] Running state [maas-region-controller] at time 21:18:37.948784
2019-07-03 21:18:37,949 [salt.state       :1813][INFO    ][44531] Executing state pkg.installed for [maas-region-controller]
2019-07-03 21:18:37,950 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-07-03 21:18:38,073 [salt.state       :300 ][INFO    ][44531] All specified packages are already installed
2019-07-03 21:18:38,073 [salt.state       :1951][INFO    ][44531] Completed state [maas-region-controller] at time 21:18:38.073699 duration_in_ms=124.915
2019-07-03 21:18:38,074 [salt.state       :1780][INFO    ][44531] Running state [python-oauth] at time 21:18:38.074098
2019-07-03 21:18:38,074 [salt.state       :1813][INFO    ][44531] Executing state pkg.installed for [python-oauth]
2019-07-03 21:18:38,084 [salt.state       :300 ][INFO    ][44531] All specified packages are already installed
2019-07-03 21:18:38,084 [salt.state       :1951][INFO    ][44531] Completed state [python-oauth] at time 21:18:38.084577 duration_in_ms=10.479
2019-07-03 21:18:38,087 [salt.state       :1780][INFO    ][44531] Running state [/etc/maas/regiond.conf] at time 21:18:38.087862
2019-07-03 21:18:38,088 [salt.state       :1813][INFO    ][44531] Executing state file.replace for [/etc/maas/regiond.conf]
2019-07-03 21:18:38,094 [salt.state       :300 ][INFO    ][44531] No changes needed to be made
2019-07-03 21:18:38,094 [salt.state       :1951][INFO    ][44531] Completed state [/etc/maas/regiond.conf] at time 21:18:38.094731 duration_in_ms=6.87
2019-07-03 21:18:38,095 [salt.state       :1780][INFO    ][44531] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:18:38.095267
2019-07-03 21:18:38,095 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-07-03 21:18:38,167 [salt.state       :300 ][INFO    ][44531] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-07-03 21:18:38,168 [salt.state       :1951][INFO    ][44531] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:18:38.168013 duration_in_ms=72.745
2019-07-03 21:18:38,169 [salt.state       :1780][INFO    ][44531] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:18:38.169181
2019-07-03 21:18:38,170 [salt.state       :1813][INFO    ][44531] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-03 21:18:38,177 [salt.state       :300 ][INFO    ][44531] No changes needed to be made
2019-07-03 21:18:38,177 [salt.state       :1951][INFO    ][44531] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:18:38.177662 duration_in_ms=8.481
2019-07-03 21:18:38,178 [salt.state       :1780][INFO    ][44531] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:18:38.178358
2019-07-03 21:18:38,178 [salt.state       :1813][INFO    ][44531] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-07-03 21:18:38,184 [salt.state       :300 ][INFO    ][44531] No changes needed to be made
2019-07-03 21:18:38,184 [salt.state       :1951][INFO    ][44531] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:18:38.184348 duration_in_ms=5.99
2019-07-03 21:18:38,185 [salt.state       :1780][INFO    ][44531] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:18:38.185025
2019-07-03 21:18:38,185 [salt.state       :1813][INFO    ][44531] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-07-03 21:18:38,220 [salt.state       :300 ][INFO    ][44531] No changes needed to be made
2019-07-03 21:18:38,221 [salt.state       :1951][INFO    ][44531] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:18:38.221072 duration_in_ms=36.046
2019-07-03 21:18:38,223 [salt.state       :1780][INFO    ][44531] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:18:38.221704
2019-07-03 21:18:38,223 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-07-03 21:18:38,242 [salt.state       :300 ][INFO    ][44531] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-07-03 21:18:38,242 [salt.state       :1951][INFO    ][44531] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:18:38.242483 duration_in_ms=20.778
2019-07-03 21:18:38,244 [salt.state       :1780][INFO    ][44531] Running state [a2enmod headers] at time 21:18:38.244202
2019-07-03 21:18:38,244 [salt.state       :1813][INFO    ][44531] Executing state cmd.run for [a2enmod headers]
2019-07-03 21:18:38,245 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command 'a2enmod headers' in directory '/root'
2019-07-03 21:18:38,337 [salt.state       :300 ][INFO    ][44531] {'pid': 44550, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-07-03 21:18:38,338 [salt.state       :1951][INFO    ][44531] Completed state [a2enmod headers] at time 21:18:38.338366 duration_in_ms=94.165
2019-07-03 21:18:38,339 [salt.state       :1780][INFO    ][44531] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:18:38.339142
2019-07-03 21:18:38,339 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-07-03 21:18:38,371 [salt.state       :300 ][INFO    ][44531] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-07-03 21:18:38,372 [salt.state       :1951][INFO    ][44531] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:18:38.372224 duration_in_ms=33.082
2019-07-03 21:18:38,373 [salt.state       :1780][INFO    ][44531] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:18:38.373058
2019-07-03 21:18:38,373 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-07-03 21:18:38,443 [salt.state       :300 ][INFO    ][44531] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-07-03 21:18:38,444 [salt.state       :1951][INFO    ][44531] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:18:38.443973 duration_in_ms=70.915
2019-07-03 21:18:38,444 [salt.state       :1780][INFO    ][44531] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:18:38.444538
2019-07-03 21:18:38,444 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-07-03 21:18:38,513 [salt.state       :300 ][INFO    ][44531] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-07-03 21:18:38,514 [salt.state       :1951][INFO    ][44531] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:18:38.514202 duration_in_ms=69.663
2019-07-03 21:18:38,515 [salt.state       :1780][INFO    ][44531] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:18:38.515315
2019-07-03 21:18:38,515 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-07-03 21:18:38,602 [salt.state       :300 ][INFO    ][44531] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-07-03 21:18:38,603 [salt.state       :1951][INFO    ][44531] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:18:38.602947 duration_in_ms=87.633
2019-07-03 21:18:38,603 [salt.state       :1780][INFO    ][44531] Running state [/root/.pgpass] at time 21:18:38.603315
2019-07-03 21:18:38,603 [salt.state       :1813][INFO    ][44531] Executing state file.managed for [/root/.pgpass]
2019-07-03 21:18:38,660 [salt.state       :300 ][INFO    ][44531] File /root/.pgpass is in the correct state
2019-07-03 21:18:38,661 [salt.state       :1951][INFO    ][44531] Completed state [/root/.pgpass] at time 21:18:38.661146 duration_in_ms=57.831
2019-07-03 21:18:38,670 [salt.state       :1780][INFO    ][44531] Running state [maas-region syncdb --noinput] at time 21:18:38.670159
2019-07-03 21:18:38,670 [salt.state       :1813][INFO    ][44531] Executing state cmd.run for [maas-region syncdb --noinput]
2019-07-03 21:18:38,671 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-07-03 21:18:41,639 [salt.state       :300 ][INFO    ][44531] {'pid': 44564, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, contenttypes, auth, metadataserver, sites, piston3, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-07-03 21:18:41,640 [salt.state       :1951][INFO    ][44531] Completed state [maas-region syncdb --noinput] at time 21:18:41.640627 duration_in_ms=2970.466
2019-07-03 21:18:41,641 [salt.state       :2022][WARNING ][44531] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-07-03 21:18:41,646 [salt.state       :1780][INFO    ][44531] Running state [maas-regiond] at time 21:18:41.646446
2019-07-03 21:18:41,647 [salt.state       :1813][INFO    ][44531] Executing state service.running for [maas-regiond]
2019-07-03 21:18:41,649 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:41,700 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-07-03 21:18:41,728 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-07-03 21:18:41,755 [salt.state       :300 ][INFO    ][44531] The service maas-regiond is already running
2019-07-03 21:18:41,756 [salt.state       :1951][INFO    ][44531] Completed state [maas-regiond] at time 21:18:41.756015 duration_in_ms=109.571
2019-07-03 21:18:41,760 [salt.state       :1780][INFO    ][44531] Running state [bind9] at time 21:18:41.759898
2019-07-03 21:18:41,760 [salt.state       :1813][INFO    ][44531] Executing state service.running for [bind9]
2019-07-03 21:18:41,765 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:41,789 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-07-03 21:18:41,812 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-07-03 21:18:41,838 [salt.state       :300 ][INFO    ][44531] The service bind9 is already running
2019-07-03 21:18:41,838 [salt.state       :1951][INFO    ][44531] Completed state [bind9] at time 21:18:41.838443 duration_in_ms=78.546
2019-07-03 21:18:41,841 [salt.state       :1780][INFO    ][44531] Running state [apache2] at time 21:18:41.841695
2019-07-03 21:18:41,842 [salt.state       :1813][INFO    ][44531] Executing state service.running for [apache2]
2019-07-03 21:18:41,843 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-07-03 21:18:41,868 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-07-03 21:18:41,888 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-07-03 21:18:41,922 [salt.state       :300 ][INFO    ][44531] The service apache2 is already running
2019-07-03 21:18:41,923 [salt.state       :1951][INFO    ][44531] Completed state [apache2] at time 21:18:41.923062 duration_in_ms=81.367
2019-07-03 21:18:41,926 [salt.state       :1780][INFO    ][44531] Running state [maasng.wait_for_http_code] at time 21:18:41.925603
2019-07-03 21:18:41,926 [salt.state       :1813][INFO    ][44531] Executing state module.run for [maasng.wait_for_http_code]
2019-07-03 21:18:41,927 [salt.utils.decorators:613 ][WARNING ][44531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:18:42,059 [salt.state       :300 ][INFO    ][44531] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-07-03 21:18:42,060 [salt.state       :1951][INFO    ][44531] Completed state [maasng.wait_for_http_code] at time 21:18:42.060463 duration_in_ms=134.86
2019-07-03 21:18:42,062 [salt.state       :1780][INFO    ][44531] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:18:42.062506
2019-07-03 21:18:42,063 [salt.state       :1813][INFO    ][44531] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-07-03 21:18:42,063 [salt.state       :300 ][INFO    ][44531] /var/lib/maas/.setup_admin exists
2019-07-03 21:18:42,064 [salt.state       :1951][INFO    ][44531] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:18:42.064323 duration_in_ms=1.816
2019-07-03 21:18:42,065 [salt.state       :1780][INFO    ][44531] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:42.065610
2019-07-03 21:18:42,066 [salt.state       :1813][INFO    ][44531] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:18:42,067 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44531] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:18:44,001 [salt.state       :300 ][INFO    ][44531] {'pid': 44585, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:18:44,003 [salt.state       :1951][INFO    ][44531] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:44.003035 duration_in_ms=1937.425
2019-07-03 21:18:44,012 [salt.state       :1780][INFO    ][44531] Running state [maas_region_boot_source_resources_mirror] at time 21:18:44.012592
2019-07-03 21:18:44,012 [salt.state       :1813][INFO    ][44531] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-07-03 21:18:44,108 [salt.state       :300 ][INFO    ][44531] {'changes': {}}
2019-07-03 21:18:44,109 [salt.state       :1951][INFO    ][44531] Completed state [maas_region_boot_source_resources_mirror] at time 21:18:44.109198 duration_in_ms=96.605
2019-07-03 21:18:44,111 [salt.state       :1780][INFO    ][44531] Running state [maasng.boot_resources_import] at time 21:18:44.111056
2019-07-03 21:18:44,111 [salt.state       :1813][INFO    ][44531] Executing state module.run for [maasng.boot_resources_import]
2019-07-03 21:18:44,112 [salt.utils.decorators:613 ][WARNING ][44531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:18:44,209 [salt.loaded.ext.module.maasng:1600][INFO    ][44531] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-07-03 21:18:49,262 [salt.loaded.ext.module.maasng:1600][INFO    ][44531] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-07-03 21:18:50,421 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211850407393
2019-07-03 21:18:50,454 [salt.minion      :1432][INFO    ][44620] Starting a new job with PID 44620
2019-07-03 21:18:50,485 [salt.minion      :1711][INFO    ][44620] Returning information for job: 20190703211850407393
2019-07-03 21:18:54,372 [salt.state       :300 ][INFO    ][44531] {'ret': True}
2019-07-03 21:18:54,372 [salt.state       :1951][INFO    ][44531] Completed state [maasng.boot_resources_import] at time 21:18:54.372583 duration_in_ms=10261.525
2019-07-03 21:18:54,375 [salt.state       :1780][INFO    ][44531] Running state [maas_region_boot_sources_selection_xenial] at time 21:18:54.375043
2019-07-03 21:18:54,375 [salt.state       :1813][INFO    ][44531] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-07-03 21:18:54,564 [salt.state       :300 ][INFO    ][44531] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-07-03 21:18:54,564 [salt.state       :1951][INFO    ][44531] Completed state [maas_region_boot_sources_selection_xenial] at time 21:18:54.564434 duration_in_ms=189.39
2019-07-03 21:18:54,567 [salt.state       :1780][INFO    ][44531] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:18:54.567097
2019-07-03 21:18:54,567 [salt.state       :1813][INFO    ][44531] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-07-03 21:18:54,568 [salt.utils.decorators:613 ][WARNING ][44531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:18:54,568 [salt.loaded.ext.module.maasng:1771][INFO    ][44531] boot-sources sync initiated for ALL Rack's
2019-07-03 21:18:55,662 [salt.state       :300 ][INFO    ][44531] {'ret': True}
2019-07-03 21:18:55,663 [salt.state       :1951][INFO    ][44531] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:18:55.663221 duration_in_ms=1096.123
2019-07-03 21:18:55,665 [salt.state       :1780][INFO    ][44531] Running state [maas.process_maas_config] at time 21:18:55.665378
2019-07-03 21:18:55,666 [salt.state       :1813][INFO    ][44531] Executing state module.run for [maas.process_maas_config]
2019-07-03 21:18:55,667 [salt.utils.decorators:613 ][WARNING ][44531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:18:55,667 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=enable_http_proxy value=True
2019-07-03 21:18:55,725 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=upstream_dns value=8.8.8.8
2019-07-03 21:18:55,784 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=commissioning_distro_series value=xenial
2019-07-03 21:18:55,848 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=default_osystem value=ubuntu
2019-07-03 21:18:55,911 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=active_discovery_interval value=600
2019-07-03 21:18:55,962 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=dnssec_validation value=no
2019-07-03 21:18:57,421 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=maas_name value=mas01
2019-07-03 21:18:57,461 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=network_discovery value=enabled
2019-07-03 21:18:57,541 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=enable_third_party_drivers value=True
2019-07-03 21:18:57,600 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=default_storage_layout value=lvm
2019-07-03 21:18:57,651 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=ntp_external_only value=True
2019-07-03 21:18:57,696 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=disk_erase_with_secure_erase value=False
2019-07-03 21:18:57,739 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=default_distro_series value=xenial
2019-07-03 21:18:57,801 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-07-03 21:18:57,916 [salt.state       :300 ][INFO    ][44531] {'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-07-03 21:18:57,916 [salt.state       :1951][INFO    ][44531] Completed state [maas.process_maas_config] at time 21:18:57.916247 duration_in_ms=2250.868
2019-07-03 21:18:57,916 [salt.state       :1780][INFO    ][44531] Running state [pxe_admin] at time 21:18:57.916914
2019-07-03 21:18:57,917 [salt.state       :1813][INFO    ][44531] Executing state maasng.fabric_present for [pxe_admin]
2019-07-03 21:18:57,985 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/', u'id': 5005, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-4', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}]
2019-07-03 21:18:58,051 [salt.loaded.ext.module.maasng:1008][WARNING ][44531] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-07-03 21:18:58,051 [salt.loaded.ext.module.maasng:1011][WARNING ][44531] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-07-03 21:18:58,129 [salt.state       :300 ][INFO    ][44531] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-07-03 21:18:58,132 [salt.state       :1951][INFO    ][44531] Completed state [pxe_admin] at time 21:18:58.132644 duration_in_ms=215.729
2019-07-03 21:18:58,133 [salt.state       :1780][INFO    ][44531] Running state [vlan 0] at time 21:18:58.133114
2019-07-03 21:18:58,133 [salt.state       :1813][INFO    ][44531] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-03 21:18:58,190 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 4, u'vlans': [{u'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'name': u'fabric-4'}, {u'id': 3, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'tsp7fn', u'mtu': 1500, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'name': u'pxe_admin'}]
2019-07-03 21:18:58,303 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 4, u'vlans': [{u'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'name': u'fabric-4'}, {u'id': 3, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'tsp7fn', u'name': u'untagged', u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'name': u'pxe_admin'}]
2019-07-03 21:18:58,563 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/', u'id': 5005, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-4', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}]
2019-07-03 21:18:58,654 [salt.state       :300 ][INFO    ][44531] {'new': 'Vlan untagged was updated'}
2019-07-03 21:18:58,655 [salt.state       :1951][INFO    ][44531] Completed state [vlan 0] at time 21:18:58.655189 duration_in_ms=522.075
2019-07-03 21:18:58,656 [salt.state       :1780][INFO    ][44531] Running state [192.168.11.0/24] at time 21:18:58.656809
2019-07-03 21:18:58,657 [salt.state       :1813][INFO    ][44531] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-07-03 21:18:58,867 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{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'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-4', u'relay_vlan': None, u'primary_rack': None, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'class_type': None, u'name': u'fabric-4', u'id': 4}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 3, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'tsp7fn', u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'class_type': u'', u'name': u'pxe_admin', u'id': 3}]
2019-07-03 21:18:58,868 [salt.loaded.ext.module.maasng:1235][WARNING ][44531] Ignoring parameter vlan:0
2019-07-03 21:18:58,931 [salt.state       :300 ][INFO    ][44531] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-07-03 21:18:58,932 [salt.state       :1951][INFO    ][44531] Completed state [192.168.11.0/24] at time 21:18:58.932252 duration_in_ms=275.441
2019-07-03 21:18:58,936 [salt.state       :1780][INFO    ][44531] Running state [maas_create_iprange_1] at time 21:18:58.936086
2019-07-03 21:18:58,936 [salt.state       :1813][INFO    ][44531] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-07-03 21:18:58,997 [salt.state       :300 ][INFO    ][44531] Iprange maas_create_iprange_1 already exist.
2019-07-03 21:18:58,998 [salt.state       :1951][INFO    ][44531] Completed state [maas_create_iprange_1] at time 21:18:58.997696 duration_in_ms=61.61
2019-07-03 21:18:58,999 [salt.state       :1780][INFO    ][44531] Running state [vlan 0] at time 21:18:58.999279
2019-07-03 21:18:59,000 [salt.state       :1813][INFO    ][44531] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-07-03 21:18:59,069 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/', u'id': 5005, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-4', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}]
2019-07-03 21:18:59,193 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 4, u'vlans': [{u'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5005, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'name': u'fabric-4'}, {u'id': 3, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 3, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'tsp7fn', u'mtu': 1500, u'id': 5004, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'name': u'pxe_admin'}]
2019-07-03 21:18:59,520 [salt.loaded.ext.module.maasng:945 ][INFO    ][44531] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'fabric': u'fabric-4', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 4, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5005/', u'id': 5005, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-4', u'resource_uri': u'/MAAS/api/2.0/fabrics/4/', u'id': 4}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 3, u'mtu': 1500, u'primary_rack': u'tsp7fn', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5004/', u'id': 5004, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/3/', u'id': 3}]
2019-07-03 21:18:59,635 [salt.state       :300 ][INFO    ][44531] {'new': 'Vlan untagged was updated'}
2019-07-03 21:18:59,635 [salt.state       :1951][INFO    ][44531] Completed state [vlan 0] at time 21:18:59.635626 duration_in_ms=636.346
2019-07-03 21:18:59,636 [salt.state       :1780][INFO    ][44531] Running state [opnfv] at time 21:18:59.636624
2019-07-03 21:18:59,637 [salt.state       :1813][INFO    ][44531] Executing state maasng.sshkey_present for [opnfv]
2019-07-03 21:18:59,685 [salt.loaded.ext.module.maasng:1903][INFO    ][44531] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-07-03 21:18:59,685 [salt.state       :300 ][INFO    ][44531] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-07-03 21:18:59,686 [salt.state       :1951][INFO    ][44531] Completed state [opnfv] at time 21:18:59.686783 duration_in_ms=50.159
2019-07-03 21:18:59,687 [salt.state       :1780][INFO    ][44531] Running state [maas.process_tags] at time 21:18:59.687472
2019-07-03 21:18:59,687 [salt.state       :1813][INFO    ][44531] Executing state module.run for [maas.process_tags]
2019-07-03 21:18:59,688 [salt.utils.decorators:613 ][WARNING ][44531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:18:59,742 [salt.loaded.ext.module.maas:92  ][INFO    ][44531] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-07-03 21:18:59,801 [salt.state       :300 ][INFO    ][44531] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-07-03 21:18:59,801 [salt.state       :1951][INFO    ][44531] Completed state [maas.process_tags] at time 21:18:59.801426 duration_in_ms=113.954
2019-07-03 21:18:59,805 [salt.minion      :1711][INFO    ][44531] Returning information for job: 20190703211835305518
2019-07-03 21:19:00,584 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703211900571089
2019-07-03 21:19:00,608 [salt.minion      :1432][INFO    ][44998] Starting a new job with PID 44998
2019-07-03 21:19:09,152 [salt.state       :915 ][INFO    ][44998] Loading fresh modules for state activity
2019-07-03 21:19:09,284 [salt.state       :1780][INFO    ][44998] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:09.284220
2019-07-03 21:19:09,284 [salt.state       :1813][INFO    ][44998] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:19:09,287 [salt.loaded.int.module.cmdmod:395 ][INFO    ][44998] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:19:11,174 [salt.state       :300 ][INFO    ][44998] {'pid': 45024, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:19:11,175 [salt.state       :1951][INFO    ][44998] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:11.175196 duration_in_ms=1890.976
2019-07-03 21:19:11,178 [salt.state       :1780][INFO    ][44998] Running state [maas.process_machines] at time 21:19:11.178701
2019-07-03 21:19:11,179 [salt.state       :1813][INFO    ][44998] Executing state module.run for [maas.process_machines]
2019-07-03 21:19:11,180 [salt.utils.decorators:613 ][WARNING ][44998] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:19:11,687 [salt.loaded.ext.module.maas:412 ][WARNING ][44998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 21:19:11,688 [salt.loaded.ext.module.maas:92  ][INFO    ][44998] machine hostname=gtw01 power_type=ipmi mac_addresses=['14:58:d0:54:6a:60'] power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 system_id=dschpq architecture=amd64/generic power_parameters_power_user=opnfv
2019-07-03 21:19:12,881 [salt.loaded.ext.module.maas:412 ][WARNING ][44998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 21:19:12,882 [salt.loaded.ext.module.maas:92  ][INFO    ][44998] machine hostname=cmp002 power_type=ipmi mac_addresses=['9c:b6:54:8a:10:18'] power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 system_id=4wpq8m architecture=amd64/generic power_parameters_power_user=opnfv
2019-07-03 21:19:14,139 [salt.loaded.ext.module.maas:412 ][WARNING ][44998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 21:19:14,140 [salt.loaded.ext.module.maas:92  ][INFO    ][44998] machine hostname=cmp001 power_type=ipmi mac_addresses=['9c:b6:54:8a:95:a0'] power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 system_id=fsmsmb architecture=amd64/generic power_parameters_power_user=opnfv
2019-07-03 21:19:15,414 [salt.loaded.ext.module.maas:412 ][WARNING ][44998] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-07-03 21:19:15,415 [salt.loaded.ext.module.maas:92  ][INFO    ][44998] machine hostname=ctl01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=rg86q3 architecture=amd64/generic power_parameters_power_user=opnfv
2019-07-03 21:19:15,691 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703211915678407
2019-07-03 21:19:15,721 [salt.minion      :1432][INFO    ][45169] Starting a new job with PID 45169
2019-07-03 21:19:15,764 [salt.minion      :1711][INFO    ][45169] Returning information for job: 20190703211915678407
2019-07-03 21:19:16,692 [salt.state       :300 ][INFO    ][44998] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-07-03 21:19:16,693 [salt.state       :1951][INFO    ][44998] Completed state [maas.process_machines] at time 21:19:16.693104 duration_in_ms=5514.403
2019-07-03 21:19:16,697 [salt.minion      :1711][INFO    ][44998] Returning information for job: 20190703211900571089
2019-07-03 21:19:50,100 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703211950087013
2019-07-03 21:19:50,124 [salt.minion      :1432][INFO    ][45230] Starting a new job with PID 45230
2019-07-03 21:19:58,422 [salt.state       :915 ][INFO    ][45230] Loading fresh modules for state activity
2019-07-03 21:19:58,537 [salt.state       :1780][INFO    ][45230] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:58.537049
2019-07-03 21:19:58,537 [salt.state       :1813][INFO    ][45230] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:19:58,540 [salt.loaded.int.module.cmdmod:395 ][INFO    ][45230] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:20:00,562 [salt.state       :300 ][INFO    ][45230] {'pid': 45267, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:20:00,563 [salt.state       :1951][INFO    ][45230] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:00.563565 duration_in_ms=2026.516
2019-07-03 21:20:00,568 [salt.state       :1780][INFO    ][45230] Running state [maas.wait_for_machine_status] at time 21:20:00.568244
2019-07-03 21:20:00,568 [salt.state       :1813][INFO    ][45230] Executing state module.run for [maas.wait_for_machine_status]
2019-07-03 21:20:00,569 [salt.utils.decorators:613 ][WARNING ][45230] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:20:02,608 [salt.state       :300 ][INFO    ][45230] {'ret': True}
2019-07-03 21:20:02,609 [salt.state       :1951][INFO    ][45230] Completed state [maas.wait_for_machine_status] at time 21:20:02.609439 duration_in_ms=2041.193
2019-07-03 21:20:02,613 [salt.minion      :1711][INFO    ][45230] Returning information for job: 20190703211950087013
2019-07-03 21:20:03,368 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703212003355267
2019-07-03 21:20:03,397 [salt.minion      :1432][INFO    ][45283] Starting a new job with PID 45283
2019-07-03 21:20:04,483 [salt.state       :915 ][INFO    ][45283] Loading fresh modules for state activity
2019-07-03 21:20:04,633 [salt.state       :1780][INFO    ][45283] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:04.633372
2019-07-03 21:20:04,635 [salt.state       :1813][INFO    ][45283] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:20:04,637 [salt.loaded.int.module.cmdmod:395 ][INFO    ][45283] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:20:06,492 [salt.state       :300 ][INFO    ][45283] {'pid': 45290, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:20:06,493 [salt.state       :1951][INFO    ][45283] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:06.493390 duration_in_ms=1860.019
2019-07-03 21:20:06,498 [salt.state       :1780][INFO    ][45283] Running state [maas_machines_storage_cmp002_lvm] at time 21:20:06.498162
2019-07-03 21:20:06,498 [salt.state       :1813][INFO    ][45283] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-07-03 21:20:06,993 [salt.state       :300 ][INFO    ][45283] Machine cmp002 is not in Ready state.
2019-07-03 21:20:06,994 [salt.state       :1951][INFO    ][45283] Completed state [maas_machines_storage_cmp002_lvm] at time 21:20:06.994410 duration_in_ms=496.247
2019-07-03 21:20:06,995 [salt.state       :1780][INFO    ][45283] Running state [maas_machines_storage_cmp001_lvm] at time 21:20:06.995208
2019-07-03 21:20:06,995 [salt.state       :1813][INFO    ][45283] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-07-03 21:20:07,465 [salt.state       :300 ][INFO    ][45283] Machine cmp001 is not in Ready state.
2019-07-03 21:20:07,467 [salt.state       :1951][INFO    ][45283] Completed state [maas_machines_storage_cmp001_lvm] at time 21:20:07.467475 duration_in_ms=472.267
2019-07-03 21:20:07,471 [salt.minion      :1711][INFO    ][45283] Returning information for job: 20190703212003355267
2019-07-03 21:20:08,189 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703212008178054
2019-07-03 21:20:08,216 [salt.minion      :1432][INFO    ][45300] Starting a new job with PID 45300
2019-07-03 21:20:09,298 [salt.state       :915 ][INFO    ][45300] Loading fresh modules for state activity
2019-07-03 21:20:09,400 [salt.state       :1780][INFO    ][45300] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:09.400135
2019-07-03 21:20:09,400 [salt.state       :1813][INFO    ][45300] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:20:09,402 [salt.loaded.int.module.cmdmod:395 ][INFO    ][45300] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:20:11,334 [salt.state       :300 ][INFO    ][45300] {'pid': 45307, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:20:11,335 [salt.state       :1951][INFO    ][45300] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:11.335685 duration_in_ms=1935.548
2019-07-03 21:20:11,338 [salt.state       :1780][INFO    ][45300] Running state [maas.deploy_machines] at time 21:20:11.338671
2019-07-03 21:20:11,339 [salt.state       :1813][INFO    ][45300] Executing state module.run for [maas.deploy_machines]
2019-07-03 21:20:11,340 [salt.utils.decorators:613 ][WARNING ][45300] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:20:11,826 [salt.loaded.ext.module.maas:684 ][INFO    ][45300] deploymachines hwe_kernel=hwe-16.04 system_id=dschpq distro_series=xenial
2019-07-03 21:20:14,195 [salt.state       :300 ][INFO    ][45300] {'ret': {'updated': ['cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': ['gtw01']}}
2019-07-03 21:20:14,195 [salt.state       :1951][INFO    ][45300] Completed state [maas.deploy_machines] at time 21:20:14.195379 duration_in_ms=2856.708
2019-07-03 21:20:14,197 [salt.minion      :1711][INFO    ][45300] Returning information for job: 20190703212008178054
2019-07-03 21:20:14,995 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command state.apply with jid 20190703212014935631
2019-07-03 21:20:15,020 [salt.minion      :1432][INFO    ][45369] Starting a new job with PID 45369
2019-07-03 21:20:23,320 [salt.state       :915 ][INFO    ][45369] Loading fresh modules for state activity
2019-07-03 21:20:23,436 [salt.state       :1780][INFO    ][45369] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:23.436857
2019-07-03 21:20:23,437 [salt.state       :1813][INFO    ][45369] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-07-03 21:20:23,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][45369] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-07-03 21:20:25,381 [salt.state       :300 ][INFO    ][45369] {'pid': 45393, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-07-03 21:20:25,382 [salt.state       :1951][INFO    ][45369] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:25.382617 duration_in_ms=1945.761
2019-07-03 21:20:25,384 [salt.state       :1780][INFO    ][45369] Running state [maas.wait_for_machine_status] at time 21:20:25.384795
2019-07-03 21:20:25,385 [salt.state       :1813][INFO    ][45369] Executing state module.run for [maas.wait_for_machine_status]
2019-07-03 21:20:25,386 [salt.utils.decorators:613 ][WARNING ][45369] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-07-03 21:20:27,238 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2248.16430092s left)
2019-07-03 21:20:29,984 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212029967847
2019-07-03 21:20:30,015 [salt.minion      :1432][INFO    ][45407] Starting a new job with PID 45407
2019-07-03 21:20:30,043 [salt.minion      :1711][INFO    ][45407] Returning information for job: 20190703212029967847
2019-07-03 21:20:59,128 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2216.27452493s left)
2019-07-03 21:21:00,080 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212100064923
2019-07-03 21:21:00,108 [salt.minion      :1432][INFO    ][45459] Starting a new job with PID 45459
2019-07-03 21:21:00,147 [salt.minion      :1711][INFO    ][45459] Returning information for job: 20190703212100064923
2019-07-03 21:21:30,163 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212130153247
2019-07-03 21:21:30,186 [salt.minion      :1432][INFO    ][45480] Starting a new job with PID 45480
2019-07-03 21:21:30,215 [salt.minion      :1711][INFO    ][45480] Returning information for job: 20190703212130153247
2019-07-03 21:21:31,144 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2184.25834394s left)
2019-07-03 21:22:00,261 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212200241577
2019-07-03 21:22:00,294 [salt.minion      :1432][INFO    ][45528] Starting a new job with PID 45528
2019-07-03 21:22:00,328 [salt.minion      :1711][INFO    ][45528] Returning information for job: 20190703212200241577
2019-07-03 21:22:03,057 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2152.344805s left)
2019-07-03 21:22:30,343 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212230326884
2019-07-03 21:22:30,370 [salt.minion      :1432][INFO    ][45552] Starting a new job with PID 45552
2019-07-03 21:22:30,413 [salt.minion      :1711][INFO    ][45552] Returning information for job: 20190703212230326884
2019-07-03 21:22:35,111 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2120.29151702s left)
2019-07-03 21:23:00,452 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212300436750
2019-07-03 21:23:00,484 [salt.minion      :1432][INFO    ][45609] Starting a new job with PID 45609
2019-07-03 21:23:00,520 [salt.minion      :1711][INFO    ][45609] Returning information for job: 20190703212300436750
2019-07-03 21:23:07,105 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2088.29755092s left)
2019-07-03 21:23:30,547 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212330534131
2019-07-03 21:23:30,571 [salt.minion      :1432][INFO    ][45632] Starting a new job with PID 45632
2019-07-03 21:23:30,607 [salt.minion      :1711][INFO    ][45632] Returning information for job: 20190703212330534131
2019-07-03 21:23:39,094 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2056.30819297s left)
2019-07-03 21:24:00,647 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212400632499
2019-07-03 21:24:00,676 [salt.minion      :1432][INFO    ][45683] Starting a new job with PID 45683
2019-07-03 21:24:00,708 [salt.minion      :1711][INFO    ][45683] Returning information for job: 20190703212400632499
2019-07-03 21:24:10,988 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2024.41362286s left)
2019-07-03 21:24:30,768 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212430749369
2019-07-03 21:24:30,798 [salt.minion      :1432][INFO    ][45706] Starting a new job with PID 45706
2019-07-03 21:24:30,833 [salt.minion      :1711][INFO    ][45706] Returning information for job: 20190703212430749369
2019-07-03 21:24:42,867 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1992.53466201s left)
2019-07-03 21:25:00,862 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212500849058
2019-07-03 21:25:00,889 [salt.minion      :1432][INFO    ][45804] Starting a new job with PID 45804
2019-07-03 21:25:00,925 [salt.minion      :1711][INFO    ][45804] Returning information for job: 20190703212500849058
2019-07-03 21:25:14,828 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1960.57454491s left)
2019-07-03 21:25:31,004 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212530988382
2019-07-03 21:25:31,035 [salt.minion      :1432][INFO    ][45856] Starting a new job with PID 45856
2019-07-03 21:25:31,066 [salt.minion      :1711][INFO    ][45856] Returning information for job: 20190703212530988382
2019-07-03 21:25:46,920 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1928.48202586s left)
2019-07-03 21:26:01,137 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212601120202
2019-07-03 21:26:01,169 [salt.minion      :1432][INFO    ][45987] Starting a new job with PID 45987
2019-07-03 21:26:01,206 [salt.minion      :1711][INFO    ][45987] Returning information for job: 20190703212601120202
2019-07-03 21:26:18,905 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1896.49734497s left)
2019-07-03 21:26:31,277 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212631261681
2019-07-03 21:26:31,304 [salt.minion      :1432][INFO    ][46037] Starting a new job with PID 46037
2019-07-03 21:26:31,338 [salt.minion      :1711][INFO    ][46037] Returning information for job: 20190703212631261681
2019-07-03 21:26:50,901 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1864.5014739s left)
2019-07-03 21:27:01,421 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212701402517
2019-07-03 21:27:01,451 [salt.minion      :1432][INFO    ][46102] Starting a new job with PID 46102
2019-07-03 21:27:01,481 [salt.minion      :1711][INFO    ][46102] Returning information for job: 20190703212701402517
2019-07-03 21:27:22,880 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1832.52252793s left)
2019-07-03 21:27:31,566 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212731553457
2019-07-03 21:27:31,592 [salt.minion      :1432][INFO    ][46135] Starting a new job with PID 46135
2019-07-03 21:27:31,632 [salt.minion      :1711][INFO    ][46135] Returning information for job: 20190703212731553457
2019-07-03 21:27:54,820 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1800.58164287s left)
2019-07-03 21:28:01,731 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212801715109
2019-07-03 21:28:01,763 [salt.minion      :1432][INFO    ][46291] Starting a new job with PID 46291
2019-07-03 21:28:01,796 [salt.minion      :1711][INFO    ][46291] Returning information for job: 20190703212801715109
2019-07-03 21:28:26,792 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1768.60959792s left)
2019-07-03 21:28:31,901 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212831886961
2019-07-03 21:28:31,932 [salt.minion      :1432][INFO    ][46352] Starting a new job with PID 46352
2019-07-03 21:28:31,963 [salt.minion      :1711][INFO    ][46352] Returning information for job: 20190703212831886961
2019-07-03 21:28:58,881 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1736.52102494s left)
2019-07-03 21:29:02,073 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212902059236
2019-07-03 21:29:02,109 [salt.minion      :1432][INFO    ][46459] Starting a new job with PID 46459
2019-07-03 21:29:02,139 [salt.minion      :1711][INFO    ][46459] Returning information for job: 20190703212902059236
2019-07-03 21:29:31,127 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1704.27533197s left)
2019-07-03 21:29:32,260 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703212932244887
2019-07-03 21:29:32,288 [salt.minion      :1432][INFO    ][46481] Starting a new job with PID 46481
2019-07-03 21:29:32,317 [salt.minion      :1711][INFO    ][46481] Returning information for job: 20190703212932244887
2019-07-03 21:30:02,433 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213002424779
2019-07-03 21:30:02,455 [salt.minion      :1432][INFO    ][46529] Starting a new job with PID 46529
2019-07-03 21:30:02,487 [salt.minion      :1711][INFO    ][46529] Returning information for job: 20190703213002424779
2019-07-03 21:30:03,115 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1672.28683305s left)
2019-07-03 21:30:32,612 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213032595390
2019-07-03 21:30:32,637 [salt.minion      :1432][INFO    ][46549] Starting a new job with PID 46549
2019-07-03 21:30:32,668 [salt.minion      :1711][INFO    ][46549] Returning information for job: 20190703213032595390
2019-07-03 21:30:35,079 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1640.32257295s left)
2019-07-03 21:31:02,801 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213102787373
2019-07-03 21:31:02,819 [salt.minion      :1432][INFO    ][46605] Starting a new job with PID 46605
2019-07-03 21:31:02,854 [salt.minion      :1711][INFO    ][46605] Returning information for job: 20190703213102787373
2019-07-03 21:31:05,321 [salt.utils.schedule:1377][INFO    ][37143] Running scheduled job: __mine_interval
2019-07-03 21:31:07,032 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1608.37009001s left)
2019-07-03 21:31:32,971 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213132959299
2019-07-03 21:31:32,999 [salt.minion      :1432][INFO    ][46641] Starting a new job with PID 46641
2019-07-03 21:31:33,057 [salt.minion      :1711][INFO    ][46641] Returning information for job: 20190703213132959299
2019-07-03 21:31:38,943 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1576.45909691s left)
2019-07-03 21:32:03,188 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213203178536
2019-07-03 21:32:03,213 [salt.minion      :1432][INFO    ][46695] Starting a new job with PID 46695
2019-07-03 21:32:03,247 [salt.minion      :1711][INFO    ][46695] Returning information for job: 20190703213203178536
2019-07-03 21:32:10,893 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1544.50914097s left)
2019-07-03 21:32:33,377 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213233362922
2019-07-03 21:32:33,406 [salt.minion      :1432][INFO    ][46748] Starting a new job with PID 46748
2019-07-03 21:32:33,438 [salt.minion      :1711][INFO    ][46748] Returning information for job: 20190703213233362922
2019-07-03 21:32:42,828 [salt.loaded.ext.module.maas:1023][INFO    ][45369] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1512.57358694s left)
2019-07-03 21:33:03,545 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command saltutil.find_job with jid 20190703213303531939
2019-07-03 21:33:03,576 [salt.minion      :1432][INFO    ][46856] Starting a new job with PID 46856
2019-07-03 21:33:03,612 [salt.minion      :1711][INFO    ][46856] Returning information for job: 20190703213303531939
2019-07-03 21:33:14,926 [salt.state       :300 ][INFO    ][45369] {'ret': True}
2019-07-03 21:33:14,927 [salt.state       :1951][INFO    ][45369] Completed state [maas.wait_for_machine_status] at time 21:33:14.927053 duration_in_ms=769542.254
2019-07-03 21:33:14,935 [salt.minion      :1711][INFO    ][45369] Returning information for job: 20190703212014935631
2019-07-03 22:26:54,971 [salt.minion      :1308][INFO    ][37143] User sudo_ubuntu Executing command cp.push_dir with jid 20190703222654959977
2019-07-03 22:26:55,001 [salt.minion      :1432][INFO    ][50917] Starting a new job with PID 50917
