2019-08-13 02:04:13,582 [salt.utils.decorators:613 ][WARNING ][2381] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:04:14,505 [salt.utils.decorators:613 ][WARNING ][2381] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:04:17,299 [salt.loaded.int.states.file:2298][WARNING ][2582] 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-08-13 02:04:32,367 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2949] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-08-13 02:04:32,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2949] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-08-13 02:04:32,434 [salt.utils.parsers:1051][WARNING ][378] Minion received a SIGTERM. Exiting.
2019-08-13 02:04:33,448 [salt.cli.daemons :293 ][INFO    ][3077] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-08-13 02:04:33,564 [salt.cli.daemons :82  ][INFO    ][3077] Starting up the Salt Minion
2019-08-13 02:04:33,565 [salt.utils.event :1017][INFO    ][3077] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-08-13 02:04:34,613 [salt.minion      :976 ][INFO    ][3077] Creating minion process manager
2019-08-13 02:04:36,568 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3077] Executing command ['date', '+%z'] in directory '/root'
2019-08-13 02:04:36,586 [salt.utils.schedule:568 ][INFO    ][3077] Updating job settings for scheduled job: __mine_interval
2019-08-13 02:04:36,588 [salt.minion      :1108][INFO    ][3077] Added mine.update to scheduler
2019-08-13 02:04:36,594 [salt.minion      :1975][INFO    ][3077] Minion is starting as user 'root'
2019-08-13 02:04:36,608 [salt.minion      :2336][INFO    ][3077] Minion is ready to receive requests!
2019-08-13 02:04:41,441 [salt.state       :2022][WARNING ][2953] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-13 02:04:44,534 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:04:45,240 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020445226965
2019-08-13 02:04:45,263 [salt.minion      :1432][INFO    ][3617] Starting a new job with PID 3617
2019-08-13 02:04:45,295 [salt.minion      :1711][INFO    ][3617] Returning information for job: 20190813020445226965
2019-08-13 02:05:15,372 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020515360772
2019-08-13 02:05:15,392 [salt.minion      :1432][INFO    ][4006] Starting a new job with PID 4006
2019-08-13 02:05:15,413 [salt.minion      :1711][INFO    ][4006] Returning information for job: 20190813020515360772
2019-08-13 02:05:45,442 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020545430584
2019-08-13 02:05:45,461 [salt.minion      :1432][INFO    ][4200] Starting a new job with PID 4200
2019-08-13 02:05:45,480 [salt.minion      :1711][INFO    ][4200] Returning information for job: 20190813020545430584
2019-08-13 02:06:15,487 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020615476908
2019-08-13 02:06:15,512 [salt.minion      :1432][INFO    ][4418] Starting a new job with PID 4418
2019-08-13 02:06:15,532 [salt.minion      :1711][INFO    ][4418] Returning information for job: 20190813020615476908
2019-08-13 02:06:45,575 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020645568027
2019-08-13 02:06:45,594 [salt.minion      :1432][INFO    ][4631] Starting a new job with PID 4631
2019-08-13 02:06:45,613 [salt.minion      :1711][INFO    ][4631] Returning information for job: 20190813020645568027
2019-08-13 02:07:15,682 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020715668206
2019-08-13 02:07:15,701 [salt.minion      :1432][INFO    ][4881] Starting a new job with PID 4881
2019-08-13 02:07:15,723 [salt.minion      :1711][INFO    ][4881] Returning information for job: 20190813020715668206
2019-08-13 02:07:45,807 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020745796012
2019-08-13 02:07:45,824 [salt.minion      :1432][INFO    ][5112] Starting a new job with PID 5112
2019-08-13 02:07:45,847 [salt.minion      :1711][INFO    ][5112] Returning information for job: 20190813020745796012
2019-08-13 02:08:15,934 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020815919730
2019-08-13 02:08:15,960 [salt.minion      :1432][INFO    ][5326] Starting a new job with PID 5326
2019-08-13 02:08:15,983 [salt.minion      :1711][INFO    ][5326] Returning information for job: 20190813020815919730
2019-08-13 02:08:46,088 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020846073587
2019-08-13 02:08:46,117 [salt.minion      :1432][INFO    ][5567] Starting a new job with PID 5567
2019-08-13 02:08:46,140 [salt.minion      :1711][INFO    ][5567] Returning information for job: 20190813020846073587
2019-08-13 02:09:16,205 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020916190541
2019-08-13 02:09:16,228 [salt.minion      :1432][INFO    ][5810] Starting a new job with PID 5810
2019-08-13 02:09:16,249 [salt.minion      :1711][INFO    ][5810] Returning information for job: 20190813020916190541
2019-08-13 02:09:46,339 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813020946324964
2019-08-13 02:09:46,365 [salt.minion      :1432][INFO    ][6048] Starting a new job with PID 6048
2019-08-13 02:09:46,389 [salt.minion      :1711][INFO    ][6048] Returning information for job: 20190813020946324964
2019-08-13 02:10:16,493 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021016476785
2019-08-13 02:10:16,508 [salt.minion      :1432][INFO    ][6305] Starting a new job with PID 6305
2019-08-13 02:10:16,531 [salt.minion      :1711][INFO    ][6305] Returning information for job: 20190813021016476785
2019-08-13 02:10:46,628 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021046615777
2019-08-13 02:10:46,652 [salt.minion      :1432][INFO    ][6566] Starting a new job with PID 6566
2019-08-13 02:10:46,676 [salt.minion      :1711][INFO    ][6566] Returning information for job: 20190813021046615777
2019-08-13 02:11:16,782 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021116770227
2019-08-13 02:11:16,807 [salt.minion      :1432][INFO    ][6779] Starting a new job with PID 6779
2019-08-13 02:11:16,828 [salt.minion      :1711][INFO    ][6779] Returning information for job: 20190813021116770227
2019-08-13 02:11:46,928 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021146917396
2019-08-13 02:11:46,952 [salt.minion      :1432][INFO    ][7018] Starting a new job with PID 7018
2019-08-13 02:11:46,974 [salt.minion      :1711][INFO    ][7018] Returning information for job: 20190813021146917396
2019-08-13 02:12:17,071 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021217059495
2019-08-13 02:12:17,096 [salt.minion      :1432][INFO    ][7237] Starting a new job with PID 7237
2019-08-13 02:12:17,118 [salt.minion      :1711][INFO    ][7237] Returning information for job: 20190813021217059495
2019-08-13 02:12:47,243 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021247228380
2019-08-13 02:12:47,267 [salt.minion      :1432][INFO    ][7462] Starting a new job with PID 7462
2019-08-13 02:12:47,292 [salt.minion      :1711][INFO    ][7462] Returning information for job: 20190813021247228380
2019-08-13 02:13:17,416 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021317403027
2019-08-13 02:13:17,436 [salt.minion      :1432][INFO    ][7690] Starting a new job with PID 7690
2019-08-13 02:13:17,464 [salt.minion      :1711][INFO    ][7690] Returning information for job: 20190813021317403027
2019-08-13 02:13:47,580 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021347567780
2019-08-13 02:13:47,604 [salt.minion      :1432][INFO    ][7911] Starting a new job with PID 7911
2019-08-13 02:13:47,627 [salt.minion      :1711][INFO    ][7911] Returning information for job: 20190813021347567780
2019-08-13 02:14:17,765 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021417747437
2019-08-13 02:14:17,792 [salt.minion      :1432][INFO    ][8131] Starting a new job with PID 8131
2019-08-13 02:14:17,814 [salt.minion      :1711][INFO    ][8131] Returning information for job: 20190813021417747437
2019-08-13 02:14:47,947 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021447934130
2019-08-13 02:14:47,972 [salt.minion      :1432][INFO    ][8370] Starting a new job with PID 8370
2019-08-13 02:14:47,996 [salt.minion      :1711][INFO    ][8370] Returning information for job: 20190813021447934130
2019-08-13 02:15:18,129 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021518119386
2019-08-13 02:15:18,151 [salt.minion      :1432][INFO    ][8574] Starting a new job with PID 8574
2019-08-13 02:15:18,173 [salt.minion      :1711][INFO    ][8574] Returning information for job: 20190813021518119386
2019-08-13 02:15:48,308 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021548291929
2019-08-13 02:15:48,334 [salt.minion      :1432][INFO    ][8810] Starting a new job with PID 8810
2019-08-13 02:15:48,357 [salt.minion      :1711][INFO    ][8810] Returning information for job: 20190813021548291929
2019-08-13 02:16:18,499 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021618484045
2019-08-13 02:16:18,525 [salt.minion      :1432][INFO    ][8997] Starting a new job with PID 8997
2019-08-13 02:16:18,547 [salt.minion      :1711][INFO    ][8997] Returning information for job: 20190813021618484045
2019-08-13 02:16:48,691 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021648677502
2019-08-13 02:16:48,713 [salt.minion      :1432][INFO    ][9243] Starting a new job with PID 9243
2019-08-13 02:16:48,735 [salt.minion      :1711][INFO    ][9243] Returning information for job: 20190813021648677502
2019-08-13 02:17:18,908 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021718895999
2019-08-13 02:17:18,934 [salt.minion      :1432][INFO    ][9461] Starting a new job with PID 9461
2019-08-13 02:17:18,957 [salt.minion      :1711][INFO    ][9461] Returning information for job: 20190813021718895999
2019-08-13 02:17:49,115 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021749100613
2019-08-13 02:17:49,141 [salt.minion      :1432][INFO    ][9739] Starting a new job with PID 9739
2019-08-13 02:17:49,168 [salt.minion      :1711][INFO    ][9739] Returning information for job: 20190813021749100613
2019-08-13 02:18:19,139 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021819128029
2019-08-13 02:18:19,158 [salt.minion      :1432][INFO    ][9959] Starting a new job with PID 9959
2019-08-13 02:18:19,177 [salt.minion      :1711][INFO    ][9959] Returning information for job: 20190813021819128029
2019-08-13 02:18:49,365 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021849352863
2019-08-13 02:18:49,388 [salt.minion      :1432][INFO    ][10208] Starting a new job with PID 10208
2019-08-13 02:18:49,414 [salt.minion      :1711][INFO    ][10208] Returning information for job: 20190813021849352863
2019-08-13 02:19:19,408 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021919392092
2019-08-13 02:19:19,437 [salt.minion      :1432][INFO    ][10424] Starting a new job with PID 10424
2019-08-13 02:19:19,458 [salt.minion      :1711][INFO    ][10424] Returning information for job: 20190813021919392092
2019-08-13 02:19:49,476 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813021949465650
2019-08-13 02:19:49,496 [salt.minion      :1432][INFO    ][10687] Starting a new job with PID 10687
2019-08-13 02:19:49,518 [salt.minion      :1711][INFO    ][10687] Returning information for job: 20190813021949465650
2019-08-13 02:19:56,948 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:20:19,539 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022019522849
2019-08-13 02:20:19,567 [salt.minion      :1432][INFO    ][10911] Starting a new job with PID 10911
2019-08-13 02:20:19,599 [salt.minion      :1711][INFO    ][10911] Returning information for job: 20190813022019522849
2019-08-13 02:20:49,631 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022049619426
2019-08-13 02:20:49,654 [salt.minion      :1432][INFO    ][11166] Starting a new job with PID 11166
2019-08-13 02:20:49,683 [salt.minion      :1711][INFO    ][11166] Returning information for job: 20190813022049619426
2019-08-13 02:21:19,714 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022119698481
2019-08-13 02:21:19,739 [salt.minion      :1432][INFO    ][11397] Starting a new job with PID 11397
2019-08-13 02:21:19,762 [salt.minion      :1711][INFO    ][11397] Returning information for job: 20190813022119698481
2019-08-13 02:21:49,817 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022149803876
2019-08-13 02:21:49,843 [salt.minion      :1432][INFO    ][11654] Starting a new job with PID 11654
2019-08-13 02:21:49,865 [salt.minion      :1711][INFO    ][11654] Returning information for job: 20190813022149803876
2019-08-13 02:22:19,933 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022219923156
2019-08-13 02:22:19,956 [salt.minion      :1432][INFO    ][11883] Starting a new job with PID 11883
2019-08-13 02:22:19,978 [salt.minion      :1711][INFO    ][11883] Returning information for job: 20190813022219923156
2019-08-13 02:22:50,087 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022250075790
2019-08-13 02:22:50,115 [salt.minion      :1432][INFO    ][12146] Starting a new job with PID 12146
2019-08-13 02:22:50,143 [salt.minion      :1711][INFO    ][12146] Returning information for job: 20190813022250075790
2019-08-13 02:23:20,237 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022320224363
2019-08-13 02:23:20,268 [salt.minion      :1432][INFO    ][12355] Starting a new job with PID 12355
2019-08-13 02:23:20,292 [salt.minion      :1711][INFO    ][12355] Returning information for job: 20190813022320224363
2019-08-13 02:23:50,424 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022350411968
2019-08-13 02:23:50,451 [salt.minion      :1432][INFO    ][12622] Starting a new job with PID 12622
2019-08-13 02:23:50,481 [salt.minion      :1711][INFO    ][12622] Returning information for job: 20190813022350411968
2019-08-13 02:24:20,575 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022420566708
2019-08-13 02:24:20,590 [salt.minion      :1432][INFO    ][12840] Starting a new job with PID 12840
2019-08-13 02:24:20,611 [salt.minion      :1711][INFO    ][12840] Returning information for job: 20190813022420566708
2019-08-13 02:24:50,712 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022450704433
2019-08-13 02:24:50,729 [salt.minion      :1432][INFO    ][13140] Starting a new job with PID 13140
2019-08-13 02:24:50,752 [salt.minion      :1711][INFO    ][13140] Returning information for job: 20190813022450704433
2019-08-13 02:25:20,797 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022520788720
2019-08-13 02:25:20,820 [salt.minion      :1432][INFO    ][13356] Starting a new job with PID 13356
2019-08-13 02:25:20,843 [salt.minion      :1711][INFO    ][13356] Returning information for job: 20190813022520788720
2019-08-13 02:25:50,935 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022550925684
2019-08-13 02:25:50,953 [salt.minion      :1432][INFO    ][13599] Starting a new job with PID 13599
2019-08-13 02:25:50,979 [salt.minion      :1711][INFO    ][13599] Returning information for job: 20190813022550925684
2019-08-13 02:26:21,124 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022621108775
2019-08-13 02:26:21,152 [salt.minion      :1432][INFO    ][13892] Starting a new job with PID 13892
2019-08-13 02:26:21,175 [salt.minion      :1711][INFO    ][13892] Returning information for job: 20190813022621108775
2019-08-13 02:26:51,152 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022651139011
2019-08-13 02:26:51,235 [salt.minion      :1432][INFO    ][14100] Starting a new job with PID 14100
2019-08-13 02:26:51,255 [salt.minion      :1711][INFO    ][14100] Returning information for job: 20190813022651139011
2019-08-13 02:27:21,271 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022721263108
2019-08-13 02:27:21,300 [salt.minion      :1432][INFO    ][14281] Starting a new job with PID 14281
2019-08-13 02:27:21,323 [salt.minion      :1711][INFO    ][14281] Returning information for job: 20190813022721263108
2019-08-13 02:27:51,319 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022751309155
2019-08-13 02:27:51,341 [salt.minion      :1432][INFO    ][14519] Starting a new job with PID 14519
2019-08-13 02:27:51,364 [salt.minion      :1711][INFO    ][14519] Returning information for job: 20190813022751309155
2019-08-13 02:28:21,449 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022821435598
2019-08-13 02:28:21,473 [salt.minion      :1432][INFO    ][14710] Starting a new job with PID 14710
2019-08-13 02:28:21,501 [salt.minion      :1711][INFO    ][14710] Returning information for job: 20190813022821435598
2019-08-13 02:28:51,552 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022851540045
2019-08-13 02:28:51,581 [salt.minion      :1432][INFO    ][14959] Starting a new job with PID 14959
2019-08-13 02:28:51,611 [salt.minion      :1711][INFO    ][14959] Returning information for job: 20190813022851540045
2019-08-13 02:29:21,716 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022921704711
2019-08-13 02:29:21,736 [salt.minion      :1432][INFO    ][15168] Starting a new job with PID 15168
2019-08-13 02:29:21,765 [salt.minion      :1711][INFO    ][15168] Returning information for job: 20190813022921704711
2019-08-13 02:29:51,868 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813022951855471
2019-08-13 02:29:51,895 [salt.minion      :1432][INFO    ][15408] Starting a new job with PID 15408
2019-08-13 02:29:51,925 [salt.minion      :1711][INFO    ][15408] Returning information for job: 20190813022951855471
2019-08-13 02:30:22,086 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023022069129
2019-08-13 02:30:22,104 [salt.minion      :1432][INFO    ][15629] Starting a new job with PID 15629
2019-08-13 02:30:22,134 [salt.minion      :1711][INFO    ][15629] Returning information for job: 20190813023022069129
2019-08-13 02:30:52,268 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023052259121
2019-08-13 02:30:52,290 [salt.minion      :1432][INFO    ][15878] Starting a new job with PID 15878
2019-08-13 02:30:52,319 [salt.minion      :1711][INFO    ][15878] Returning information for job: 20190813023052259121
2019-08-13 02:31:22,489 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023122474521
2019-08-13 02:31:22,513 [salt.minion      :1432][INFO    ][16108] Starting a new job with PID 16108
2019-08-13 02:31:22,543 [salt.minion      :1711][INFO    ][16108] Returning information for job: 20190813023122474521
2019-08-13 02:31:52,563 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023152553236
2019-08-13 02:31:52,590 [salt.minion      :1432][INFO    ][16367] Starting a new job with PID 16367
2019-08-13 02:31:52,620 [salt.minion      :1711][INFO    ][16367] Returning information for job: 20190813023152553236
2019-08-13 02:32:22,581 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023222571167
2019-08-13 02:32:22,605 [salt.minion      :1432][INFO    ][16613] Starting a new job with PID 16613
2019-08-13 02:32:22,632 [salt.minion      :1711][INFO    ][16613] Returning information for job: 20190813023222571167
2019-08-13 02:32:52,616 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023252604199
2019-08-13 02:32:52,643 [salt.minion      :1432][INFO    ][16878] Starting a new job with PID 16878
2019-08-13 02:32:52,677 [salt.minion      :1711][INFO    ][16878] Returning information for job: 20190813023252604199
2019-08-13 02:33:22,688 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023322678751
2019-08-13 02:33:22,714 [salt.minion      :1432][INFO    ][17076] Starting a new job with PID 17076
2019-08-13 02:33:22,744 [salt.minion      :1711][INFO    ][17076] Returning information for job: 20190813023322678751
2019-08-13 02:33:52,792 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023352780806
2019-08-13 02:33:52,819 [salt.minion      :1432][INFO    ][17325] Starting a new job with PID 17325
2019-08-13 02:33:52,851 [salt.minion      :1711][INFO    ][17325] Returning information for job: 20190813023352780806
2019-08-13 02:34:22,864 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023422850573
2019-08-13 02:34:22,884 [salt.minion      :1432][INFO    ][17519] Starting a new job with PID 17519
2019-08-13 02:34:22,916 [salt.minion      :1711][INFO    ][17519] Returning information for job: 20190813023422850573
2019-08-13 02:34:53,000 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023452988558
2019-08-13 02:34:53,017 [salt.minion      :1432][INFO    ][17775] Starting a new job with PID 17775
2019-08-13 02:34:53,052 [salt.minion      :1711][INFO    ][17775] Returning information for job: 20190813023452988558
2019-08-13 02:35:23,118 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023523104114
2019-08-13 02:35:23,142 [salt.minion      :1432][INFO    ][18008] Starting a new job with PID 18008
2019-08-13 02:35:23,170 [salt.minion      :1711][INFO    ][18008] Returning information for job: 20190813023523104114
2019-08-13 02:35:53,321 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023553307181
2019-08-13 02:35:53,350 [salt.minion      :1432][INFO    ][18246] Starting a new job with PID 18246
2019-08-13 02:35:53,385 [salt.minion      :1711][INFO    ][18246] Returning information for job: 20190813023553307181
2019-08-13 02:36:23,520 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023623512631
2019-08-13 02:36:23,542 [salt.minion      :1432][INFO    ][18463] Starting a new job with PID 18463
2019-08-13 02:36:23,572 [salt.minion      :1711][INFO    ][18463] Returning information for job: 20190813023623512631
2019-08-13 02:36:53,741 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023653724717
2019-08-13 02:36:53,767 [salt.minion      :1432][INFO    ][18676] Starting a new job with PID 18676
2019-08-13 02:36:53,799 [salt.minion      :1711][INFO    ][18676] Returning information for job: 20190813023653724717
2019-08-13 02:37:23,792 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023723780240
2019-08-13 02:37:23,815 [salt.minion      :1432][INFO    ][18877] Starting a new job with PID 18877
2019-08-13 02:37:23,842 [salt.minion      :1711][INFO    ][18877] Returning information for job: 20190813023723780240
2019-08-13 02:37:53,821 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023753806602
2019-08-13 02:37:53,842 [salt.minion      :1432][INFO    ][19125] Starting a new job with PID 19125
2019-08-13 02:37:53,876 [salt.minion      :1711][INFO    ][19125] Returning information for job: 20190813023753806602
2019-08-13 02:38:23,856 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023823843078
2019-08-13 02:38:23,878 [salt.minion      :1432][INFO    ][19327] Starting a new job with PID 19327
2019-08-13 02:38:23,913 [salt.minion      :1711][INFO    ][19327] Returning information for job: 20190813023823843078
2019-08-13 02:38:53,887 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023853877462
2019-08-13 02:38:53,911 [salt.minion      :1432][INFO    ][19544] Starting a new job with PID 19544
2019-08-13 02:38:53,941 [salt.minion      :1711][INFO    ][19544] Returning information for job: 20190813023853877462
2019-08-13 02:38:56,311 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:39:24,031 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023924020916
2019-08-13 02:39:24,054 [salt.minion      :1432][INFO    ][19593] Starting a new job with PID 19593
2019-08-13 02:39:24,089 [salt.minion      :1711][INFO    ][19593] Returning information for job: 20190813023924020916
2019-08-13 02:39:54,137 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813023954120497
2019-08-13 02:39:54,162 [salt.minion      :1432][INFO    ][19667] Starting a new job with PID 19667
2019-08-13 02:39:54,191 [salt.minion      :1711][INFO    ][19667] Returning information for job: 20190813023954120497
2019-08-13 02:40:24,345 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024024330656
2019-08-13 02:40:24,368 [salt.minion      :1432][INFO    ][19701] Starting a new job with PID 19701
2019-08-13 02:40:24,405 [salt.minion      :1711][INFO    ][19701] Returning information for job: 20190813024024330656
2019-08-13 02:40:54,509 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024054493104
2019-08-13 02:40:54,532 [salt.minion      :1432][INFO    ][19781] Starting a new job with PID 19781
2019-08-13 02:40:54,563 [salt.minion      :1711][INFO    ][19781] Returning information for job: 20190813024054493104
2019-08-13 02:41:24,727 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024124712783
2019-08-13 02:41:24,751 [salt.minion      :1432][INFO    ][19815] Starting a new job with PID 19815
2019-08-13 02:41:24,781 [salt.minion      :1711][INFO    ][19815] Returning information for job: 20190813024124712783
2019-08-13 02:41:54,872 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024154860250
2019-08-13 02:41:54,896 [salt.minion      :1432][INFO    ][19892] Starting a new job with PID 19892
2019-08-13 02:41:54,923 [salt.minion      :1711][INFO    ][19892] Returning information for job: 20190813024154860250
2019-08-13 02:42:24,949 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024224939062
2019-08-13 02:42:24,970 [salt.minion      :1432][INFO    ][19930] Starting a new job with PID 19930
2019-08-13 02:42:24,998 [salt.minion      :1711][INFO    ][19930] Returning information for job: 20190813024224939062
2019-08-13 02:42:55,019 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024255009669
2019-08-13 02:42:55,044 [salt.minion      :1432][INFO    ][20004] Starting a new job with PID 20004
2019-08-13 02:42:55,075 [salt.minion      :1711][INFO    ][20004] Returning information for job: 20190813024255009669
2019-08-13 02:43:25,049 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024325034878
2019-08-13 02:43:25,067 [salt.minion      :1432][INFO    ][20044] Starting a new job with PID 20044
2019-08-13 02:43:25,101 [salt.minion      :1711][INFO    ][20044] Returning information for job: 20190813024325034878
2019-08-13 02:43:55,168 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024355152326
2019-08-13 02:43:55,187 [salt.minion      :1432][INFO    ][20121] Starting a new job with PID 20121
2019-08-13 02:43:55,218 [salt.minion      :1711][INFO    ][20121] Returning information for job: 20190813024355152326
2019-08-13 02:44:25,364 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024425351933
2019-08-13 02:44:25,388 [salt.minion      :1432][INFO    ][20167] Starting a new job with PID 20167
2019-08-13 02:44:25,416 [salt.minion      :1711][INFO    ][20167] Returning information for job: 20190813024425351933
2019-08-13 02:44:55,395 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024455384576
2019-08-13 02:44:55,414 [salt.minion      :1432][INFO    ][20253] Starting a new job with PID 20253
2019-08-13 02:44:55,445 [salt.minion      :1711][INFO    ][20253] Returning information for job: 20190813024455384576
2019-08-13 02:45:25,521 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024525510116
2019-08-13 02:45:25,542 [salt.minion      :1432][INFO    ][20299] Starting a new job with PID 20299
2019-08-13 02:45:25,571 [salt.minion      :1711][INFO    ][20299] Returning information for job: 20190813024525510116
2019-08-13 02:45:55,674 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024555657679
2019-08-13 02:45:55,699 [salt.minion      :1432][INFO    ][20373] Starting a new job with PID 20373
2019-08-13 02:45:55,732 [salt.minion      :1711][INFO    ][20373] Returning information for job: 20190813024555657679
2019-08-13 02:46:25,760 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024625744840
2019-08-13 02:46:25,781 [salt.minion      :1432][INFO    ][20414] Starting a new job with PID 20414
2019-08-13 02:46:25,810 [salt.minion      :1711][INFO    ][20414] Returning information for job: 20190813024625744840
2019-08-13 02:46:55,785 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024655776613
2019-08-13 02:46:55,807 [salt.minion      :1432][INFO    ][20481] Starting a new job with PID 20481
2019-08-13 02:46:55,836 [salt.minion      :1711][INFO    ][20481] Returning information for job: 20190813024655776613
2019-08-13 02:47:25,869 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024725856289
2019-08-13 02:47:25,895 [salt.minion      :1432][INFO    ][20631] Starting a new job with PID 20631
2019-08-13 02:47:25,927 [salt.minion      :1711][INFO    ][20631] Returning information for job: 20190813024725856289
2019-08-13 02:47:55,927 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024755912613
2019-08-13 02:47:55,950 [salt.minion      :1432][INFO    ][20692] Starting a new job with PID 20692
2019-08-13 02:47:55,980 [salt.minion      :1711][INFO    ][20692] Returning information for job: 20190813024755912613
2019-08-13 02:48:25,973 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024825965399
2019-08-13 02:48:25,992 [salt.minion      :1432][INFO    ][20718] Starting a new job with PID 20718
2019-08-13 02:48:26,025 [salt.minion      :1711][INFO    ][20718] Returning information for job: 20190813024825965399
2019-08-13 02:48:56,140 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024856127183
2019-08-13 02:48:56,165 [salt.minion      :1432][INFO    ][20781] Starting a new job with PID 20781
2019-08-13 02:48:56,197 [salt.minion      :1711][INFO    ][20781] Returning information for job: 20190813024856127183
2019-08-13 02:49:26,252 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024926235958
2019-08-13 02:49:26,279 [salt.minion      :1432][INFO    ][20807] Starting a new job with PID 20807
2019-08-13 02:49:26,311 [salt.minion      :1711][INFO    ][20807] Returning information for job: 20190813024926235958
2019-08-13 02:49:56,296 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813024956282841
2019-08-13 02:49:56,323 [salt.minion      :1432][INFO    ][20873] Starting a new job with PID 20873
2019-08-13 02:49:56,355 [salt.minion      :1711][INFO    ][20873] Returning information for job: 20190813024956282841
2019-08-13 02:50:26,408 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025026391689
2019-08-13 02:50:26,434 [salt.minion      :1432][INFO    ][20899] Starting a new job with PID 20899
2019-08-13 02:50:26,463 [salt.minion      :1711][INFO    ][20899] Returning information for job: 20190813025026391689
2019-08-13 02:50:56,552 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025056541017
2019-08-13 02:50:56,579 [salt.minion      :1432][INFO    ][20962] Starting a new job with PID 20962
2019-08-13 02:50:56,610 [salt.minion      :1711][INFO    ][20962] Returning information for job: 20190813025056541017
2019-08-13 02:51:26,718 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025126707271
2019-08-13 02:51:26,742 [salt.minion      :1432][INFO    ][20988] Starting a new job with PID 20988
2019-08-13 02:51:26,773 [salt.minion      :1711][INFO    ][20988] Returning information for job: 20190813025126707271
2019-08-13 02:51:56,804 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025156787594
2019-08-13 02:51:56,831 [salt.minion      :1432][INFO    ][21052] Starting a new job with PID 21052
2019-08-13 02:51:56,862 [salt.minion      :1711][INFO    ][21052] Returning information for job: 20190813025156787594
2019-08-13 02:52:27,011 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025226994841
2019-08-13 02:52:27,036 [salt.minion      :1432][INFO    ][21078] Starting a new job with PID 21078
2019-08-13 02:52:27,067 [salt.minion      :1711][INFO    ][21078] Returning information for job: 20190813025226994841
2019-08-13 02:52:57,042 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025257029962
2019-08-13 02:52:57,071 [salt.minion      :1432][INFO    ][21144] Starting a new job with PID 21144
2019-08-13 02:52:57,099 [salt.minion      :1711][INFO    ][21144] Returning information for job: 20190813025257029962
2019-08-13 02:53:27,138 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025327127222
2019-08-13 02:53:27,165 [salt.minion      :1432][INFO    ][21169] Starting a new job with PID 21169
2019-08-13 02:53:27,195 [salt.minion      :1711][INFO    ][21169] Returning information for job: 20190813025327127222
2019-08-13 02:53:57,188 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025357176893
2019-08-13 02:53:57,210 [salt.minion      :1432][INFO    ][21233] Starting a new job with PID 21233
2019-08-13 02:53:57,244 [salt.minion      :1711][INFO    ][21233] Returning information for job: 20190813025357176893
2019-08-13 02:54:00,887 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:54:03,508 [salt.loaded.ext.module.maasng:1008][WARNING ][2953] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-08-13 02:54:03,508 [salt.loaded.ext.module.maasng:1011][WARNING ][2953] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-08-13 02:54:04,240 [salt.loaded.ext.module.maasng:1235][WARNING ][2953] Ignoring parameter vlan:0
2019-08-13 02:54:06,741 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813025406729492
2019-08-13 02:54:06,768 [salt.minion      :1432][INFO    ][21348] Starting a new job with PID 21348
2019-08-13 02:54:14,249 [salt.state       :915 ][INFO    ][21348] Loading fresh modules for state activity
2019-08-13 02:54:14,360 [salt.fileclient  :1219][INFO    ][21348] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-08-13 02:54:14,434 [salt.state       :1780][INFO    ][21348] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:54:14.434526
2019-08-13 02:54:14,435 [salt.state       :1813][INFO    ][21348] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 02:54:14,440 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21348] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 02:54:16,798 [salt.state       :300 ][INFO    ][21348] {'pid': 21359, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 02:54:16,799 [salt.state       :1951][INFO    ][21348] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:54:16.799795 duration_in_ms=2365.268
2019-08-13 02:54:16,804 [salt.state       :1780][INFO    ][21348] Running state [maas.process_machines] at time 02:54:16.804310
2019-08-13 02:54:16,805 [salt.state       :1813][INFO    ][21348] Executing state module.run for [maas.process_machines]
2019-08-13 02:54:16,806 [salt.utils.decorators:613 ][WARNING ][21348] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:54:16,906 [salt.loaded.ext.module.maas:412 ][WARNING ][21348] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 02:54:16,907 [salt.loaded.ext.module.maas:92  ][INFO    ][21348] 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 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 02:54:21,371 [salt.loaded.ext.module.maas:412 ][WARNING ][21348] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 02:54:21,371 [salt.loaded.ext.module.maas:92  ][INFO    ][21348] 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 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 02:54:21,764 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025421753380
2019-08-13 02:54:21,792 [salt.minion      :1432][INFO    ][21422] Starting a new job with PID 21422
2019-08-13 02:54:21,825 [salt.minion      :1711][INFO    ][21422] Returning information for job: 20190813025421753380
2019-08-13 02:54:25,737 [salt.loaded.ext.module.maas:412 ][WARNING ][21348] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 02:54:25,737 [salt.loaded.ext.module.maas:92  ][INFO    ][21348] machine hostname=kvm01 power_type=ipmi mac_addresses=14:58:d0:54:e7:88 power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 02:54:30,141 [salt.loaded.ext.module.maas:412 ][WARNING ][21348] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 02:54:30,142 [salt.loaded.ext.module.maas:92  ][INFO    ][21348] machine hostname=kvm03 power_type=ipmi mac_addresses=14:58:d0:54:7a:28 power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 02:54:34,620 [salt.loaded.ext.module.maas:412 ][WARNING ][21348] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 02:54:34,621 [salt.loaded.ext.module.maas:92  ][INFO    ][21348] machine hostname=kvm02 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 02:54:39,969 [salt.state       :300 ][INFO    ][21348] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-08-13 02:54:39,970 [salt.state       :1951][INFO    ][21348] Completed state [maas.process_machines] at time 02:54:39.969686 duration_in_ms=23165.376
2019-08-13 02:54:39,973 [salt.minion      :1711][INFO    ][21348] Returning information for job: 20190813025406729492
2019-08-13 02:55:11,532 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813025511523121
2019-08-13 02:55:11,552 [salt.minion      :1432][INFO    ][21756] Starting a new job with PID 21756
2019-08-13 02:55:18,167 [salt.state       :915 ][INFO    ][21756] Loading fresh modules for state activity
2019-08-13 02:55:18,239 [salt.fileclient  :1219][INFO    ][21756] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-08-13 02:55:18,292 [salt.state       :1780][INFO    ][21756] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:55:18.291933
2019-08-13 02:55:18,292 [salt.state       :1813][INFO    ][21756] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 02:55:18,295 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21756] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 02:55:20,291 [salt.state       :300 ][INFO    ][21756] {'pid': 21769, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 02:55:20,292 [salt.state       :1951][INFO    ][21756] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 02:55:20.292302 duration_in_ms=2000.369
2019-08-13 02:55:20,297 [salt.state       :1780][INFO    ][21756] Running state [maas.wait_for_machine_status] at time 02:55:20.297507
2019-08-13 02:55:20,298 [salt.state       :1813][INFO    ][21756] Executing state module.run for [maas.wait_for_machine_status]
2019-08-13 02:55:20,299 [salt.utils.decorators:613 ][WARNING ][21756] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 02:55:21,148 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.16920185s left)
2019-08-13 02:55:26,584 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025526567498
2019-08-13 02:55:26,602 [salt.minion      :1432][INFO    ][21784] Starting a new job with PID 21784
2019-08-13 02:55:26,632 [salt.minion      :1711][INFO    ][21784] Returning information for job: 20190813025526567498
2019-08-13 02:55:51,965 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.35255599s left)
2019-08-13 02:55:56,804 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025556795276
2019-08-13 02:55:56,824 [salt.minion      :1432][INFO    ][21849] Starting a new job with PID 21849
2019-08-13 02:55:56,851 [salt.minion      :1711][INFO    ][21849] Returning information for job: 20190813025556795276
2019-08-13 02:56:22,834 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.48301792s left)
2019-08-13 02:56:26,848 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025626835182
2019-08-13 02:56:26,866 [salt.minion      :1432][INFO    ][21888] Starting a new job with PID 21888
2019-08-13 02:56:26,896 [salt.minion      :1711][INFO    ][21888] Returning information for job: 20190813025626835182
2019-08-13 02:56:53,648 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.66894984s left)
2019-08-13 02:56:56,896 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025656880052
2019-08-13 02:56:56,917 [salt.minion      :1432][INFO    ][21976] Starting a new job with PID 21976
2019-08-13 02:56:56,952 [salt.minion      :1711][INFO    ][21976] Returning information for job: 20190813025656880052
2019-08-13 02:57:24,778 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.53898787s left)
2019-08-13 02:57:26,936 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025726927258
2019-08-13 02:57:26,959 [salt.minion      :1432][INFO    ][22050] Starting a new job with PID 22050
2019-08-13 02:57:26,995 [salt.minion      :1711][INFO    ][22050] Returning information for job: 20190813025726927258
2019-08-13 02:57:55,908 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.40901899s left)
2019-08-13 02:57:57,028 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025757016184
2019-08-13 02:57:57,046 [salt.minion      :1432][INFO    ][22269] Starting a new job with PID 22269
2019-08-13 02:57:57,080 [salt.minion      :1711][INFO    ][22269] Returning information for job: 20190813025757016184
2019-08-13 02:58:27,108 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025827092679
2019-08-13 02:58:27,131 [salt.minion      :1432][INFO    ][22342] Starting a new job with PID 22342
2019-08-13 02:58:27,166 [salt.minion      :1711][INFO    ][22342] Returning information for job: 20190813025827092679
2019-08-13 02:58:27,486 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1312.83089185s left)
2019-08-13 02:58:57,224 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025857214447
2019-08-13 02:58:57,244 [salt.minion      :1432][INFO    ][22643] Starting a new job with PID 22643
2019-08-13 02:58:57,271 [salt.minion      :1711][INFO    ][22643] Returning information for job: 20190813025857214447
2019-08-13 02:58:59,423 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1280.89441395s left)
2019-08-13 02:59:27,332 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025927318472
2019-08-13 02:59:27,359 [salt.minion      :1432][INFO    ][22796] Starting a new job with PID 22796
2019-08-13 02:59:27,405 [salt.minion      :1711][INFO    ][22796] Returning information for job: 20190813025927318472
2019-08-13 02:59:31,729 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1248.58845878s left)
2019-08-13 02:59:57,500 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813025957485348
2019-08-13 02:59:57,526 [salt.minion      :1432][INFO    ][23301] Starting a new job with PID 23301
2019-08-13 02:59:57,563 [salt.minion      :1711][INFO    ][23301] Returning information for job: 20190813025957485348
2019-08-13 03:00:03,874 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1216.44287777s left)
2019-08-13 03:00:27,570 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030027554811
2019-08-13 03:00:27,592 [salt.minion      :1432][INFO    ][23339] Starting a new job with PID 23339
2019-08-13 03:00:27,620 [salt.minion      :1711][INFO    ][23339] Returning information for job: 20190813030027554811
2019-08-13 03:00:36,414 [salt.loaded.ext.module.maas:1023][INFO    ][21756] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1183.90801978s left)
2019-08-13 03:00:57,680 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030057669586
2019-08-13 03:00:57,705 [salt.minion      :1432][INFO    ][23538] Starting a new job with PID 23538
2019-08-13 03:00:57,736 [salt.minion      :1711][INFO    ][23538] Returning information for job: 20190813030057669586
2019-08-13 03:01:09,436 [salt.state       :300 ][INFO    ][21756] {'ret': True}
2019-08-13 03:01:09,437 [salt.state       :1951][INFO    ][21756] Completed state [maas.wait_for_machine_status] at time 03:01:09.436667 duration_in_ms=349139.16
2019-08-13 03:01:09,439 [salt.minion      :1711][INFO    ][21756] Returning information for job: 20190813025511523121
2019-08-13 03:01:10,188 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813030110176339
2019-08-13 03:01:10,210 [salt.minion      :1432][INFO    ][23568] Starting a new job with PID 23568
2019-08-13 03:01:16,806 [salt.state       :915 ][INFO    ][23568] Loading fresh modules for state activity
2019-08-13 03:01:16,873 [salt.fileclient  :1219][INFO    ][23568] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-08-13 03:01:16,989 [salt.state       :1780][INFO    ][23568] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:16.989012
2019-08-13 03:01:16,989 [salt.state       :1813][INFO    ][23568] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:01:16,991 [salt.loaded.int.module.cmdmod:395 ][INFO    ][23568] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:01:18,948 [salt.state       :300 ][INFO    ][23568] {'pid': 23591, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:01:18,951 [salt.state       :1951][INFO    ][23568] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:18.949687 duration_in_ms=1960.673
2019-08-13 03:01:18,955 [salt.state       :1780][INFO    ][23568] Running state [maas_machines_storage_cmp002_lvm] at time 03:01:18.955280
2019-08-13 03:01:18,956 [salt.state       :1813][INFO    ][23568] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-08-13 03:01:20,157 [salt.loaded.ext.module.maasng:610 ][INFO    ][23568] htesnf
2019-08-13 03:01:20,157 [salt.loaded.ext.module.maasng:626 ][INFO    ][23568] sda
2019-08-13 03:01:20,852 [salt.loaded.ext.module.maasng:361 ][INFO    ][23568] htesnf
2019-08-13 03:01:20,953 [salt.loaded.ext.module.maasng:367 ][INFO    ][23568] [{u'size': 800109715456, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/', u'type': u'physical', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'htesnf', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'used_size': 800106479616, u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'partitions': [{u'size': 800101236736, u'uuid': u'15c8d452-8048-4997-b7e3-90e83c0111c1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'htesnf', u'filesystem': {u'label': None, u'uuid': u'7cf1953e-38ca-401d-9a86-d986612be0fe', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 1, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/partition/1'}]}, {u'size': 800097042432, u'uuid': u'1120e60c-979d-4cf5-8d60-8c92d73a78e7', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/3/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'htesnf', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'04af4b3a-55e2-4dab-aa28-5261ebbd4932', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 800097042432, u'id': 3, u'serial': None, u'partitions': []}]
2019-08-13 03:01:20,954 [salt.loaded.ext.module.maasng:632 ][INFO    ][23568] vgroot
2019-08-13 03:01:20,955 [salt.loaded.ext.module.maasng:635 ][INFO    ][23568] lvroot
2019-08-13 03:01:20,955 [salt.loaded.ext.module.maasng:639 ][INFO    ][23568] 107374182400
2019-08-13 03:01:21,547 [salt.loaded.ext.module.maasng:645 ][INFO    ][23568] {u'hwe_kernel': u'', 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'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'partition_table_type': u'MBR', u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'5031109b-9d25-47f1-9c76-e9f628010415', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'htesnf', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'50c89045-66dc-45ba-aca5-11c9f2ddcd6a', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/partition/6'}], u'id': 1, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'htesnf', u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}, {u'partition_table_type': None, u'block_size': 4096, u'uuid': u'201e6ecf-b06c-4f76-84c4-6ad54a79d1b1', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'id': 11, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'htesnf', u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/11/', u'filesystem': {u'mount_options': None, u'uuid': u'ecf75bfb-793d-40bb-95e8-54026222d494', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/htesnf/', u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'htesnf', u'power_state': u'off', 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'owner_data': {}, u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'block_size': 4096, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'uuid': None, u'tags': [u'ssd'], u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/', u'partitions': [{u'uuid': u'5031109b-9d25-47f1-9c76-e9f628010415', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'htesnf', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'50c89045-66dc-45ba-aca5-11c9f2ddcd6a', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/partition/6'}], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'used_size': 800106479616, u'system_id': u'htesnf', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'htesnf', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'block_size': 4096, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'uuid': None, u'tags': [u'ssd'], u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/', u'partitions': [{u'uuid': u'5031109b-9d25-47f1-9c76-e9f628010415', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'htesnf', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'50c89045-66dc-45ba-aca5-11c9f2ddcd6a', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/1/partition/6'}], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'used_size': 800106479616, u'system_id': u'htesnf', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}, 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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 17}], 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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/4/'}, {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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'mode': u'link_up', u'id': 18}], 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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.40'}], u'mac_address': u'9c:b6:54:8a:10:1c', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/14/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 19}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:48', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/15/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 20}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:49', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/13/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:51', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/11/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:50', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/12/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'block_size': 4096, u'id_path': None, u'uuid': u'201e6ecf-b06c-4f76-84c4-6ad54a79d1b1', u'tags': [], u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/blockdevices/11/', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'used_size': 107374182400, u'system_id': u'htesnf', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'ecf75bfb-793d-40bb-95e8-54026222d494', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id': 11, u'available_size': 0, u'serial': None, u'size': 107374182400, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', 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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 17}], 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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'htesnf', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/htesnf/interfaces/4/'}, u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-08-13 03:01:21,549 [salt.state       :300 ][INFO    ][23568] {'new': {'storage_layout': 'lvm'}}
2019-08-13 03:01:21,550 [salt.state       :1951][INFO    ][23568] Completed state [maas_machines_storage_cmp002_lvm] at time 03:01:21.549989 duration_in_ms=2594.709
2019-08-13 03:01:21,550 [salt.state       :1780][INFO    ][23568] Running state [maas_machines_storage_cmp001_lvm] at time 03:01:21.550703
2019-08-13 03:01:21,551 [salt.state       :1813][INFO    ][23568] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-08-13 03:01:22,675 [salt.loaded.ext.module.maasng:610 ][INFO    ][23568] ed6yan
2019-08-13 03:01:22,676 [salt.loaded.ext.module.maasng:626 ][INFO    ][23568] sda
2019-08-13 03:01:23,239 [salt.loaded.ext.module.maasng:361 ][INFO    ][23568] ed6yan
2019-08-13 03:01:23,325 [salt.loaded.ext.module.maasng:367 ][INFO    ][23568] [{u'partition_table_type': u'MBR', u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'5f88d8fc-f79d-4d52-acdf-3b8ea2a264c6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ed6yan', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'57d73c69-fa5c-48c1-9f70-fe133d0cc5b8', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, 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/ed6yan/blockdevices/2/partition/2'}], u'id': 2, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ed6yan', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'name': u'sda'}, {u'partition_table_type': None, u'block_size': 4096, u'uuid': u'b3e8e24a-bf09-4c7b-820a-cc0030bc83b8', u'tags': [], u'used_size': 800097042432, u'partitions': [], u'id': 4, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'ed6yan', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/4/', u'filesystem': {u'mount_options': None, u'uuid': u'e63d81aa-a3d0-402e-9dba-d510ac79dabb', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 800097042432, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}]
2019-08-13 03:01:23,325 [salt.loaded.ext.module.maasng:632 ][INFO    ][23568] vgroot
2019-08-13 03:01:23,326 [salt.loaded.ext.module.maasng:635 ][INFO    ][23568] lvroot
2019-08-13 03:01:23,326 [salt.loaded.ext.module.maasng:639 ][INFO    ][23568] 107374182400
2019-08-13 03:01:23,935 [salt.loaded.ext.module.maasng:645 ][INFO    ][23568] {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'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'size': 800109715456, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/', u'type': u'physical', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ed6yan', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'used_size': 800106479616, u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'size': 800101236736, u'uuid': u'1282853c-3b30-4f98-b534-966aca781072', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ed6yan', u'filesystem': {u'label': None, u'uuid': u'3a9fd1a2-a977-4e2e-a524-d613201e593f', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/partition/7'}]}, {u'size': 107374182400, u'uuid': u'c69cb0b1-308f-404b-b161-a384b2ae1ebf', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/12/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'ed6yan', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'c9ac2fe5-a625-4332-83ca-dbbdd3b053bd', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/ed6yan/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 800109.715456, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'ed6yan', 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'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'c69cb0b1-308f-404b-b161-a384b2ae1ebf', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/12/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'ed6yan', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'c9ac2fe5-a625-4332-83ca-dbbdd3b053bd', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'min_hwe_kernel': u'ga-16.04', u'status': 4, u'bcaches': [], u'cpu_count': 40, 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'ed6yan', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'size': 800109715456, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/', u'type': u'physical', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ed6yan', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'used_size': 800106479616, u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'size': 800101236736, u'uuid': u'1282853c-3b30-4f98-b534-966aca781072', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ed6yan', u'filesystem': {u'label': None, u'uuid': u'3a9fd1a2-a977-4e2e-a524-d613201e593f', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/partition/7'}]}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 800109715456, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/', u'type': u'physical', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ed6yan', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'used_size': 800106479616, u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'size': 800101236736, u'uuid': u'1282853c-3b30-4f98-b534-966aca781072', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ed6yan', u'filesystem': {u'label': None, u'uuid': u'3a9fd1a2-a977-4e2e-a524-d613201e593f', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/blockdevices/2/partition/7'}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'ip_addresses': [u'192.168.11.39', u'192.168.11.41'], u'architecture': u'amd64/generic', 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/5/'}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/5/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 16, u'discovered': None, u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d5', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/16/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'id': 17, u'discovered': None, u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d4', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/17/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 25}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 18, u'discovered': None, u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cd', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'mode': u'link_up', u'id': 26}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'adhqm4', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.41'}], u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a4', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/19/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 20, u'discovered': None, u'system_id': u'ed6yan', u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cc', u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ed6yan/interfaces/20/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-08-13 03:01:23,937 [salt.state       :300 ][INFO    ][23568] {'new': {'storage_layout': 'lvm'}}
2019-08-13 03:01:23,937 [salt.state       :1951][INFO    ][23568] Completed state [maas_machines_storage_cmp001_lvm] at time 03:01:23.937450 duration_in_ms=2386.747
2019-08-13 03:01:23,940 [salt.minion      :1711][INFO    ][23568] Returning information for job: 20190813030110176339
2019-08-13 03:01:24,647 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813030124635601
2019-08-13 03:01:24,672 [salt.minion      :1432][INFO    ][23613] Starting a new job with PID 23613
2019-08-13 03:01:25,871 [salt.state       :915 ][INFO    ][23613] Loading fresh modules for state activity
2019-08-13 03:01:25,948 [salt.fileclient  :1219][INFO    ][23613] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-08-13 03:01:26,007 [salt.state       :1780][INFO    ][23613] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:26.007334
2019-08-13 03:01:26,007 [salt.state       :1813][INFO    ][23613] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:01:26,009 [salt.loaded.int.module.cmdmod:395 ][INFO    ][23613] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:01:28,011 [salt.state       :300 ][INFO    ][23613] {'pid': 23620, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:01:28,013 [salt.state       :1951][INFO    ][23613] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:01:28.012842 duration_in_ms=2005.507
2019-08-13 03:01:28,016 [salt.state       :1780][INFO    ][23613] Running state [maas.deploy_machines] at time 03:01:28.016249
2019-08-13 03:01:28,016 [salt.state       :1813][INFO    ][23613] Executing state module.run for [maas.deploy_machines]
2019-08-13 03:01:28,024 [salt.utils.decorators:613 ][WARNING ][23613] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:01:28,624 [salt.loaded.ext.module.maas:684 ][INFO    ][23613] deploymachines hwe_kernel=ga-16.04 system_id=htesnf distro_series=xenial
2019-08-13 03:01:34,917 [salt.loaded.ext.module.maas:684 ][INFO    ][23613] deploymachines hwe_kernel=ga-16.04 system_id=ed6yan distro_series=xenial
2019-08-13 03:01:39,707 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030139693385
2019-08-13 03:01:39,727 [salt.minion      :1432][INFO    ][23737] Starting a new job with PID 23737
2019-08-13 03:01:39,761 [salt.minion      :1711][INFO    ][23737] Returning information for job: 20190813030139693385
2019-08-13 03:01:40,628 [salt.loaded.ext.module.maas:684 ][INFO    ][23613] deploymachines hwe_kernel=ga-16.04 system_id=6e3e4m distro_series=xenial
2019-08-13 03:01:46,871 [salt.loaded.ext.module.maas:684 ][INFO    ][23613] deploymachines hwe_kernel=ga-16.04 system_id=y8frmk distro_series=xenial
2019-08-13 03:01:53,299 [salt.loaded.ext.module.maas:684 ][INFO    ][23613] deploymachines hwe_kernel=ga-16.04 system_id=fb3mpe distro_series=xenial
2019-08-13 03:01:59,593 [salt.state       :300 ][INFO    ][23613] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-08-13 03:01:59,597 [salt.state       :1951][INFO    ][23613] Completed state [maas.deploy_machines] at time 03:01:59.597087 duration_in_ms=31580.837
2019-08-13 03:01:59,599 [salt.minion      :1711][INFO    ][23613] Returning information for job: 20190813030124635601
2019-08-13 03:02:00,331 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813030200318419
2019-08-13 03:02:00,356 [salt.minion      :1432][INFO    ][23963] Starting a new job with PID 23963
2019-08-13 03:02:06,710 [salt.state       :915 ][INFO    ][23963] Loading fresh modules for state activity
2019-08-13 03:02:06,776 [salt.fileclient  :1219][INFO    ][23963] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-08-13 03:02:06,826 [salt.state       :1780][INFO    ][23963] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:02:06.826800
2019-08-13 03:02:06,827 [salt.state       :1813][INFO    ][23963] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:02:06,829 [salt.loaded.int.module.cmdmod:395 ][INFO    ][23963] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:02:08,795 [salt.state       :300 ][INFO    ][23963] {'pid': 23978, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:02:08,796 [salt.state       :1951][INFO    ][23963] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:02:08.795959 duration_in_ms=1969.158
2019-08-13 03:02:08,804 [salt.state       :1780][INFO    ][23963] Running state [maas.wait_for_machine_status] at time 03:02:08.804174
2019-08-13 03:02:08,805 [salt.state       :1813][INFO    ][23963] Executing state module.run for [maas.wait_for_machine_status]
2019-08-13 03:02:08,806 [salt.utils.decorators:613 ][WARNING ][23963] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:02:11,867 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.95304489s left)
2019-08-13 03:02:15,450 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030215437665
2019-08-13 03:02:15,472 [salt.minion      :1432][INFO    ][23996] Starting a new job with PID 23996
2019-08-13 03:02:15,500 [salt.minion      :1711][INFO    ][23996] Returning information for job: 20190813030215437665
2019-08-13 03:02:44,916 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.90460706s left)
2019-08-13 03:02:45,528 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030245514151
2019-08-13 03:02:45,550 [salt.minion      :1432][INFO    ][24159] Starting a new job with PID 24159
2019-08-13 03:02:45,581 [salt.minion      :1711][INFO    ][24159] Returning information for job: 20190813030245514151
2019-08-13 03:03:15,604 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030315590756
2019-08-13 03:03:15,629 [salt.minion      :1432][INFO    ][24196] Starting a new job with PID 24196
2019-08-13 03:03:15,659 [salt.minion      :1711][INFO    ][24196] Returning information for job: 20190813030315590756
2019-08-13 03:03:17,972 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.84866905s left)
2019-08-13 03:03:45,690 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030345675407
2019-08-13 03:03:45,716 [salt.minion      :1432][INFO    ][24235] Starting a new job with PID 24235
2019-08-13 03:03:45,745 [salt.minion      :1711][INFO    ][24235] Returning information for job: 20190813030345675407
2019-08-13 03:03:50,876 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.9440701s left)
2019-08-13 03:04:15,772 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030415758538
2019-08-13 03:04:15,800 [salt.minion      :1432][INFO    ][24292] Starting a new job with PID 24292
2019-08-13 03:04:15,835 [salt.minion      :1711][INFO    ][24292] Returning information for job: 20190813030415758538
2019-08-13 03:04:23,740 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2115.08024001s left)
2019-08-13 03:04:37,612 [salt.utils.schedule:1377][INFO    ][3077] Running scheduled job: __mine_interval
2019-08-13 03:04:45,882 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030445871211
2019-08-13 03:04:45,908 [salt.minion      :1432][INFO    ][24474] Starting a new job with PID 24474
2019-08-13 03:04:45,947 [salt.minion      :1711][INFO    ][24474] Returning information for job: 20190813030445871211
2019-08-13 03:04:56,802 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2082.01806307s left)
2019-08-13 03:05:16,017 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030516007890
2019-08-13 03:05:16,041 [salt.minion      :1432][INFO    ][24630] Starting a new job with PID 24630
2019-08-13 03:05:16,081 [salt.minion      :1711][INFO    ][24630] Returning information for job: 20190813030516007890
2019-08-13 03:05:30,400 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2048.41987705s left)
2019-08-13 03:05:46,181 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030546167991
2019-08-13 03:05:46,201 [salt.minion      :1432][INFO    ][24757] Starting a new job with PID 24757
2019-08-13 03:05:46,244 [salt.minion      :1711][INFO    ][24757] Returning information for job: 20190813030546167991
2019-08-13 03:06:16,361 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030616346914
2019-08-13 03:06:16,379 [salt.minion      :1432][INFO    ][24888] Starting a new job with PID 24888
2019-08-13 03:06:16,432 [salt.minion      :1711][INFO    ][24888] Returning information for job: 20190813030616346914
2019-08-13 03:06:46,568 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030646544891
2019-08-13 03:06:46,592 [salt.minion      :1432][INFO    ][25015] Starting a new job with PID 25015
2019-08-13 03:06:46,625 [salt.minion      :1711][INFO    ][25015] Returning information for job: 20190813030646544891
2019-08-13 03:07:16,767 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030716715289
2019-08-13 03:07:16,795 [salt.minion      :1432][INFO    ][25069] Starting a new job with PID 25069
2019-08-13 03:07:16,842 [salt.minion      :1711][INFO    ][25069] Returning information for job: 20190813030716715289
2019-08-13 03:07:25,908 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1932.91182804s left)
2019-08-13 03:07:46,807 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030746788172
2019-08-13 03:07:46,835 [salt.minion      :1432][INFO    ][25592] Starting a new job with PID 25592
2019-08-13 03:07:46,873 [salt.minion      :1711][INFO    ][25592] Returning information for job: 20190813030746788172
2019-08-13 03:07:59,074 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1899.74596596s left)
2019-08-13 03:08:16,964 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030816948928
2019-08-13 03:08:16,987 [salt.minion      :1432][INFO    ][25843] Starting a new job with PID 25843
2019-08-13 03:08:17,019 [salt.minion      :1711][INFO    ][25843] Returning information for job: 20190813030816948928
2019-08-13 03:08:31,997 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1866.82317996s left)
2019-08-13 03:08:47,112 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030847099183
2019-08-13 03:08:47,137 [salt.minion      :1432][INFO    ][26045] Starting a new job with PID 26045
2019-08-13 03:08:47,172 [salt.minion      :1711][INFO    ][26045] Returning information for job: 20190813030847099183
2019-08-13 03:09:05,021 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1833.79959512s left)
2019-08-13 03:09:17,280 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030917268884
2019-08-13 03:09:17,310 [salt.minion      :1432][INFO    ][26124] Starting a new job with PID 26124
2019-08-13 03:09:17,358 [salt.minion      :1711][INFO    ][26124] Returning information for job: 20190813030917268884
2019-08-13 03:09:37,940 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1800.88032198s left)
2019-08-13 03:09:47,491 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813030947479750
2019-08-13 03:09:47,518 [salt.minion      :1432][INFO    ][26379] Starting a new job with PID 26379
2019-08-13 03:09:47,555 [salt.minion      :1711][INFO    ][26379] Returning information for job: 20190813030947479750
2019-08-13 03:10:11,129 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1767.69152808s left)
2019-08-13 03:10:17,680 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031017667044
2019-08-13 03:10:17,709 [salt.minion      :1432][INFO    ][26504] Starting a new job with PID 26504
2019-08-13 03:10:17,747 [salt.minion      :1711][INFO    ][26504] Returning information for job: 20190813031017667044
2019-08-13 03:10:44,271 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1734.54926991s left)
2019-08-13 03:10:47,869 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031047854275
2019-08-13 03:10:47,915 [salt.minion      :1432][INFO    ][26775] Starting a new job with PID 26775
2019-08-13 03:10:47,961 [salt.minion      :1711][INFO    ][26775] Returning information for job: 20190813031047854275
2019-08-13 03:11:17,233 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1701.58738995s left)
2019-08-13 03:11:18,091 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031118076180
2019-08-13 03:11:18,116 [salt.minion      :1432][INFO    ][26867] Starting a new job with PID 26867
2019-08-13 03:11:18,156 [salt.minion      :1711][INFO    ][26867] Returning information for job: 20190813031118076180
2019-08-13 03:11:48,308 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031148292906
2019-08-13 03:11:48,332 [salt.minion      :1432][INFO    ][26970] Starting a new job with PID 26970
2019-08-13 03:11:48,362 [salt.minion      :1711][INFO    ][26970] Returning information for job: 20190813031148292906
2019-08-13 03:11:50,549 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1668.27131796s left)
2019-08-13 03:12:18,406 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031218387679
2019-08-13 03:12:18,435 [salt.minion      :1432][INFO    ][27009] Starting a new job with PID 27009
2019-08-13 03:12:18,471 [salt.minion      :1711][INFO    ][27009] Returning information for job: 20190813031218387679
2019-08-13 03:12:23,440 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1635.38000607s left)
2019-08-13 03:12:48,600 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031248586159
2019-08-13 03:12:48,628 [salt.minion      :1432][INFO    ][27156] Starting a new job with PID 27156
2019-08-13 03:12:48,657 [salt.minion      :1711][INFO    ][27156] Returning information for job: 20190813031248586159
2019-08-13 03:12:56,525 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1602.29531813s left)
2019-08-13 03:13:18,800 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031318790559
2019-08-13 03:13:18,833 [salt.minion      :1432][INFO    ][27179] Starting a new job with PID 27179
2019-08-13 03:13:18,862 [salt.minion      :1711][INFO    ][27179] Returning information for job: 20190813031318790559
2019-08-13 03:13:29,524 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1569.29610109s left)
2019-08-13 03:13:49,018 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031349000821
2019-08-13 03:13:49,044 [salt.minion      :1432][INFO    ][27232] Starting a new job with PID 27232
2019-08-13 03:13:49,076 [salt.minion      :1711][INFO    ][27232] Returning information for job: 20190813031349000821
2019-08-13 03:14:02,572 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1536.24788094s left)
2019-08-13 03:14:19,246 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031419231772
2019-08-13 03:14:19,275 [salt.minion      :1432][INFO    ][27256] Starting a new job with PID 27256
2019-08-13 03:14:19,303 [salt.minion      :1711][INFO    ][27256] Returning information for job: 20190813031419231772
2019-08-13 03:14:35,649 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1503.17145395s left)
2019-08-13 03:14:49,268 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031449260415
2019-08-13 03:14:49,290 [salt.minion      :1432][INFO    ][27363] Starting a new job with PID 27363
2019-08-13 03:14:49,318 [salt.minion      :1711][INFO    ][27363] Returning information for job: 20190813031449260415
2019-08-13 03:15:08,525 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001', 'kvm03']
sleep for:30s Timeout:2250s (1470.29565501s left)
2019-08-13 03:15:19,376 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031519364943
2019-08-13 03:15:19,408 [salt.minion      :1432][INFO    ][27463] Starting a new job with PID 27463
2019-08-13 03:15:19,436 [salt.minion      :1711][INFO    ][27463] Returning information for job: 20190813031519364943
2019-08-13 03:15:41,701 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1437.11967206s left)
2019-08-13 03:15:49,603 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031549589951
2019-08-13 03:15:49,631 [salt.minion      :1432][INFO    ][27802] Starting a new job with PID 27802
2019-08-13 03:15:49,664 [salt.minion      :1711][INFO    ][27802] Returning information for job: 20190813031549589951
2019-08-13 03:16:14,607 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1404.21286798s left)
2019-08-13 03:16:19,651 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031619640337
2019-08-13 03:16:19,681 [salt.minion      :1432][INFO    ][27847] Starting a new job with PID 27847
2019-08-13 03:16:19,710 [salt.minion      :1711][INFO    ][27847] Returning information for job: 20190813031619640337
2019-08-13 03:16:47,680 [salt.loaded.ext.module.maas:1023][INFO    ][23963] Waiting status:Deployed for machines:['cmp001']
sleep for:30s Timeout:2250s (1371.140553s left)
2019-08-13 03:16:49,724 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031649715414
2019-08-13 03:16:49,750 [salt.minion      :1432][INFO    ][27904] Starting a new job with PID 27904
2019-08-13 03:16:49,775 [salt.minion      :1711][INFO    ][27904] Returning information for job: 20190813031649715414
2019-08-13 03:17:18,915 [salt.loaded.ext.module.maas:993 ][INFO    ][23963] Machine ed6yan mark broken
2019-08-13 03:17:19,583 [salt.loaded.ext.module.maas:996 ][INFO    ][23963] Machine ed6yan mark fixed
2019-08-13 03:17:19,808 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031719796362
2019-08-13 03:17:19,834 [salt.minion      :1432][INFO    ][27950] Starting a new job with PID 27950
2019-08-13 03:17:19,869 [salt.minion      :1711][INFO    ][27950] Returning information for job: 20190813031719796362
2019-08-13 03:17:20,824 [salt.loaded.ext.module.maas:684 ][INFO    ][23963] deploymachines hwe_kernel=ga-16.04 system_id=ed6yan distro_series=xenial
2019-08-13 03:17:23,427 [salt.loaded.ext.module.maas:160 ][ERROR   ][23963] Failed for object cmp001 reason Unable to change power state to 'cycle' for node cmp001: another action is already in progress for that node.
2019-08-13 03:17:23,429 [salt.state       :302 ][ERROR   ][23963] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'kvm01', 'kvm03', 'kvm02'], 'errors': {'cmp001': "Unable to change power state to 'cycle' for node cmp001: another action is already in progress for that node."}, 'success': []}
2019-08-13 03:17:23,430 [salt.state       :1951][INFO    ][23963] Completed state [maas.wait_for_machine_status] at time 03:17:23.429606 duration_in_ms=914625.428
2019-08-13 03:17:23,435 [salt.minion      :1711][INFO    ][23963] Returning information for job: 20190813030200318419
2019-08-13 03:17:34,389 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command pillar.get with jid 20190813031734375792
2019-08-13 03:17:34,414 [salt.minion      :1432][INFO    ][28021] Starting a new job with PID 28021
2019-08-13 03:17:34,425 [salt.minion      :1711][INFO    ][28021] Returning information for job: 20190813031734375792
2019-08-13 03:17:35,145 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command service.status with jid 20190813031735136006
2019-08-13 03:17:35,172 [salt.minion      :1432][INFO    ][28026] Starting a new job with PID 28026
2019-08-13 03:17:36,397 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][28026] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-08-13 03:17:36,452 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][28026] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-08-13 03:17:36,474 [salt.minion      :1711][INFO    ][28026] Returning information for job: 20190813031735136006
2019-08-13 03:17:37,203 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813031737193257
2019-08-13 03:17:37,229 [salt.minion      :1432][INFO    ][28037] Starting a new job with PID 28037
2019-08-13 03:17:43,482 [salt.state       :915 ][INFO    ][28037] Loading fresh modules for state activity
2019-08-13 03:17:44,159 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'salt-minion --version' in directory '/root'
2019-08-13 03:17:44,674 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'salt-minion --version' in directory '/root'
2019-08-13 03:17:45,792 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'salt-minion --version' in directory '/root'
2019-08-13 03:17:46,143 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'salt-minion --version' in directory '/root'
2019-08-13 03:17:48,590 [salt.state       :1780][INFO    ][28037] Running state [salt-minion] at time 03:17:48.589964
2019-08-13 03:17:48,590 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [salt-minion]
2019-08-13 03:17:48,592 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-13 03:17:48,735 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:48,735 [salt.state       :1951][INFO    ][28037] Completed state [salt-minion] at time 03:17:48.735408 duration_in_ms=145.445
2019-08-13 03:17:48,735 [salt.state       :1780][INFO    ][28037] Running state [salt_minion_dependency_packages] at time 03:17:48.735786
2019-08-13 03:17:48,736 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-08-13 03:17:48,745 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:48,745 [salt.state       :1951][INFO    ][28037] Completed state [salt_minion_dependency_packages] at time 03:17:48.745476 duration_in_ms=9.69
2019-08-13 03:17:48,750 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/minion.d/minion.conf] at time 03:17:48.750474
2019-08-13 03:17:48,750 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-08-13 03:17:49,035 [salt.state       :300 ][INFO    ][28037] File /etc/salt/minion.d/minion.conf is in the correct state
2019-08-13 03:17:49,035 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/minion.d/minion.conf] at time 03:17:49.035704 duration_in_ms=285.229
2019-08-13 03:17:49,036 [salt.state       :1780][INFO    ][28037] Running state [python-netaddr] at time 03:17:49.036049
2019-08-13 03:17:49,036 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [python-netaddr]
2019-08-13 03:17:49,048 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:49,048 [salt.state       :1951][INFO    ][28037] Completed state [python-netaddr] at time 03:17:49.048385 duration_in_ms=12.336
2019-08-13 03:17:49,052 [salt.state       :1780][INFO    ][28037] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:17:49.052761
2019-08-13 03:17:49,053 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-08-13 03:17:49,068 [salt.state       :300 ][INFO    ][28037] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-08-13 03:17:49,069 [salt.state       :1951][INFO    ][28037] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:17:49.069102 duration_in_ms=16.34
2019-08-13 03:17:49,072 [salt.state       :1780][INFO    ][28037] Running state [salt-minion] at time 03:17:49.072232
2019-08-13 03:17:49,072 [salt.state       :1813][INFO    ][28037] Executing state service.running for [salt-minion]
2019-08-13 03:17:49,074 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-08-13 03:17:49,122 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-08-13 03:17:49,143 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-08-13 03:17:49,168 [salt.state       :300 ][INFO    ][28037] The service salt-minion is already running
2019-08-13 03:17:49,169 [salt.state       :1951][INFO    ][28037] Completed state [salt-minion] at time 03:17:49.169605 duration_in_ms=97.374
2019-08-13 03:17:49,172 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains.d] at time 03:17:49.172650
2019-08-13 03:17:49,173 [salt.state       :1813][INFO    ][28037] Executing state file.directory for [/etc/salt/grains.d]
2019-08-13 03:17:49,176 [salt.state       :300 ][INFO    ][28037] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-08-13 03:17:49,176 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains.d] at time 03:17:49.176508 duration_in_ms=3.857
2019-08-13 03:17:49,178 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains] at time 03:17:49.178743
2019-08-13 03:17:49,179 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/grains]
2019-08-13 03:17:49,180 [salt.state       :300 ][INFO    ][28037] File /etc/salt/grains exists with proper permissions. No changes made.
2019-08-13 03:17:49,181 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains] at time 03:17:49.180894 duration_in_ms=2.15
2019-08-13 03:17:49,183 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains.d/placeholder] at time 03:17:49.183015
2019-08-13 03:17:49,183 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-08-13 03:17:49,184 [salt.state       :300 ][INFO    ][28037] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-08-13 03:17:49,184 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains.d/placeholder] at time 03:17:49.184794 duration_in_ms=1.779
2019-08-13 03:17:49,185 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains.d/sphinx] at time 03:17:49.185619
2019-08-13 03:17:49,186 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-08-13 03:17:49,188 [salt.state       :300 ][INFO    ][28037] File /etc/salt/grains.d/sphinx is in the correct state
2019-08-13 03:17:49,189 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains.d/sphinx] at time 03:17:49.188974 duration_in_ms=3.356
2019-08-13 03:17:49,193 [salt.state       :1780][INFO    ][28037] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.193566
2019-08-13 03:17:49,194 [salt.state       :1813][INFO    ][28037] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-08-13 03:17:49,194 [salt.state       :300 ][INFO    ][28037] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-08-13 03:17:49,194 [salt.state       :1951][INFO    ][28037] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.194532 duration_in_ms=0.966
2019-08-13 03:17:49,195 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains.d/dns_records] at time 03:17:49.195050
2019-08-13 03:17:49,195 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-08-13 03:17:49,196 [salt.state       :300 ][INFO    ][28037] File /etc/salt/grains.d/dns_records is in the correct state
2019-08-13 03:17:49,196 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains.d/dns_records] at time 03:17:49.196814 duration_in_ms=1.764
2019-08-13 03:17:49,197 [salt.state       :1780][INFO    ][28037] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.197778
2019-08-13 03:17:49,198 [salt.state       :1813][INFO    ][28037] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-08-13 03:17:49,198 [salt.state       :300 ][INFO    ][28037] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-08-13 03:17:49,198 [salt.state       :1951][INFO    ][28037] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.198628 duration_in_ms=0.85
2019-08-13 03:17:49,199 [salt.state       :1780][INFO    ][28037] Running state [/etc/salt/grains.d/salt] at time 03:17:49.199150
2019-08-13 03:17:49,199 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-08-13 03:17:49,200 [salt.state       :300 ][INFO    ][28037] File /etc/salt/grains.d/salt is in the correct state
2019-08-13 03:17:49,200 [salt.state       :1951][INFO    ][28037] Completed state [/etc/salt/grains.d/salt] at time 03:17:49.200930 duration_in_ms=1.78
2019-08-13 03:17:49,202 [salt.state       :1780][INFO    ][28037] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.202654
2019-08-13 03:17:49,202 [salt.state       :1813][INFO    ][28037] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-08-13 03:17:49,203 [salt.state       :300 ][INFO    ][28037] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-08-13 03:17:49,203 [salt.state       :1951][INFO    ][28037] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:17:49.203499 duration_in_ms=0.845
2019-08-13 03:17:49,205 [salt.state       :1780][INFO    ][28037] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:17:49.205431
2019-08-13 03:17:49,205 [salt.state       :1813][INFO    ][28037] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-08-13 03:17:49,206 [salt.state       :300 ][INFO    ][28037] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-08-13 03:17:49,206 [salt.state       :1951][INFO    ][28037] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:17:49.206298 duration_in_ms=0.868
2019-08-13 03:17:49,207 [salt.state       :1780][INFO    ][28037] Running state [mine.update] at time 03:17:49.206989
2019-08-13 03:17:49,207 [salt.state       :1813][INFO    ][28037] Executing state module.wait for [mine.update]
2019-08-13 03:17:49,207 [salt.state       :300 ][INFO    ][28037] No changes made for mine.update
2019-08-13 03:17:49,207 [salt.state       :1951][INFO    ][28037] Completed state [mine.update] at time 03:17:49.207782 duration_in_ms=0.792
2019-08-13 03:17:49,208 [salt.state       :1780][INFO    ][28037] Running state [ca-certificates] at time 03:17:49.208056
2019-08-13 03:17:49,208 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [ca-certificates]
2019-08-13 03:17:49,219 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:49,219 [salt.state       :1951][INFO    ][28037] Completed state [ca-certificates] at time 03:17:49.219819 duration_in_ms=11.763
2019-08-13 03:17:49,220 [salt.state       :1780][INFO    ][28037] Running state [update-ca-certificates] at time 03:17:49.220551
2019-08-13 03:17:49,220 [salt.state       :1813][INFO    ][28037] Executing state cmd.wait for [update-ca-certificates]
2019-08-13 03:17:49,221 [salt.state       :300 ][INFO    ][28037] No changes made for update-ca-certificates
2019-08-13 03:17:49,221 [salt.state       :1951][INFO    ][28037] Completed state [update-ca-certificates] at time 03:17:49.221402 duration_in_ms=0.851
2019-08-13 03:17:49,221 [salt.state       :1780][INFO    ][28037] Running state [iptables] at time 03:17:49.221678
2019-08-13 03:17:49,221 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [iptables]
2019-08-13 03:17:49,232 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:49,232 [salt.state       :1951][INFO    ][28037] Completed state [iptables] at time 03:17:49.232596 duration_in_ms=10.918
2019-08-13 03:17:49,232 [salt.state       :1780][INFO    ][28037] Running state [iptables-persistent] at time 03:17:49.232880
2019-08-13 03:17:49,233 [salt.state       :1813][INFO    ][28037] Executing state pkg.installed for [iptables-persistent]
2019-08-13 03:17:49,243 [salt.state       :300 ][INFO    ][28037] All specified packages are already installed
2019-08-13 03:17:49,243 [salt.state       :1951][INFO    ][28037] Completed state [iptables-persistent] at time 03:17:49.243364 duration_in_ms=10.484
2019-08-13 03:17:49,244 [salt.state       :1780][INFO    ][28037] Running state [iptables_modules_v4_load] at time 03:17:49.244646
2019-08-13 03:17:49,244 [salt.state       :1813][INFO    ][28037] Executing state kmod.present for [iptables_modules_v4_load]
2019-08-13 03:17:49,245 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'lsmod' in directory '/root'
2019-08-13 03:17:49,270 [salt.state       :300 ][INFO    ][28037] Kernel modules iptable_filter, ip_tables are already present
2019-08-13 03:17:49,271 [salt.state       :1951][INFO    ][28037] Completed state [iptables_modules_v4_load] at time 03:17:49.270936 duration_in_ms=26.289
2019-08-13 03:17:49,272 [salt.state       :1780][INFO    ][28037] Running state [/etc/iptables/rules.v4] at time 03:17:49.272197
2019-08-13 03:17:49,272 [salt.state       :1813][INFO    ][28037] Executing state file.managed for [/etc/iptables/rules.v4]
2019-08-13 03:17:49,395 [salt.state       :300 ][INFO    ][28037] File /etc/iptables/rules.v4 is in the correct state
2019-08-13 03:17:49,395 [salt.state       :1951][INFO    ][28037] Completed state [/etc/iptables/rules.v4] at time 03:17:49.395764 duration_in_ms=123.567
2019-08-13 03:17:49,397 [salt.state       :1780][INFO    ][28037] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:17:49.397685
2019-08-13 03:17:49,398 [salt.state       :1813][INFO    ][28037] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-08-13 03:17:49,399 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-08-13 03:17:49,422 [salt.state       :300 ][INFO    ][28037] onlyif execution failed
2019-08-13 03:17:49,423 [salt.state       :1951][INFO    ][28037] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:17:49.423288 duration_in_ms=25.602
2019-08-13 03:17:49,424 [salt.state       :1780][INFO    ][28037] Running state [netfilter-persistent] at time 03:17:49.424751
2019-08-13 03:17:49,425 [salt.state       :1813][INFO    ][28037] Executing state service.running for [netfilter-persistent]
2019-08-13 03:17:49,426 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-08-13 03:17:49,453 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-08-13 03:17:49,474 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-08-13 03:17:49,495 [salt.state       :300 ][INFO    ][28037] The service netfilter-persistent is already running
2019-08-13 03:17:49,496 [salt.state       :1951][INFO    ][28037] Completed state [netfilter-persistent] at time 03:17:49.496444 duration_in_ms=71.693
2019-08-13 03:17:49,498 [salt.state       :1780][INFO    ][28037] Running state [iptables_extra.remove_stale_tables] at time 03:17:49.498276
2019-08-13 03:17:49,498 [salt.state       :1813][INFO    ][28037] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-08-13 03:17:49,499 [salt.state       :300 ][INFO    ][28037] No changes made for iptables_extra.remove_stale_tables
2019-08-13 03:17:49,499 [salt.state       :1951][INFO    ][28037] Completed state [iptables_extra.remove_stale_tables] at time 03:17:49.499836 duration_in_ms=1.561
2019-08-13 03:17:49,500 [salt.state       :1780][INFO    ][28037] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:17:49.500329
2019-08-13 03:17:49,500 [salt.state       :1813][INFO    ][28037] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-08-13 03:17:49,503 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28037] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-08-13 03:17:49,520 [salt.state       :300 ][INFO    ][28037] onlyif execution failed
2019-08-13 03:17:49,521 [salt.state       :1951][INFO    ][28037] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:17:49.521217 duration_in_ms=20.888
2019-08-13 03:17:49,523 [salt.state       :1780][INFO    ][28037] Running state [/etc/iptables/rules.v6] at time 03:17:49.523771
2019-08-13 03:17:49,524 [salt.state       :1813][INFO    ][28037] Executing state file.absent for [/etc/iptables/rules.v6]
2019-08-13 03:17:49,525 [salt.state       :300 ][INFO    ][28037] File /etc/iptables/rules.v6 is not present
2019-08-13 03:17:49,527 [salt.state       :1951][INFO    ][28037] Completed state [/etc/iptables/rules.v6] at time 03:17:49.527846 duration_in_ms=4.076
2019-08-13 03:17:49,528 [salt.state       :1780][INFO    ][28037] Running state [iptables_extra.flush_all] at time 03:17:49.528668
2019-08-13 03:17:49,529 [salt.state       :1813][INFO    ][28037] Executing state module.wait for [iptables_extra.flush_all]
2019-08-13 03:17:49,529 [salt.state       :300 ][INFO    ][28037] No changes made for iptables_extra.flush_all
2019-08-13 03:17:49,529 [salt.state       :1951][INFO    ][28037] Completed state [iptables_extra.flush_all] at time 03:17:49.529596 duration_in_ms=0.928
2019-08-13 03:17:49,533 [salt.minion      :1711][INFO    ][28037] Returning information for job: 20190813031737193257
2019-08-13 03:17:50,255 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813031750241407
2019-08-13 03:17:50,285 [salt.minion      :1432][INFO    ][28142] Starting a new job with PID 28142
2019-08-13 03:17:51,335 [salt.state       :915 ][INFO    ][28142] Loading fresh modules for state activity
2019-08-13 03:17:52,659 [salt.state       :1780][INFO    ][28142] Running state [maas-rack-controller] at time 03:17:52.659751
2019-08-13 03:17:52,660 [salt.state       :1813][INFO    ][28142] Executing state pkg.installed for [maas-rack-controller]
2019-08-13 03:17:52,660 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28142] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-13 03:17:52,788 [salt.state       :300 ][INFO    ][28142] All specified packages are already installed
2019-08-13 03:17:52,788 [salt.state       :1951][INFO    ][28142] Completed state [maas-rack-controller] at time 03:17:52.788751 duration_in_ms=129.0
2019-08-13 03:17:52,789 [salt.state       :1780][INFO    ][28142] Running state [ipmitool] at time 03:17:52.789139
2019-08-13 03:17:52,789 [salt.state       :1813][INFO    ][28142] Executing state pkg.installed for [ipmitool]
2019-08-13 03:17:52,799 [salt.state       :300 ][INFO    ][28142] All specified packages are already installed
2019-08-13 03:17:52,799 [salt.state       :1951][INFO    ][28142] Completed state [ipmitool] at time 03:17:52.799619 duration_in_ms=10.481
2019-08-13 03:17:52,803 [salt.state       :1780][INFO    ][28142] Running state [/etc/maas/rackd.conf] at time 03:17:52.803410
2019-08-13 03:17:52,803 [salt.state       :1813][INFO    ][28142] Executing state file.line for [/etc/maas/rackd.conf]
2019-08-13 03:17:52,804 [salt.state       :300 ][INFO    ][28142] No changes needed to be made
2019-08-13 03:17:52,805 [salt.state       :1951][INFO    ][28142] Completed state [/etc/maas/rackd.conf] at time 03:17:52.805002 duration_in_ms=1.592
2019-08-13 03:17:52,805 [salt.state       :1780][INFO    ][28142] Running state [/etc/maas/rackd.conf] at time 03:17:52.805286
2019-08-13 03:17:52,805 [salt.state       :1813][INFO    ][28142] Executing state file.managed for [/etc/maas/rackd.conf]
2019-08-13 03:17:52,805 [salt.loaded.int.states.file:2298][WARNING ][28142] 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-08-13 03:17:52,806 [salt.state       :300 ][INFO    ][28142] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-08-13 03:17:52,807 [salt.state       :1951][INFO    ][28142] Completed state [/etc/maas/rackd.conf] at time 03:17:52.806977 duration_in_ms=1.691
2019-08-13 03:17:52,808 [salt.state       :1780][INFO    ][28142] Running state [maas-rackd] at time 03:17:52.808046
2019-08-13 03:17:52,808 [salt.state       :1813][INFO    ][28142] Executing state service.running for [maas-rackd]
2019-08-13 03:17:52,809 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28142] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-08-13 03:17:52,853 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28142] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-08-13 03:17:52,877 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28142] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-08-13 03:17:52,896 [salt.state       :300 ][INFO    ][28142] The service maas-rackd is already running
2019-08-13 03:17:52,897 [salt.state       :1951][INFO    ][28142] Completed state [maas-rackd] at time 03:17:52.896913 duration_in_ms=88.866
2019-08-13 03:17:52,901 [salt.minion      :1711][INFO    ][28142] Returning information for job: 20190813031750241407
2019-08-13 03:17:53,603 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813031753591229
2019-08-13 03:17:53,629 [salt.minion      :1432][INFO    ][28165] Starting a new job with PID 28165
2019-08-13 03:17:54,739 [salt.state       :915 ][INFO    ][28165] Loading fresh modules for state activity
2019-08-13 03:17:56,220 [salt.state       :1780][INFO    ][28165] Running state [maas-region-controller] at time 03:17:56.220030
2019-08-13 03:17:56,220 [salt.state       :1813][INFO    ][28165] Executing state pkg.installed for [maas-region-controller]
2019-08-13 03:17:56,221 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-13 03:17:56,348 [salt.state       :300 ][INFO    ][28165] All specified packages are already installed
2019-08-13 03:17:56,348 [salt.state       :1951][INFO    ][28165] Completed state [maas-region-controller] at time 03:17:56.348391 duration_in_ms=128.363
2019-08-13 03:17:56,348 [salt.state       :1780][INFO    ][28165] Running state [python-oauth] at time 03:17:56.348767
2019-08-13 03:17:56,349 [salt.state       :1813][INFO    ][28165] Executing state pkg.installed for [python-oauth]
2019-08-13 03:17:56,359 [salt.state       :300 ][INFO    ][28165] All specified packages are already installed
2019-08-13 03:17:56,359 [salt.state       :1951][INFO    ][28165] Completed state [python-oauth] at time 03:17:56.359346 duration_in_ms=10.579
2019-08-13 03:17:56,362 [salt.state       :1780][INFO    ][28165] Running state [/etc/maas/regiond.conf] at time 03:17:56.362620
2019-08-13 03:17:56,362 [salt.state       :1813][INFO    ][28165] Executing state file.replace for [/etc/maas/regiond.conf]
2019-08-13 03:17:56,368 [salt.state       :300 ][INFO    ][28165] No changes needed to be made
2019-08-13 03:17:56,368 [salt.state       :1951][INFO    ][28165] Completed state [/etc/maas/regiond.conf] at time 03:17:56.368891 duration_in_ms=6.271
2019-08-13 03:17:56,369 [salt.state       :1780][INFO    ][28165] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:17:56.369411
2019-08-13 03:17:56,369 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-08-13 03:17:56,435 [salt.state       :300 ][INFO    ][28165] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-08-13 03:17:56,436 [salt.state       :1951][INFO    ][28165] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:17:56.436084 duration_in_ms=66.672
2019-08-13 03:17:56,436 [salt.state       :1780][INFO    ][28165] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:17:56.436729
2019-08-13 03:17:56,437 [salt.state       :1813][INFO    ][28165] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-13 03:17:56,443 [salt.state       :300 ][INFO    ][28165] No changes needed to be made
2019-08-13 03:17:56,443 [salt.state       :1951][INFO    ][28165] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:17:56.443292 duration_in_ms=6.563
2019-08-13 03:17:56,443 [salt.state       :1780][INFO    ][28165] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:17:56.443809
2019-08-13 03:17:56,444 [salt.state       :1813][INFO    ][28165] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-13 03:17:56,448 [salt.state       :300 ][INFO    ][28165] No changes needed to be made
2019-08-13 03:17:56,448 [salt.state       :1951][INFO    ][28165] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:17:56.448662 duration_in_ms=4.853
2019-08-13 03:17:56,449 [salt.state       :1780][INFO    ][28165] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:17:56.449187
2019-08-13 03:17:56,449 [salt.state       :1813][INFO    ][28165] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-08-13 03:17:56,482 [salt.state       :300 ][INFO    ][28165] No changes needed to be made
2019-08-13 03:17:56,482 [salt.state       :1951][INFO    ][28165] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:17:56.482299 duration_in_ms=33.112
2019-08-13 03:17:56,482 [salt.state       :1780][INFO    ][28165] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:17:56.482887
2019-08-13 03:17:56,483 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-08-13 03:17:56,500 [salt.state       :300 ][INFO    ][28165] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-08-13 03:17:56,501 [salt.state       :1951][INFO    ][28165] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:17:56.501225 duration_in_ms=18.338
2019-08-13 03:17:56,503 [salt.state       :1780][INFO    ][28165] Running state [a2enmod headers] at time 03:17:56.503403
2019-08-13 03:17:56,503 [salt.state       :1813][INFO    ][28165] Executing state cmd.run for [a2enmod headers]
2019-08-13 03:17:56,505 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command 'a2enmod headers' in directory '/root'
2019-08-13 03:17:56,600 [salt.state       :300 ][INFO    ][28165] {'pid': 28184, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-08-13 03:17:56,601 [salt.state       :1951][INFO    ][28165] Completed state [a2enmod headers] at time 03:17:56.601527 duration_in_ms=98.124
2019-08-13 03:17:56,602 [salt.state       :1780][INFO    ][28165] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:17:56.602172
2019-08-13 03:17:56,602 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-08-13 03:17:56,634 [salt.state       :300 ][INFO    ][28165] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-08-13 03:17:56,634 [salt.state       :1951][INFO    ][28165] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:17:56.634675 duration_in_ms=32.504
2019-08-13 03:17:56,635 [salt.state       :1780][INFO    ][28165] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:17:56.635300
2019-08-13 03:17:56,635 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-08-13 03:17:56,698 [salt.state       :300 ][INFO    ][28165] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-08-13 03:17:56,698 [salt.state       :1951][INFO    ][28165] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:17:56.698650 duration_in_ms=63.35
2019-08-13 03:17:56,699 [salt.state       :1780][INFO    ][28165] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:17:56.699208
2019-08-13 03:17:56,699 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-08-13 03:17:56,760 [salt.state       :300 ][INFO    ][28165] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-08-13 03:17:56,760 [salt.state       :1951][INFO    ][28165] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:17:56.760709 duration_in_ms=61.5
2019-08-13 03:17:56,761 [salt.state       :1780][INFO    ][28165] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:17:56.761247
2019-08-13 03:17:56,761 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-08-13 03:17:56,839 [salt.state       :300 ][INFO    ][28165] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-08-13 03:17:56,839 [salt.state       :1951][INFO    ][28165] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:17:56.839415 duration_in_ms=78.167
2019-08-13 03:17:56,839 [salt.state       :1780][INFO    ][28165] Running state [/root/.pgpass] at time 03:17:56.839713
2019-08-13 03:17:56,840 [salt.state       :1813][INFO    ][28165] Executing state file.managed for [/root/.pgpass]
2019-08-13 03:17:56,894 [salt.state       :300 ][INFO    ][28165] File /root/.pgpass is in the correct state
2019-08-13 03:17:56,895 [salt.state       :1951][INFO    ][28165] Completed state [/root/.pgpass] at time 03:17:56.895101 duration_in_ms=55.388
2019-08-13 03:17:56,900 [salt.state       :1780][INFO    ][28165] Running state [maas-region syncdb --noinput] at time 03:17:56.900585
2019-08-13 03:17:56,900 [salt.state       :1813][INFO    ][28165] Executing state cmd.run for [maas-region syncdb --noinput]
2019-08-13 03:17:56,901 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-08-13 03:18:00,468 [salt.state       :300 ][INFO    ][28165] {'pid': 28197, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sessions, auth, piston3, maasserver, contenttypes, metadataserver, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-08-13 03:18:00,469 [salt.state       :1951][INFO    ][28165] Completed state [maas-region syncdb --noinput] at time 03:18:00.469299 duration_in_ms=3568.712
2019-08-13 03:18:00,470 [salt.state       :2022][WARNING ][28165] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-13 03:18:00,474 [salt.state       :1780][INFO    ][28165] Running state [maas-regiond] at time 03:18:00.474689
2019-08-13 03:18:00,475 [salt.state       :1813][INFO    ][28165] Executing state service.running for [maas-regiond]
2019-08-13 03:18:00,477 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-08-13 03:18:00,525 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-08-13 03:18:00,545 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-08-13 03:18:00,569 [salt.state       :300 ][INFO    ][28165] The service maas-regiond is already running
2019-08-13 03:18:00,571 [salt.state       :1951][INFO    ][28165] Completed state [maas-regiond] at time 03:18:00.569618 duration_in_ms=94.929
2019-08-13 03:18:00,576 [salt.state       :1780][INFO    ][28165] Running state [bind9] at time 03:18:00.576104
2019-08-13 03:18:00,577 [salt.state       :1813][INFO    ][28165] Executing state service.running for [bind9]
2019-08-13 03:18:00,581 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-08-13 03:18:00,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-08-13 03:18:00,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-08-13 03:18:00,653 [salt.state       :300 ][INFO    ][28165] The service bind9 is already running
2019-08-13 03:18:00,655 [salt.state       :1951][INFO    ][28165] Completed state [bind9] at time 03:18:00.655673 duration_in_ms=79.572
2019-08-13 03:18:00,659 [salt.state       :1780][INFO    ][28165] Running state [apache2] at time 03:18:00.658928
2019-08-13 03:18:00,659 [salt.state       :1813][INFO    ][28165] Executing state service.running for [apache2]
2019-08-13 03:18:00,661 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-08-13 03:18:00,687 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-08-13 03:18:00,713 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-08-13 03:18:00,749 [salt.state       :300 ][INFO    ][28165] The service apache2 is already running
2019-08-13 03:18:00,751 [salt.state       :1951][INFO    ][28165] Completed state [apache2] at time 03:18:00.750812 duration_in_ms=91.882
2019-08-13 03:18:00,754 [salt.state       :1780][INFO    ][28165] Running state [maasng.wait_for_http_code] at time 03:18:00.754142
2019-08-13 03:18:00,754 [salt.state       :1813][INFO    ][28165] Executing state module.run for [maasng.wait_for_http_code]
2019-08-13 03:18:00,755 [salt.utils.decorators:613 ][WARNING ][28165] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:18:00,913 [salt.state       :300 ][INFO    ][28165] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-08-13 03:18:00,913 [salt.state       :1951][INFO    ][28165] Completed state [maasng.wait_for_http_code] at time 03:18:00.913614 duration_in_ms=159.472
2019-08-13 03:18:00,916 [salt.state       :1780][INFO    ][28165] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:18:00.916476
2019-08-13 03:18:00,916 [salt.state       :1813][INFO    ][28165] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-08-13 03:18:00,917 [salt.state       :300 ][INFO    ][28165] /var/lib/maas/.setup_admin exists
2019-08-13 03:18:00,917 [salt.state       :1951][INFO    ][28165] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:18:00.917515 duration_in_ms=1.039
2019-08-13 03:18:00,918 [salt.state       :1780][INFO    ][28165] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:18:00.918558
2019-08-13 03:18:00,918 [salt.state       :1813][INFO    ][28165] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:18:00,919 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28165] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:18:02,897 [salt.state       :300 ][INFO    ][28165] {'pid': 28219, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:18:02,898 [salt.state       :1951][INFO    ][28165] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:18:02.898730 duration_in_ms=1980.17
2019-08-13 03:18:02,910 [salt.state       :1780][INFO    ][28165] Running state [maas_region_boot_source_resources_mirror] at time 03:18:02.910661
2019-08-13 03:18:02,911 [salt.state       :1813][INFO    ][28165] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-08-13 03:18:03,017 [salt.state       :300 ][INFO    ][28165] {'changes': {}}
2019-08-13 03:18:03,018 [salt.state       :1951][INFO    ][28165] Completed state [maas_region_boot_source_resources_mirror] at time 03:18:03.018264 duration_in_ms=107.604
2019-08-13 03:18:03,019 [salt.state       :1780][INFO    ][28165] Running state [maasng.boot_resources_import] at time 03:18:03.019425
2019-08-13 03:18:03,020 [salt.state       :1813][INFO    ][28165] Executing state module.run for [maasng.boot_resources_import]
2019-08-13 03:18:03,020 [salt.utils.decorators:613 ][WARNING ][28165] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:18:03,130 [salt.loaded.ext.module.maasng:1600][INFO    ][28165] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-08-13 03:18:08,180 [salt.loaded.ext.module.maasng:1600][INFO    ][28165] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-08-13 03:18:08,684 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031808675722
2019-08-13 03:18:08,708 [salt.minion      :1432][INFO    ][28251] Starting a new job with PID 28251
2019-08-13 03:18:08,736 [salt.minion      :1711][INFO    ][28251] Returning information for job: 20190813031808675722
2019-08-13 03:18:13,271 [salt.state       :300 ][INFO    ][28165] {'ret': True}
2019-08-13 03:18:13,272 [salt.state       :1951][INFO    ][28165] Completed state [maasng.boot_resources_import] at time 03:18:13.272211 duration_in_ms=10252.785
2019-08-13 03:18:13,273 [salt.state       :1780][INFO    ][28165] Running state [maas_region_boot_sources_selection_xenial] at time 03:18:13.273092
2019-08-13 03:18:13,273 [salt.state       :1813][INFO    ][28165] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-08-13 03:18:13,471 [salt.state       :300 ][INFO    ][28165] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-08-13 03:18:13,471 [salt.state       :1951][INFO    ][28165] Completed state [maas_region_boot_sources_selection_xenial] at time 03:18:13.471798 duration_in_ms=198.705
2019-08-13 03:18:13,472 [salt.state       :1780][INFO    ][28165] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:18:13.472687
2019-08-13 03:18:13,473 [salt.state       :1813][INFO    ][28165] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-08-13 03:18:13,473 [salt.utils.decorators:613 ][WARNING ][28165] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:18:13,474 [salt.loaded.ext.module.maasng:1771][INFO    ][28165] boot-sources sync initiated for ALL Rack's
2019-08-13 03:18:14,487 [salt.state       :300 ][INFO    ][28165] {'ret': True}
2019-08-13 03:18:14,487 [salt.state       :1951][INFO    ][28165] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:18:14.487874 duration_in_ms=1015.187
2019-08-13 03:18:14,489 [salt.state       :1780][INFO    ][28165] Running state [maas.process_maas_config] at time 03:18:14.489172
2019-08-13 03:18:14,489 [salt.state       :1813][INFO    ][28165] Executing state module.run for [maas.process_maas_config]
2019-08-13 03:18:14,490 [salt.utils.decorators:613 ][WARNING ][28165] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:18:14,491 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=enable_http_proxy value=True
2019-08-13 03:18:14,546 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=upstream_dns value=8.8.8.8
2019-08-13 03:18:14,597 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=commissioning_distro_series value=xenial
2019-08-13 03:18:14,664 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=default_osystem value=ubuntu
2019-08-13 03:18:14,713 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=active_discovery_interval value=600
2019-08-13 03:18:15,923 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=dnssec_validation value=no
2019-08-13 03:18:15,972 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=maas_name value=mas01
2019-08-13 03:18:16,027 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=network_discovery value=enabled
2019-08-13 03:18:16,164 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=enable_third_party_drivers value=True
2019-08-13 03:18:16,220 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=default_storage_layout value=lvm
2019-08-13 03:18:16,270 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=ntp_external_only value=True
2019-08-13 03:18:16,332 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=disk_erase_with_secure_erase value=False
2019-08-13 03:18:16,388 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=default_distro_series value=xenial
2019-08-13 03:18:16,470 [salt.loaded.ext.module.maas:92  ][INFO    ][28165] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-08-13 03:18:16,595 [salt.state       :300 ][INFO    ][28165] {'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-08-13 03:18:16,596 [salt.state       :1951][INFO    ][28165] Completed state [maas.process_maas_config] at time 03:18:16.596033 duration_in_ms=2106.86
2019-08-13 03:18:16,597 [salt.state       :1780][INFO    ][28165] Running state [pxe_admin] at time 03:18:16.596955
2019-08-13 03:18:16,597 [salt.state       :1813][INFO    ][28165] Executing state maasng.fabric_present for [pxe_admin]
2019-08-13 03:18:16,651 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'fabric-2'}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'adhqm4', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'pxe_admin'}]
2019-08-13 03:18:16,717 [salt.loaded.ext.module.maasng:1008][WARNING ][28165] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-08-13 03:18:16,719 [salt.loaded.ext.module.maasng:1011][WARNING ][28165] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-08-13 03:18:16,790 [salt.state       :300 ][INFO    ][28165] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-08-13 03:18:16,791 [salt.state       :1951][INFO    ][28165] Completed state [pxe_admin] at time 03:18:16.791143 duration_in_ms=194.187
2019-08-13 03:18:16,791 [salt.state       :1780][INFO    ][28165] Running state [vlan 0] at time 03:18:16.791596
2019-08-13 03:18:16,792 [salt.state       :1813][INFO    ][28165] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-13 03:18:16,859 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-2', u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'adhqm4', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-13 03:18:16,964 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-2', u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'adhqm4', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-13 03:18:17,206 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {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': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-13 03:18:17,299 [salt.state       :300 ][INFO    ][28165] {'new': 'Vlan untagged was updated'}
2019-08-13 03:18:17,300 [salt.state       :1951][INFO    ][28165] Completed state [vlan 0] at time 03:18:17.300101 duration_in_ms=508.504
2019-08-13 03:18:17,301 [salt.state       :1780][INFO    ][28165] Running state [192.168.11.0/24] at time 03:18:17.301294
2019-08-13 03:18:17,301 [salt.state       :1813][INFO    ][28165] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-08-13 03:18:17,480 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-13 03:18:17,480 [salt.loaded.ext.module.maasng:1235][WARNING ][28165] Ignoring parameter vlan:0
2019-08-13 03:18:17,560 [salt.state       :300 ][INFO    ][28165] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-08-13 03:18:17,561 [salt.state       :1951][INFO    ][28165] Completed state [192.168.11.0/24] at time 03:18:17.561111 duration_in_ms=259.816
2019-08-13 03:18:17,562 [salt.state       :1780][INFO    ][28165] Running state [maas_create_iprange_1] at time 03:18:17.562746
2019-08-13 03:18:17,563 [salt.state       :1813][INFO    ][28165] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-08-13 03:18:17,622 [salt.state       :300 ][INFO    ][28165] Iprange maas_create_iprange_1 already exist.
2019-08-13 03:18:17,622 [salt.state       :1951][INFO    ][28165] Completed state [maas_create_iprange_1] at time 03:18:17.622463 duration_in_ms=59.717
2019-08-13 03:18:17,622 [salt.state       :1780][INFO    ][28165] Running state [vlan 0] at time 03:18:17.622807
2019-08-13 03:18:17,623 [salt.state       :1813][INFO    ][28165] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-13 03:18:17,673 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'name': u'fabric-2', u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'adhqm4', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-13 03:18:17,766 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'fabric-2'}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'adhqm4', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'pxe_admin'}]
2019-08-13 03:18:18,008 [salt.loaded.ext.module.maasng:945 ][INFO    ][28165] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'adhqm4', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-13 03:18:18,128 [salt.state       :300 ][INFO    ][28165] {'new': 'Vlan untagged was updated'}
2019-08-13 03:18:18,128 [salt.state       :1951][INFO    ][28165] Completed state [vlan 0] at time 03:18:18.128374 duration_in_ms=505.566
2019-08-13 03:18:18,129 [salt.state       :1780][INFO    ][28165] Running state [opnfv] at time 03:18:18.129216
2019-08-13 03:18:18,129 [salt.state       :1813][INFO    ][28165] Executing state maasng.sshkey_present for [opnfv]
2019-08-13 03:18:18,204 [salt.loaded.ext.module.maasng:1903][INFO    ][28165] [{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-08-13 03:18:18,205 [salt.state       :300 ][INFO    ][28165] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-08-13 03:18:18,205 [salt.state       :1951][INFO    ][28165] Completed state [opnfv] at time 03:18:18.205364 duration_in_ms=76.148
2019-08-13 03:18:18,211 [salt.minion      :1711][INFO    ][28165] Returning information for job: 20190813031753591229
2019-08-13 03:18:18,979 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813031818971043
2019-08-13 03:18:18,995 [salt.minion      :1432][INFO    ][28608] Starting a new job with PID 28608
2019-08-13 03:18:25,143 [salt.state       :915 ][INFO    ][28608] Loading fresh modules for state activity
2019-08-13 03:18:25,274 [salt.state       :1780][INFO    ][28608] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:18:25.273687
2019-08-13 03:18:25,274 [salt.state       :1813][INFO    ][28608] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:18:25,276 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28608] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:18:27,212 [salt.state       :300 ][INFO    ][28608] {'pid': 28631, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:18:27,214 [salt.state       :1951][INFO    ][28608] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:18:27.213636 duration_in_ms=1939.949
2019-08-13 03:18:27,217 [salt.state       :1780][INFO    ][28608] Running state [maas.process_machines] at time 03:18:27.217011
2019-08-13 03:18:27,217 [salt.state       :1813][INFO    ][28608] Executing state module.run for [maas.process_machines]
2019-08-13 03:18:27,219 [salt.utils.decorators:613 ][WARNING ][28608] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:18:27,820 [salt.loaded.ext.module.maas:412 ][WARNING ][28608] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 03:18:27,821 [salt.loaded.ext.module.maas:92  ][INFO    ][28608] 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=htesnf architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 03:18:29,097 [salt.loaded.ext.module.maas:412 ][WARNING ][28608] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 03:18:29,098 [salt.loaded.ext.module.maas:92  ][INFO    ][28608] 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=ed6yan architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 03:18:30,387 [salt.loaded.ext.module.maas:412 ][WARNING ][28608] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 03:18:30,388 [salt.loaded.ext.module.maas:92  ][INFO    ][28608] machine hostname=kvm01 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=6e3e4m architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 03:18:31,700 [salt.loaded.ext.module.maas:412 ][WARNING ][28608] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 03:18:31,702 [salt.loaded.ext.module.maas:92  ][INFO    ][28608] machine hostname=kvm03 power_type=ipmi mac_addresses=['14:58:d0:54:7a:28'] power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 system_id=y8frmk architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 03:18:32,915 [salt.loaded.ext.module.maas:412 ][WARNING ][28608] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-13 03:18:32,916 [salt.loaded.ext.module.maas:92  ][INFO    ][28608] machine hostname=kvm02 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=fb3mpe architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-13 03:18:34,006 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031833994733
2019-08-13 03:18:34,029 [salt.minion      :1432][INFO    ][28856] Starting a new job with PID 28856
2019-08-13 03:18:34,056 [salt.minion      :1711][INFO    ][28856] Returning information for job: 20190813031833994733
2019-08-13 03:18:34,200 [salt.state       :300 ][INFO    ][28608] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-08-13 03:18:34,201 [salt.state       :1951][INFO    ][28608] Completed state [maas.process_machines] at time 03:18:34.200892 duration_in_ms=6983.878
2019-08-13 03:18:34,207 [salt.minion      :1711][INFO    ][28608] Returning information for job: 20190813031818971043
2019-08-13 03:19:08,237 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813031908224667
2019-08-13 03:19:08,260 [salt.minion      :1432][INFO    ][28904] Starting a new job with PID 28904
2019-08-13 03:19:14,349 [salt.state       :915 ][INFO    ][28904] Loading fresh modules for state activity
2019-08-13 03:19:14,478 [salt.state       :1780][INFO    ][28904] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:19:14.477995
2019-08-13 03:19:14,478 [salt.state       :1813][INFO    ][28904] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:19:14,480 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28904] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:19:16,547 [salt.state       :300 ][INFO    ][28904] {'pid': 28914, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:19:16,549 [salt.state       :1951][INFO    ][28904] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:19:16.548969 duration_in_ms=2070.973
2019-08-13 03:19:16,553 [salt.state       :1780][INFO    ][28904] Running state [maas.wait_for_machine_status] at time 03:19:16.552945
2019-08-13 03:19:16,553 [salt.state       :1813][INFO    ][28904] Executing state module.run for [maas.wait_for_machine_status]
2019-08-13 03:19:16,554 [salt.utils.decorators:613 ][WARNING ][28904] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:19:17,852 [salt.loaded.ext.module.maas:993 ][INFO    ][28904] Machine ed6yan mark broken
2019-08-13 03:19:18,420 [salt.loaded.ext.module.maas:996 ][INFO    ][28904] Machine ed6yan mark fixed
2019-08-13 03:19:19,467 [salt.loaded.ext.module.maas:684 ][INFO    ][28904] deploymachines hwe_kernel=ga-16.04 system_id=ed6yan distro_series=xenial
2019-08-13 03:19:23,369 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031923305092
2019-08-13 03:19:23,388 [salt.minion      :1432][INFO    ][28985] Starting a new job with PID 28985
2019-08-13 03:19:23,421 [salt.minion      :1711][INFO    ][28985] Returning information for job: 20190813031923305092
2019-08-13 03:19:23,783 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1492.78939509s left)
2019-08-13 03:19:53,459 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813031953446854
2019-08-13 03:19:53,487 [salt.minion      :1432][INFO    ][29042] Starting a new job with PID 29042
2019-08-13 03:19:53,520 [salt.minion      :1711][INFO    ][29042] Returning information for job: 20190813031953446854
2019-08-13 03:19:56,931 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1459.64181805s left)
2019-08-13 03:20:23,576 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032023560805
2019-08-13 03:20:23,603 [salt.minion      :1432][INFO    ][29061] Starting a new job with PID 29061
2019-08-13 03:20:23,629 [salt.minion      :1711][INFO    ][29061] Returning information for job: 20190813032023560805
2019-08-13 03:20:29,825 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1426.74734211s left)
2019-08-13 03:20:53,668 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032053648169
2019-08-13 03:20:53,699 [salt.minion      :1432][INFO    ][29118] Starting a new job with PID 29118
2019-08-13 03:20:53,737 [salt.minion      :1711][INFO    ][29118] Returning information for job: 20190813032053648169
2019-08-13 03:21:02,745 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1393.82799602s left)
2019-08-13 03:21:23,773 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032123761170
2019-08-13 03:21:23,792 [salt.minion      :1432][INFO    ][29138] Starting a new job with PID 29138
2019-08-13 03:21:23,824 [salt.minion      :1711][INFO    ][29138] Returning information for job: 20190813032123761170
2019-08-13 03:21:35,715 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1360.85739994s left)
2019-08-13 03:21:53,859 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032153841692
2019-08-13 03:21:53,886 [salt.minion      :1432][INFO    ][29195] Starting a new job with PID 29195
2019-08-13 03:21:53,916 [salt.minion      :1711][INFO    ][29195] Returning information for job: 20190813032153841692
2019-08-13 03:22:08,740 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1327.83298492s left)
2019-08-13 03:22:23,948 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032223933272
2019-08-13 03:22:23,976 [salt.minion      :1432][INFO    ][29236] Starting a new job with PID 29236
2019-08-13 03:22:24,007 [salt.minion      :1711][INFO    ][29236] Returning information for job: 20190813032223933272
2019-08-13 03:22:41,670 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1294.90255404s left)
2019-08-13 03:22:54,067 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032254051097
2019-08-13 03:22:54,093 [salt.minion      :1432][INFO    ][29376] Starting a new job with PID 29376
2019-08-13 03:22:54,124 [salt.minion      :1711][INFO    ][29376] Returning information for job: 20190813032254051097
2019-08-13 03:23:14,561 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1262.01219201s left)
2019-08-13 03:23:24,179 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032324163655
2019-08-13 03:23:24,210 [salt.minion      :1432][INFO    ][29403] Starting a new job with PID 29403
2019-08-13 03:23:24,241 [salt.minion      :1711][INFO    ][29403] Returning information for job: 20190813032324163655
2019-08-13 03:23:48,483 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1228.08940792s left)
2019-08-13 03:23:54,299 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032354282269
2019-08-13 03:23:54,329 [salt.minion      :1432][INFO    ][29571] Starting a new job with PID 29571
2019-08-13 03:23:54,358 [salt.minion      :1711][INFO    ][29571] Returning information for job: 20190813032354282269
2019-08-13 03:24:21,439 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1195.13358998s left)
2019-08-13 03:24:24,428 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032424411484
2019-08-13 03:24:24,456 [salt.minion      :1432][INFO    ][29596] Starting a new job with PID 29596
2019-08-13 03:24:24,487 [salt.minion      :1711][INFO    ][29596] Returning information for job: 20190813032424411484
2019-08-13 03:24:54,329 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1162.24355102s left)
2019-08-13 03:24:54,559 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032454547252
2019-08-13 03:24:54,584 [salt.minion      :1432][INFO    ][29740] Starting a new job with PID 29740
2019-08-13 03:24:54,616 [salt.minion      :1711][INFO    ][29740] Returning information for job: 20190813032454547252
2019-08-13 03:25:24,689 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032524675267
2019-08-13 03:25:24,712 [salt.minion      :1432][INFO    ][29763] Starting a new job with PID 29763
2019-08-13 03:25:24,739 [salt.minion      :1711][INFO    ][29763] Returning information for job: 20190813032524675267
2019-08-13 03:25:27,325 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1129.24802613s left)
2019-08-13 03:25:54,817 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032554803488
2019-08-13 03:25:54,847 [salt.minion      :1432][INFO    ][29874] Starting a new job with PID 29874
2019-08-13 03:25:54,877 [salt.minion      :1711][INFO    ][29874] Returning information for job: 20190813032554803488
2019-08-13 03:26:00,449 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1096.12354302s left)
2019-08-13 03:26:24,961 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032624943830
2019-08-13 03:26:24,992 [salt.minion      :1432][INFO    ][29900] Starting a new job with PID 29900
2019-08-13 03:26:25,025 [salt.minion      :1711][INFO    ][29900] Returning information for job: 20190813032624943830
2019-08-13 03:26:33,522 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1063.05117607s left)
2019-08-13 03:26:55,111 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032655098868
2019-08-13 03:26:55,139 [salt.minion      :1432][INFO    ][30021] Starting a new job with PID 30021
2019-08-13 03:26:55,169 [salt.minion      :1711][INFO    ][30021] Returning information for job: 20190813032655098868
2019-08-13 03:27:06,522 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (1030.05062699s left)
2019-08-13 03:27:25,277 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032725263613
2019-08-13 03:27:25,304 [salt.minion      :1432][INFO    ][30043] Starting a new job with PID 30043
2019-08-13 03:27:25,336 [salt.minion      :1711][INFO    ][30043] Returning information for job: 20190813032725263613
2019-08-13 03:27:39,540 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (997.033123016s left)
2019-08-13 03:27:55,444 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032755429076
2019-08-13 03:27:55,469 [salt.minion      :1432][INFO    ][30102] Starting a new job with PID 30102
2019-08-13 03:27:55,501 [salt.minion      :1711][INFO    ][30102] Returning information for job: 20190813032755429076
2019-08-13 03:28:12,467 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (964.106431007s left)
2019-08-13 03:28:25,605 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032825593620
2019-08-13 03:28:25,637 [salt.minion      :1432][INFO    ][30122] Starting a new job with PID 30122
2019-08-13 03:28:25,673 [salt.minion      :1711][INFO    ][30122] Returning information for job: 20190813032825593620
2019-08-13 03:28:45,483 [salt.loaded.ext.module.maas:1023][INFO    ][28904] Waiting status:Ready|Deployed for machines:['cmp001']
sleep for:30s Timeout:1500s (931.089842081s left)
2019-08-13 03:28:55,792 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command saltutil.find_job with jid 20190813032855778992
2019-08-13 03:28:55,821 [salt.minion      :1432][INFO    ][30178] Starting a new job with PID 30178
2019-08-13 03:28:55,851 [salt.minion      :1711][INFO    ][30178] Returning information for job: 20190813032855778992
2019-08-13 03:29:18,636 [salt.state       :300 ][INFO    ][28904] {'ret': True}
2019-08-13 03:29:18,639 [salt.state       :1951][INFO    ][28904] Completed state [maas.wait_for_machine_status] at time 03:29:18.637526 duration_in_ms=602084.574
2019-08-13 03:29:18,643 [salt.minion      :1711][INFO    ][28904] Returning information for job: 20190813031908224667
2019-08-13 03:29:19,365 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813032919351607
2019-08-13 03:29:19,396 [salt.minion      :1432][INFO    ][30217] Starting a new job with PID 30217
2019-08-13 03:29:25,727 [salt.state       :915 ][INFO    ][30217] Loading fresh modules for state activity
2019-08-13 03:29:25,904 [salt.state       :1780][INFO    ][30217] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:25.903921
2019-08-13 03:29:25,904 [salt.state       :1813][INFO    ][30217] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:29:25,906 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30217] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:29:27,848 [salt.state       :300 ][INFO    ][30217] {'pid': 30232, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:29:27,849 [salt.state       :1951][INFO    ][30217] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:27.848982 duration_in_ms=1945.061
2019-08-13 03:29:27,853 [salt.state       :1780][INFO    ][30217] Running state [maas_machines_storage_cmp002_lvm] at time 03:29:27.852991
2019-08-13 03:29:27,853 [salt.state       :1813][INFO    ][30217] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-08-13 03:29:28,596 [salt.state       :300 ][INFO    ][30217] Machine cmp002 is not in Ready state.
2019-08-13 03:29:28,597 [salt.state       :1951][INFO    ][30217] Completed state [maas_machines_storage_cmp002_lvm] at time 03:29:28.597065 duration_in_ms=744.072
2019-08-13 03:29:28,599 [salt.state       :1780][INFO    ][30217] Running state [maas_machines_storage_cmp001_lvm] at time 03:29:28.599503
2019-08-13 03:29:28,599 [salt.state       :1813][INFO    ][30217] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-08-13 03:29:29,194 [salt.state       :300 ][INFO    ][30217] Machine cmp001 is not in Ready state.
2019-08-13 03:29:29,195 [salt.state       :1951][INFO    ][30217] Completed state [maas_machines_storage_cmp001_lvm] at time 03:29:29.195495 duration_in_ms=595.991
2019-08-13 03:29:29,202 [salt.minion      :1711][INFO    ][30217] Returning information for job: 20190813032919351607
2019-08-13 03:29:29,919 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813032929909042
2019-08-13 03:29:29,944 [salt.minion      :1432][INFO    ][30242] Starting a new job with PID 30242
2019-08-13 03:29:31,180 [salt.state       :915 ][INFO    ][30242] Loading fresh modules for state activity
2019-08-13 03:29:31,298 [salt.state       :1780][INFO    ][30242] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:31.298077
2019-08-13 03:29:31,298 [salt.state       :1813][INFO    ][30242] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:29:31,300 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30242] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:29:33,223 [salt.state       :300 ][INFO    ][30242] {'pid': 30261, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:29:33,224 [salt.state       :1951][INFO    ][30242] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:33.224195 duration_in_ms=1926.116
2019-08-13 03:29:33,227 [salt.state       :1780][INFO    ][30242] Running state [maas.deploy_machines] at time 03:29:33.227730
2019-08-13 03:29:33,228 [salt.state       :1813][INFO    ][30242] Executing state module.run for [maas.deploy_machines]
2019-08-13 03:29:33,229 [salt.utils.decorators:613 ][WARNING ][30242] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:29:33,809 [salt.state       :300 ][INFO    ][30242] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-08-13 03:29:33,810 [salt.state       :1951][INFO    ][30242] Completed state [maas.deploy_machines] at time 03:29:33.810086 duration_in_ms=582.356
2019-08-13 03:29:33,814 [salt.minion      :1711][INFO    ][30242] Returning information for job: 20190813032929909042
2019-08-13 03:29:34,528 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command state.apply with jid 20190813032934509392
2019-08-13 03:29:34,553 [salt.minion      :1432][INFO    ][30270] Starting a new job with PID 30270
2019-08-13 03:29:35,790 [salt.state       :915 ][INFO    ][30270] Loading fresh modules for state activity
2019-08-13 03:29:35,910 [salt.state       :1780][INFO    ][30270] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:35.909700
2019-08-13 03:29:35,910 [salt.state       :1813][INFO    ][30270] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-13 03:29:35,912 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30270] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-13 03:29:37,836 [salt.state       :300 ][INFO    ][30270] {'pid': 30277, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-13 03:29:37,838 [salt.state       :1951][INFO    ][30270] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:37.837618 duration_in_ms=1927.916
2019-08-13 03:29:37,841 [salt.state       :1780][INFO    ][30270] Running state [maas.wait_for_machine_status] at time 03:29:37.840972
2019-08-13 03:29:37,841 [salt.state       :1813][INFO    ][30270] Executing state module.run for [maas.wait_for_machine_status]
2019-08-13 03:29:37,841 [salt.utils.decorators:613 ][WARNING ][30270] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-13 03:29:40,721 [salt.state       :300 ][INFO    ][30270] {'ret': True}
2019-08-13 03:29:40,722 [salt.state       :1951][INFO    ][30270] Completed state [maas.wait_for_machine_status] at time 03:29:40.722471 duration_in_ms=2881.498
2019-08-13 03:29:40,726 [salt.minion      :1711][INFO    ][30270] Returning information for job: 20190813032934509392
2019-08-13 04:04:37,611 [salt.utils.schedule:1377][INFO    ][3077] Running scheduled job: __mine_interval
2019-08-13 05:01:02,213 [salt.minion      :1308][INFO    ][3077] User sudo_ubuntu Executing command cp.push_dir with jid 20190813050102197200
2019-08-13 05:01:02,242 [salt.minion      :1432][INFO    ][36667] Starting a new job with PID 36667
