2019-06-26 20:06:39,129 [salt.utils.decorators:613 ][WARNING ][2351] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:06:40,280 [salt.utils.decorators:613 ][WARNING ][2351] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:06:44,171 [salt.loaded.int.states.file:2298][WARNING ][2611] 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-06-26 20:07:06,704 [salt.state       :2022][WARNING ][2863] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-26 20:07:08,912 [salt.utils.decorators:613 ][WARNING ][2863] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:07:24,212 [salt.utils.decorators:613 ][WARNING ][2863] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:07:51,115 [salt.utils.decorators:613 ][WARNING ][2863] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:07:52,273 [salt.utils.decorators:613 ][WARNING ][2863] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:07:54,769 [salt.loaded.ext.module.maasng:1008][WARNING ][2863] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-06-26 20:07:54,772 [salt.loaded.ext.module.maasng:1011][WARNING ][2863] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-06-26 20:07:55,516 [salt.loaded.ext.module.maasng:1235][WARNING ][2863] Ignoring parameter vlan:0
2019-06-26 20:07:56,472 [salt.utils.decorators:613 ][WARNING ][2863] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:07:59,875 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5420] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-26 20:07:59,911 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5420] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-26 20:07:59,973 [salt.utils.parsers:1051][WARNING ][382] Minion received a SIGTERM. Exiting.
2019-06-26 20:08:01,092 [salt.cli.daemons :293 ][INFO    ][5494] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-06-26 20:08:01,264 [salt.cli.daemons :82  ][INFO    ][5494] Starting up the Salt Minion
2019-06-26 20:08:01,265 [salt.utils.event :1017][INFO    ][5494] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-06-26 20:08:02,489 [salt.minion      :976 ][INFO    ][5494] Creating minion process manager
2019-06-26 20:08:04,504 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5494] Executing command ['date', '+%z'] in directory '/root'
2019-06-26 20:08:04,525 [salt.utils.schedule:568 ][INFO    ][5494] Updating job settings for scheduled job: __mine_interval
2019-06-26 20:08:04,529 [salt.minion      :1108][INFO    ][5494] Added mine.update to scheduler
2019-06-26 20:08:04,534 [salt.minion      :1975][INFO    ][5494] Minion is starting as user 'root'
2019-06-26 20:08:04,547 [salt.minion      :2336][INFO    ][5494] Minion is ready to receive requests!
2019-06-26 20:08:08,253 [salt.utils.decorators:613 ][WARNING ][5428] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:08:08,331 [salt.loaded.ext.module.maas:412 ][WARNING ][5428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:08:09,919 [salt.loaded.ext.module.maas:412 ][WARNING ][5428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:08:11,664 [salt.loaded.ext.module.maas:412 ][WARNING ][5428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:08:12,536 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626200812526684
2019-06-26 20:08:12,561 [salt.minion      :1432][INFO    ][5758] Starting a new job with PID 5758
2019-06-26 20:08:12,593 [salt.minion      :1711][INFO    ][5758] Returning information for job: 20190626200812526684
2019-06-26 20:08:13,114 [salt.loaded.ext.module.maas:412 ][WARNING ][5428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:08:46,045 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626200846024951
2019-06-26 20:08:46,072 [salt.minion      :1432][INFO    ][5851] Starting a new job with PID 5851
2019-06-26 20:08:54,247 [salt.state       :915 ][INFO    ][5851] Loading fresh modules for state activity
2019-06-26 20:08:54,311 [salt.fileclient  :1219][INFO    ][5851] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-26 20:08:54,375 [salt.state       :1780][INFO    ][5851] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:08:54.375103
2019-06-26 20:08:54,375 [salt.state       :1813][INFO    ][5851] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 20:08:54,377 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5851] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 20:08:56,239 [salt.state       :300 ][INFO    ][5851] {'pid': 5873, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 20:08:56,240 [salt.state       :1951][INFO    ][5851] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:08:56.240718 duration_in_ms=1865.615
2019-06-26 20:08:56,245 [salt.state       :1780][INFO    ][5851] Running state [maas.wait_for_machine_status] at time 20:08:56.245279
2019-06-26 20:08:56,247 [salt.state       :1813][INFO    ][5851] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 20:08:56,248 [salt.utils.decorators:613 ][WARNING ][5851] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:08:56,892 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.38287091s left)
2019-06-26 20:09:01,107 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626200901096701
2019-06-26 20:09:01,133 [salt.minion      :1432][INFO    ][5884] Starting a new job with PID 5884
2019-06-26 20:09:01,161 [salt.minion      :1711][INFO    ][5884] Returning information for job: 20190626200901096701
2019-06-26 20:09:27,536 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.73880982s left)
2019-06-26 20:09:31,209 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626200931193356
2019-06-26 20:09:31,237 [salt.minion      :1432][INFO    ][5927] Starting a new job with PID 5927
2019-06-26 20:09:31,268 [salt.minion      :1711][INFO    ][5927] Returning information for job: 20190626200931193356
2019-06-26 20:09:58,163 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1438.11158895s left)
2019-06-26 20:10:01,332 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201001320735
2019-06-26 20:10:01,362 [salt.minion      :1432][INFO    ][5957] Starting a new job with PID 5957
2019-06-26 20:10:01,396 [salt.minion      :1711][INFO    ][5957] Returning information for job: 20190626201001320735
2019-06-26 20:10:28,818 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1407.4561038s left)
2019-06-26 20:10:31,419 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201031400951
2019-06-26 20:10:31,446 [salt.minion      :1432][INFO    ][6005] Starting a new job with PID 6005
2019-06-26 20:10:31,473 [salt.minion      :1711][INFO    ][6005] Returning information for job: 20190626201031400951
2019-06-26 20:10:59,603 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1376.6715579s left)
2019-06-26 20:11:01,497 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201101479775
2019-06-26 20:11:01,524 [salt.minion      :1432][INFO    ][6065] Starting a new job with PID 6065
2019-06-26 20:11:01,552 [salt.minion      :1711][INFO    ][6065] Returning information for job: 20190626201101479775
2019-06-26 20:11:30,483 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1345.79108095s left)
2019-06-26 20:11:31,596 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201131582854
2019-06-26 20:11:31,620 [salt.minion      :1432][INFO    ][6181] Starting a new job with PID 6181
2019-06-26 20:11:31,650 [salt.minion      :1711][INFO    ][6181] Returning information for job: 20190626201131582854
2019-06-26 20:12:01,345 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1314.92985988s left)
2019-06-26 20:12:01,699 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201201685272
2019-06-26 20:12:01,726 [salt.minion      :1432][INFO    ][6255] Starting a new job with PID 6255
2019-06-26 20:12:01,752 [salt.minion      :1711][INFO    ][6255] Returning information for job: 20190626201201685272
2019-06-26 20:12:31,837 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201231824238
2019-06-26 20:12:31,860 [salt.minion      :1432][INFO    ][6585] Starting a new job with PID 6585
2019-06-26 20:12:31,894 [salt.minion      :1711][INFO    ][6585] Returning information for job: 20190626201231824238
2019-06-26 20:12:32,327 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1283.94762897s left)
2019-06-26 20:13:01,950 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201301932693
2019-06-26 20:13:01,978 [salt.minion      :1432][INFO    ][6672] Starting a new job with PID 6672
2019-06-26 20:13:02,006 [salt.minion      :1711][INFO    ][6672] Returning information for job: 20190626201301932693
2019-06-26 20:13:03,701 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1252.57389283s left)
2019-06-26 20:13:32,107 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201332094950
2019-06-26 20:13:32,131 [salt.minion      :1432][INFO    ][6844] Starting a new job with PID 6844
2019-06-26 20:13:32,158 [salt.minion      :1711][INFO    ][6844] Returning information for job: 20190626201332094950
2019-06-26 20:13:35,164 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1221.1102109s left)
2019-06-26 20:14:02,225 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201402209387
2019-06-26 20:14:02,254 [salt.minion      :1432][INFO    ][6927] Starting a new job with PID 6927
2019-06-26 20:14:02,285 [salt.minion      :1711][INFO    ][6927] Returning information for job: 20190626201402209387
2019-06-26 20:14:06,707 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1189.56707978s left)
2019-06-26 20:14:32,362 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201432343047
2019-06-26 20:14:32,394 [salt.minion      :1432][INFO    ][7020] Starting a new job with PID 7020
2019-06-26 20:14:32,423 [salt.minion      :1711][INFO    ][7020] Returning information for job: 20190626201432343047
2019-06-26 20:14:38,136 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1158.13829184s left)
2019-06-26 20:15:02,513 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201502494336
2019-06-26 20:15:02,540 [salt.minion      :1432][INFO    ][7090] Starting a new job with PID 7090
2019-06-26 20:15:02,569 [salt.minion      :1711][INFO    ][7090] Returning information for job: 20190626201502494336
2019-06-26 20:15:10,117 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1126.15726995s left)
2019-06-26 20:15:32,664 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201532645015
2019-06-26 20:15:32,689 [salt.minion      :1432][INFO    ][7148] Starting a new job with PID 7148
2019-06-26 20:15:32,724 [salt.minion      :1711][INFO    ][7148] Returning information for job: 20190626201532645015
2019-06-26 20:15:41,900 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1094.37485385s left)
2019-06-26 20:16:02,808 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201602791264
2019-06-26 20:16:02,840 [salt.minion      :1432][INFO    ][7177] Starting a new job with PID 7177
2019-06-26 20:16:02,879 [salt.minion      :1711][INFO    ][7177] Returning information for job: 20190626201602791264
2019-06-26 20:16:13,643 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1062.63102078s left)
2019-06-26 20:16:32,968 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201632953637
2019-06-26 20:16:32,994 [salt.minion      :1432][INFO    ][7225] Starting a new job with PID 7225
2019-06-26 20:16:33,023 [salt.minion      :1711][INFO    ][7225] Returning information for job: 20190626201632953637
2019-06-26 20:16:45,365 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1030.90943193s left)
2019-06-26 20:17:03,128 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201703112810
2019-06-26 20:17:03,160 [salt.minion      :1432][INFO    ][7268] Starting a new job with PID 7268
2019-06-26 20:17:03,189 [salt.minion      :1711][INFO    ][7268] Returning information for job: 20190626201703112810
2019-06-26 20:17:17,099 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (999.175664902s left)
2019-06-26 20:17:33,284 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201733267792
2019-06-26 20:17:33,311 [salt.minion      :1432][INFO    ][7325] Starting a new job with PID 7325
2019-06-26 20:17:33,349 [salt.minion      :1711][INFO    ][7325] Returning information for job: 20190626201733267792
2019-06-26 20:17:48,797 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (967.477710962s left)
2019-06-26 20:18:03,432 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201803417643
2019-06-26 20:18:03,462 [salt.minion      :1432][INFO    ][7353] Starting a new job with PID 7353
2019-06-26 20:18:03,490 [salt.minion      :1711][INFO    ][7353] Returning information for job: 20190626201803417643
2019-06-26 20:18:19,241 [salt.loaded.ext.module.maas:981 ][INFO    ][5851] Machine gdmake deleted
2019-06-26 20:18:19,907 [salt.loaded.ext.module.maas:412 ][WARNING ][5851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:18:19,907 [salt.loaded.ext.module.maas:92  ][INFO    ][5851] machine hostname=gtw01 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 20:18:21,355 [salt.loaded.ext.module.maas:412 ][WARNING ][5851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:18:21,356 [salt.loaded.ext.module.maas:92  ][INFO    ][5851] 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=bxh6nq architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 20:18:22,586 [salt.loaded.ext.module.maas:412 ][WARNING ][5851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:18:22,587 [salt.loaded.ext.module.maas:92  ][INFO    ][5851] 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=ffgqpr architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 20:18:23,823 [salt.loaded.ext.module.maas:412 ][WARNING ][5851] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 20:18:23,825 [salt.loaded.ext.module.maas:92  ][INFO    ][5851] machine hostname=ctl01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=gqdm3y architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 20:18:26,357 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (929.917622805s left)
2019-06-26 20:18:33,616 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201833599882
2019-06-26 20:18:33,647 [salt.minion      :1432][INFO    ][7582] Starting a new job with PID 7582
2019-06-26 20:18:33,674 [salt.minion      :1711][INFO    ][7582] Returning information for job: 20190626201833599882
2019-06-26 20:18:58,188 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (898.086184978s left)
2019-06-26 20:19:03,800 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201903780871
2019-06-26 20:19:03,832 [salt.minion      :1432][INFO    ][7609] Starting a new job with PID 7609
2019-06-26 20:19:03,859 [salt.minion      :1711][INFO    ][7609] Returning information for job: 20190626201903780871
2019-06-26 20:19:29,907 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (866.367842913s left)
2019-06-26 20:19:33,992 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626201933975490
2019-06-26 20:19:34,020 [salt.minion      :1432][INFO    ][7656] Starting a new job with PID 7656
2019-06-26 20:19:34,053 [salt.minion      :1711][INFO    ][7656] Returning information for job: 20190626201933975490
2019-06-26 20:20:01,719 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (834.555377007s left)
2019-06-26 20:20:04,184 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202004171433
2019-06-26 20:20:04,206 [salt.minion      :1432][INFO    ][7685] Starting a new job with PID 7685
2019-06-26 20:20:04,237 [salt.minion      :1711][INFO    ][7685] Returning information for job: 20190626202004171433
2019-06-26 20:20:33,400 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (802.874395847s left)
2019-06-26 20:20:34,384 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202034367988
2019-06-26 20:20:34,412 [salt.minion      :1432][INFO    ][7730] Starting a new job with PID 7730
2019-06-26 20:20:34,443 [salt.minion      :1711][INFO    ][7730] Returning information for job: 20190626202034367988
2019-06-26 20:21:04,594 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202104581338
2019-06-26 20:21:04,619 [salt.minion      :1432][INFO    ][7764] Starting a new job with PID 7764
2019-06-26 20:21:04,656 [salt.minion      :1711][INFO    ][7764] Returning information for job: 20190626202104581338
2019-06-26 20:21:04,973 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (771.30167079s left)
2019-06-26 20:21:34,820 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202134805136
2019-06-26 20:21:34,842 [salt.minion      :1432][INFO    ][7812] Starting a new job with PID 7812
2019-06-26 20:21:34,869 [salt.minion      :1711][INFO    ][7812] Returning information for job: 20190626202134805136
2019-06-26 20:21:36,537 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (739.737448931s left)
2019-06-26 20:22:05,039 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202205026856
2019-06-26 20:22:05,063 [salt.minion      :1432][INFO    ][7848] Starting a new job with PID 7848
2019-06-26 20:22:05,092 [salt.minion      :1711][INFO    ][7848] Returning information for job: 20190626202205026856
2019-06-26 20:22:08,337 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (707.937912941s left)
2019-06-26 20:22:35,051 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202235043231
2019-06-26 20:22:35,074 [salt.minion      :1432][INFO    ][7928] Starting a new job with PID 7928
2019-06-26 20:22:35,100 [salt.minion      :1711][INFO    ][7928] Returning information for job: 20190626202235043231
2019-06-26 20:22:39,768 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (676.506757975s left)
2019-06-26 20:23:05,268 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202305254418
2019-06-26 20:23:05,293 [salt.minion      :1432][INFO    ][7975] Starting a new job with PID 7975
2019-06-26 20:23:05,329 [salt.minion      :1711][INFO    ][7975] Returning information for job: 20190626202305254418
2019-06-26 20:23:11,748 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (644.526768923s left)
2019-06-26 20:23:35,325 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202335303915
2019-06-26 20:23:35,357 [salt.minion      :1432][INFO    ][8088] Starting a new job with PID 8088
2019-06-26 20:23:35,387 [salt.minion      :1711][INFO    ][8088] Returning information for job: 20190626202335303915
2019-06-26 20:23:43,254 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (613.020778894s left)
2019-06-26 20:24:05,397 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202405380215
2019-06-26 20:24:05,425 [salt.minion      :1432][INFO    ][8152] Starting a new job with PID 8152
2019-06-26 20:24:05,452 [salt.minion      :1711][INFO    ][8152] Returning information for job: 20190626202405380215
2019-06-26 20:24:14,977 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (581.297319889s left)
2019-06-26 20:24:35,460 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202435446156
2019-06-26 20:24:35,487 [salt.minion      :1432][INFO    ][8275] Starting a new job with PID 8275
2019-06-26 20:24:35,513 [salt.minion      :1711][INFO    ][8275] Returning information for job: 20190626202435446156
2019-06-26 20:24:46,645 [salt.loaded.ext.module.maas:1023][INFO    ][5851] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (549.629410982s left)
2019-06-26 20:25:05,560 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202505542208
2019-06-26 20:25:05,589 [salt.minion      :1432][INFO    ][8345] Starting a new job with PID 8345
2019-06-26 20:25:05,620 [salt.minion      :1711][INFO    ][8345] Returning information for job: 20190626202505542208
2019-06-26 20:25:18,445 [salt.state       :300 ][INFO    ][5851] {'ret': True}
2019-06-26 20:25:18,447 [salt.state       :1951][INFO    ][5851] Completed state [maas.wait_for_machine_status] at time 20:25:18.447594 duration_in_ms=982202.312
2019-06-26 20:25:18,459 [salt.minion      :1711][INFO    ][5851] Returning information for job: 20190626200846024951
2019-06-26 20:25:19,271 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626202519258320
2019-06-26 20:25:19,295 [salt.minion      :1432][INFO    ][8398] Starting a new job with PID 8398
2019-06-26 20:25:27,477 [salt.state       :915 ][INFO    ][8398] Loading fresh modules for state activity
2019-06-26 20:25:27,549 [salt.fileclient  :1219][INFO    ][8398] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-26 20:25:27,662 [salt.state       :1780][INFO    ][8398] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:27.662255
2019-06-26 20:25:27,662 [salt.state       :1813][INFO    ][8398] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 20:25:27,664 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8398] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 20:25:29,517 [salt.state       :300 ][INFO    ][8398] {'pid': 8412, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 20:25:29,519 [salt.state       :1951][INFO    ][8398] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:29.518922 duration_in_ms=1856.666
2019-06-26 20:25:29,523 [salt.state       :1780][INFO    ][8398] Running state [maas_machines_storage_cmp002_lvm] at time 20:25:29.523484
2019-06-26 20:25:29,524 [salt.state       :1813][INFO    ][8398] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-26 20:25:30,395 [salt.loaded.ext.module.maasng:610 ][INFO    ][8398] bxh6nq
2019-06-26 20:25:30,396 [salt.loaded.ext.module.maasng:626 ][INFO    ][8398] sda
2019-06-26 20:25:30,804 [salt.loaded.ext.module.maasng:361 ][INFO    ][8398] bxh6nq
2019-06-26 20:25:30,903 [salt.loaded.ext.module.maasng:367 ][INFO    ][8398] [{u'size': 800109715456, u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'filesystem': None, u'name': u'sda', u'system_id': u'bxh6nq', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/', u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'partitions': [{u'uuid': u'2612d281-69ab-4df3-82c2-f9dd4d65c85f', u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/partition/1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bxh6nq', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'0e41aad4-3a41-4c68-b2c3-8bcb49caf7f3', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 1, u'device_id': 1}]}, {u'size': 800097042432, u'block_size': 4096, u'uuid': u'58d601e3-b533-456c-a839-80720f3c1065', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 800097042432, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'2cf5af7d-8f61-428e-b7f9-9b65aa5a9a62', u'mount_options': None}, u'name': u'vgroot-lvroot', u'system_id': u'bxh6nq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/3/', u'type': u'virtual', u'id': 3, u'serial': None, u'partitions': []}]
2019-06-26 20:25:30,903 [salt.loaded.ext.module.maasng:632 ][INFO    ][8398] vgroot
2019-06-26 20:25:30,903 [salt.loaded.ext.module.maasng:635 ][INFO    ][8398] lvroot
2019-06-26 20:25:30,904 [salt.loaded.ext.module.maasng:639 ][INFO    ][8398] 107374182400
2019-06-26 20:25:31,503 [salt.loaded.ext.module.maasng:645 ][INFO    ][8398] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, 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'primary_rack': u'hpd6dr', 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'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'dhcp', u'id': 15}], 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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/5/'}, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/bxh6nq/', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'bxh6nq', 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'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'uuid': u'250f30c2-aead-4ad5-acb7-84bdfd2b4b78', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'a1a6fc33-0164-48f7-91a4-4e94590c08c5', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bxh6nq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/9/', u'type': u'virtual', u'id': 9, u'size': 107374182400}], u'blockdevice_set': [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'6746ca12-9bc3-4610-9ccc-58e2fd662f1a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bxh6nq', u'filesystem': {u'mount_options': None, u'uuid': u'd6e2b9ba-c158-4a4c-b66c-1cd03d69d334', u'label': None, u'mount_point': 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': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/partition/5'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'bxh6nq', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/'}, {u'size': 107374182400, u'model': None, u'uuid': u'250f30c2-aead-4ad5-acb7-84bdfd2b4b78', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'a1a6fc33-0164-48f7-91a4-4e94590c08c5', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bxh6nq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/9/'}], u'status': 4, u'bcaches': [], u'cpu_count': 40, u'raids': [], u'owner_data': {}, u'ip_addresses': [], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'bxh6nq', u'id': 5}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'6746ca12-9bc3-4610-9ccc-58e2fd662f1a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bxh6nq', u'filesystem': {u'mount_options': None, u'uuid': u'd6e2b9ba-c158-4a4c-b66c-1cd03d69d334', u'label': None, u'mount_point': 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': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/partition/5'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'bxh6nq', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/', u'type': u'physical', u'id': 1, u'size': 800109715456}, 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'primary_rack': u'hpd6dr', 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'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'dhcp', u'id': 15}], 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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/5/'}, {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'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/14/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 16}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:49', u'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/10/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 17}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:48', u'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/11/'}, {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'primary_rack': u'hpd6dr', 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'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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:10:1c', u'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/13/'}, {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'system_id': u'bxh6nq', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/interfaces/12/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'6746ca12-9bc3-4610-9ccc-58e2fd662f1a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bxh6nq', u'filesystem': {u'mount_options': None, u'uuid': u'd6e2b9ba-c158-4a4c-b66c-1cd03d69d334', u'label': None, u'mount_point': 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': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/partition/5'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'bxh6nq', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/bxh6nq/blockdevices/1/', u'type': u'physical', u'id': 1, u'size': 800109715456}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-06-26 20:25:31,505 [salt.state       :300 ][INFO    ][8398] {'new': {'storage_layout': 'lvm'}}
2019-06-26 20:25:31,506 [salt.state       :1951][INFO    ][8398] Completed state [maas_machines_storage_cmp002_lvm] at time 20:25:31.506248 duration_in_ms=1982.763
2019-06-26 20:25:31,507 [salt.state       :1780][INFO    ][8398] Running state [maas_machines_storage_cmp001_lvm] at time 20:25:31.506976
2019-06-26 20:25:31,507 [salt.state       :1813][INFO    ][8398] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-26 20:25:32,380 [salt.loaded.ext.module.maasng:610 ][INFO    ][8398] ffgqpr
2019-06-26 20:25:32,381 [salt.loaded.ext.module.maasng:626 ][INFO    ][8398] sda
2019-06-26 20:25:32,797 [salt.loaded.ext.module.maasng:361 ][INFO    ][8398] ffgqpr
2019-06-26 20:25:32,887 [salt.loaded.ext.module.maasng:367 ][INFO    ][8398] [{u'size': 800109715456, u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'filesystem': None, u'name': u'sda', u'system_id': u'ffgqpr', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/', u'type': u'physical', u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'uuid': u'2f824484-4c84-400a-b5a1-97897250b23b', u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/partition/2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffgqpr', u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'3c55a90c-347a-42f6-96ed-a5eaba732503', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 2, u'device_id': 2}]}, {u'size': 800097042432, u'block_size': 4096, u'uuid': u'37d5612d-e2da-4da3-a65a-cc09a46dfd18', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 800097042432, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'2777a799-014d-4bd7-b8d5-b7812f221fe7', u'mount_options': None}, u'name': u'vgroot-lvroot', u'system_id': u'ffgqpr', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/4/', u'type': u'virtual', u'id': 4, u'serial': None, u'partitions': []}]
2019-06-26 20:25:32,888 [salt.loaded.ext.module.maasng:632 ][INFO    ][8398] vgroot
2019-06-26 20:25:32,888 [salt.loaded.ext.module.maasng:635 ][INFO    ][8398] lvroot
2019-06-26 20:25:32,888 [salt.loaded.ext.module.maasng:639 ][INFO    ][8398] 107374182400
2019-06-26 20:25:33,453 [salt.loaded.ext.module.maasng:645 ][INFO    ][8398] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, 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'primary_rack': u'hpd6dr', 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'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'dhcp', u'id': 21}], 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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/6/'}, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/ffgqpr/', u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'ffgqpr', 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'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'uuid': u'6d0846cc-0388-4839-973b-c49be8f5f630', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'0c7636b1-d554-4549-a275-86c341ff3b32', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'ffgqpr', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/10/', u'type': u'virtual', u'id': 10, u'size': 107374182400}], u'blockdevice_set': [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'ed2d887b-4ffe-44ea-a543-694319c35f59', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffgqpr', u'filesystem': {u'mount_options': None, u'uuid': u'f4bed03d-dd58-41eb-b897-25d8d2568091', u'label': None, u'mount_point': 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': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'ffgqpr', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/'}, {u'size': 107374182400, u'model': None, u'uuid': u'6d0846cc-0388-4839-973b-c49be8f5f630', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'0c7636b1-d554-4549-a275-86c341ff3b32', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'ffgqpr', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/10/'}], u'status': 4, u'bcaches': [], u'cpu_count': 40, u'raids': [], u'owner_data': {}, u'ip_addresses': [], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'ffgqpr', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 6, u'boot_disk': {u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'ed2d887b-4ffe-44ea-a543-694319c35f59', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffgqpr', u'filesystem': {u'mount_options': None, u'uuid': u'f4bed03d-dd58-41eb-b897-25d8d2568091', u'label': None, u'mount_point': 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': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'ffgqpr', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/', u'type': u'physical', u'id': 2, u'size': 800109715456}, 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'primary_rack': u'hpd6dr', 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'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'dhcp', u'id': 21}], 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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/6/'}, {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:1f:d5', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/16/'}, {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:1f:d4', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/19/'}, {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'primary_rack': u'hpd6dr', 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'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': 22}], 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'primary_rack': u'hpd6dr', 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'enabled': True, u'children': [], u'discovered': [], u'mac_address': u'9c:b6:54:8a:95:a4', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/15/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 23}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:52:cc', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/17/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 24}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:52:cd', u'system_id': u'ffgqpr', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/interfaces/18/'}], u'current_testing_result_id': 7, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'size': 800101236736, u'uuid': u'ed2d887b-4ffe-44ea-a543-694319c35f59', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffgqpr', u'filesystem': {u'mount_options': None, u'uuid': u'f4bed03d-dd58-41eb-b897-25d8d2568091', u'label': None, u'mount_point': 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': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'ffgqpr', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'resource_uri': u'/MAAS/api/2.0/nodes/ffgqpr/blockdevices/2/', u'type': u'physical', u'id': 2, u'size': 800109715456}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-06-26 20:25:33,455 [salt.state       :300 ][INFO    ][8398] {'new': {'storage_layout': 'lvm'}}
2019-06-26 20:25:33,456 [salt.state       :1951][INFO    ][8398] Completed state [maas_machines_storage_cmp001_lvm] at time 20:25:33.455980 duration_in_ms=1949.004
2019-06-26 20:25:33,460 [salt.minion      :1711][INFO    ][8398] Returning information for job: 20190626202519258320
2019-06-26 20:25:34,152 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626202534139271
2019-06-26 20:25:34,173 [salt.minion      :1432][INFO    ][8430] Starting a new job with PID 8430
2019-06-26 20:25:35,215 [salt.state       :915 ][INFO    ][8430] Loading fresh modules for state activity
2019-06-26 20:25:35,270 [salt.fileclient  :1219][INFO    ][8430] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-26 20:25:35,320 [salt.state       :1780][INFO    ][8430] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:35.320630
2019-06-26 20:25:35,321 [salt.state       :1813][INFO    ][8430] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 20:25:35,323 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8430] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 20:25:37,185 [salt.state       :300 ][INFO    ][8430] {'pid': 8437, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 20:25:37,186 [salt.state       :1951][INFO    ][8430] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:37.186112 duration_in_ms=1865.481
2019-06-26 20:25:37,190 [salt.state       :1780][INFO    ][8430] Running state [maas.deploy_machines] at time 20:25:37.189695
2019-06-26 20:25:37,191 [salt.state       :1813][INFO    ][8430] Executing state module.run for [maas.deploy_machines]
2019-06-26 20:25:37,192 [salt.utils.decorators:613 ][WARNING ][8430] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:25:37,593 [salt.loaded.ext.module.maas:684 ][INFO    ][8430] deploymachines hwe_kernel=hwe-16.04 system_id=tarten distro_series=xenial
2019-06-26 20:25:40,072 [salt.loaded.ext.module.maas:684 ][INFO    ][8430] deploymachines hwe_kernel=hwe-16.04 system_id=bxh6nq distro_series=xenial
2019-06-26 20:25:42,531 [salt.loaded.ext.module.maas:684 ][INFO    ][8430] deploymachines hwe_kernel=hwe-16.04 system_id=ffgqpr distro_series=xenial
2019-06-26 20:25:45,108 [salt.loaded.ext.module.maas:684 ][INFO    ][8430] deploymachines hwe_kernel=hwe-16.04 system_id=gqdm3y distro_series=xenial
2019-06-26 20:25:47,617 [salt.state       :300 ][INFO    ][8430] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-06-26 20:25:47,619 [salt.state       :1951][INFO    ][8430] Completed state [maas.deploy_machines] at time 20:25:47.619119 duration_in_ms=10429.424
2019-06-26 20:25:47,622 [salt.minion      :1711][INFO    ][8430] Returning information for job: 20190626202534139271
2019-06-26 20:25:48,339 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626202548327313
2019-06-26 20:25:48,359 [salt.minion      :1432][INFO    ][8656] Starting a new job with PID 8656
2019-06-26 20:25:56,643 [salt.state       :915 ][INFO    ][8656] Loading fresh modules for state activity
2019-06-26 20:25:56,709 [salt.fileclient  :1219][INFO    ][8656] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-26 20:25:56,776 [salt.state       :1780][INFO    ][8656] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:56.776676
2019-06-26 20:25:56,777 [salt.state       :1813][INFO    ][8656] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 20:25:56,779 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8656] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 20:25:58,671 [salt.state       :300 ][INFO    ][8656] {'pid': 8686, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 20:25:58,672 [salt.state       :1951][INFO    ][8656] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:25:58.672456 duration_in_ms=1895.78
2019-06-26 20:25:58,676 [salt.state       :1780][INFO    ][8656] Running state [maas.wait_for_machine_status] at time 20:25:58.676353
2019-06-26 20:25:58,677 [salt.state       :1813][INFO    ][8656] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 20:25:58,678 [salt.utils.decorators:613 ][WARNING ][8656] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 20:26:00,413 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2248.28537607s left)
2019-06-26 20:26:03,392 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202603374982
2019-06-26 20:26:03,427 [salt.minion      :1432][INFO    ][8697] Starting a new job with PID 8697
2019-06-26 20:26:03,454 [salt.minion      :1711][INFO    ][8697] Returning information for job: 20190626202603374982
2019-06-26 20:26:32,161 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2216.5371809s left)
2019-06-26 20:26:33,479 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202633464479
2019-06-26 20:26:33,507 [salt.minion      :1432][INFO    ][8739] Starting a new job with PID 8739
2019-06-26 20:26:33,537 [salt.minion      :1711][INFO    ][8739] Returning information for job: 20190626202633464479
2019-06-26 20:27:03,597 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202703581484
2019-06-26 20:27:03,619 [salt.minion      :1432][INFO    ][8904] Starting a new job with PID 8904
2019-06-26 20:27:03,642 [salt.minion      :1711][INFO    ][8904] Returning information for job: 20190626202703581484
2019-06-26 20:27:04,261 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2184.43723392s left)
2019-06-26 20:27:33,666 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202733654515
2019-06-26 20:27:33,695 [salt.minion      :1432][INFO    ][8955] Starting a new job with PID 8955
2019-06-26 20:27:33,715 [salt.minion      :1711][INFO    ][8955] Returning information for job: 20190626202733654515
2019-06-26 20:27:35,993 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2152.70547605s left)
2019-06-26 20:28:03,739 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202803725466
2019-06-26 20:28:03,765 [salt.minion      :1432][INFO    ][8988] Starting a new job with PID 8988
2019-06-26 20:28:03,785 [salt.minion      :1711][INFO    ][8988] Returning information for job: 20190626202803725466
2019-06-26 20:28:07,923 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2120.77459598s left)
2019-06-26 20:28:33,804 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202833787106
2019-06-26 20:28:33,834 [salt.minion      :1432][INFO    ][9058] Starting a new job with PID 9058
2019-06-26 20:28:33,855 [salt.minion      :1711][INFO    ][9058] Returning information for job: 20190626202833787106
2019-06-26 20:28:40,049 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2088.648772s left)
2019-06-26 20:29:03,883 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202903864732
2019-06-26 20:29:03,906 [salt.minion      :1432][INFO    ][9137] Starting a new job with PID 9137
2019-06-26 20:29:03,927 [salt.minion      :1711][INFO    ][9137] Returning information for job: 20190626202903864732
2019-06-26 20:29:12,609 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2056.08902407s left)
2019-06-26 20:29:34,013 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626202933999396
2019-06-26 20:29:34,037 [salt.minion      :1432][INFO    ][9327] Starting a new job with PID 9327
2019-06-26 20:29:34,060 [salt.minion      :1711][INFO    ][9327] Returning information for job: 20190626202933999396
2019-06-26 20:29:44,490 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2024.20771694s left)
2019-06-26 20:30:04,089 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203004077302
2019-06-26 20:30:04,112 [salt.minion      :1432][INFO    ][9406] Starting a new job with PID 9406
2019-06-26 20:30:04,134 [salt.minion      :1711][INFO    ][9406] Returning information for job: 20190626203004077302
2019-06-26 20:30:16,509 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1992.1891191s left)
2019-06-26 20:30:34,228 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203034213507
2019-06-26 20:30:34,253 [salt.minion      :1432][INFO    ][9683] Starting a new job with PID 9683
2019-06-26 20:30:34,277 [salt.minion      :1711][INFO    ][9683] Returning information for job: 20190626203034213507
2019-06-26 20:30:48,608 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1960.0903399s left)
2019-06-26 20:31:04,340 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203104326963
2019-06-26 20:31:04,362 [salt.minion      :1432][INFO    ][9724] Starting a new job with PID 9724
2019-06-26 20:31:04,383 [salt.minion      :1711][INFO    ][9724] Returning information for job: 20190626203104326963
2019-06-26 20:31:20,625 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1928.07302594s left)
2019-06-26 20:31:34,497 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203134484923
2019-06-26 20:31:34,526 [salt.minion      :1432][INFO    ][10064] Starting a new job with PID 10064
2019-06-26 20:31:34,551 [salt.minion      :1711][INFO    ][10064] Returning information for job: 20190626203134484923
2019-06-26 20:31:52,678 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1896.01961899s left)
2019-06-26 20:32:04,633 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203204616115
2019-06-26 20:32:04,659 [salt.minion      :1432][INFO    ][10097] Starting a new job with PID 10097
2019-06-26 20:32:04,681 [salt.minion      :1711][INFO    ][10097] Returning information for job: 20190626203204616115
2019-06-26 20:32:24,882 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1863.81644392s left)
2019-06-26 20:32:34,807 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203234790983
2019-06-26 20:32:34,834 [salt.minion      :1432][INFO    ][10350] Starting a new job with PID 10350
2019-06-26 20:32:34,857 [salt.minion      :1711][INFO    ][10350] Returning information for job: 20190626203234790983
2019-06-26 20:32:56,959 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1831.73943591s left)
2019-06-26 20:33:04,940 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203304923463
2019-06-26 20:33:04,966 [salt.minion      :1432][INFO    ][10386] Starting a new job with PID 10386
2019-06-26 20:33:04,987 [salt.minion      :1711][INFO    ][10386] Returning information for job: 20190626203304923463
2019-06-26 20:33:28,980 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1799.71773791s left)
2019-06-26 20:33:35,107 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203335091777
2019-06-26 20:33:35,136 [salt.minion      :1432][INFO    ][10620] Starting a new job with PID 10620
2019-06-26 20:33:35,157 [salt.minion      :1711][INFO    ][10620] Returning information for job: 20190626203335091777
2019-06-26 20:34:00,963 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1767.73480105s left)
2019-06-26 20:34:05,269 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203405252949
2019-06-26 20:34:05,300 [salt.minion      :1432][INFO    ][10655] Starting a new job with PID 10655
2019-06-26 20:34:05,325 [salt.minion      :1711][INFO    ][10655] Returning information for job: 20190626203405252949
2019-06-26 20:34:32,971 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1735.72737789s left)
2019-06-26 20:34:35,463 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203435446936
2019-06-26 20:34:35,495 [salt.minion      :1432][INFO    ][10821] Starting a new job with PID 10821
2019-06-26 20:34:35,516 [salt.minion      :1711][INFO    ][10821] Returning information for job: 20190626203435446936
2019-06-26 20:35:04,903 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1703.79471397s left)
2019-06-26 20:35:05,615 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203505603415
2019-06-26 20:35:05,644 [salt.minion      :1432][INFO    ][10850] Starting a new job with PID 10850
2019-06-26 20:35:05,670 [salt.minion      :1711][INFO    ][10850] Returning information for job: 20190626203505603415
2019-06-26 20:35:35,792 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203535780911
2019-06-26 20:35:35,815 [salt.minion      :1432][INFO    ][10915] Starting a new job with PID 10915
2019-06-26 20:35:35,839 [salt.minion      :1711][INFO    ][10915] Returning information for job: 20190626203535780911
2019-06-26 20:35:37,005 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1671.69287801s left)
2019-06-26 20:36:05,963 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203605951609
2019-06-26 20:36:05,991 [salt.minion      :1432][INFO    ][10987] Starting a new job with PID 10987
2019-06-26 20:36:06,019 [salt.minion      :1711][INFO    ][10987] Returning information for job: 20190626203605951609
2019-06-26 20:36:09,079 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1639.61855412s left)
2019-06-26 20:36:36,163 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203636154520
2019-06-26 20:36:36,186 [salt.minion      :1432][INFO    ][11208] Starting a new job with PID 11208
2019-06-26 20:36:36,210 [salt.minion      :1711][INFO    ][11208] Returning information for job: 20190626203636154520
2019-06-26 20:36:41,092 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1607.60567093s left)
2019-06-26 20:37:06,353 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203706336629
2019-06-26 20:37:06,383 [salt.minion      :1432][INFO    ][11246] Starting a new job with PID 11246
2019-06-26 20:37:06,407 [salt.minion      :1711][INFO    ][11246] Returning information for job: 20190626203706336629
2019-06-26 20:37:13,194 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1575.50469112s left)
2019-06-26 20:37:36,549 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203736533134
2019-06-26 20:37:36,572 [salt.minion      :1432][INFO    ][11346] Starting a new job with PID 11346
2019-06-26 20:37:36,599 [salt.minion      :1711][INFO    ][11346] Returning information for job: 20190626203736533134
2019-06-26 20:37:45,191 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1543.50730205s left)
2019-06-26 20:38:06,754 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203806738098
2019-06-26 20:38:06,785 [salt.minion      :1432][INFO    ][11397] Starting a new job with PID 11397
2019-06-26 20:38:06,811 [salt.minion      :1711][INFO    ][11397] Returning information for job: 20190626203806738098
2019-06-26 20:38:17,334 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1511.36410999s left)
2019-06-26 20:38:36,957 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203836947465
2019-06-26 20:38:36,988 [salt.minion      :1432][INFO    ][11457] Starting a new job with PID 11457
2019-06-26 20:38:37,021 [salt.minion      :1711][INFO    ][11457] Returning information for job: 20190626203836947465
2019-06-26 20:38:49,260 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1479.43871093s left)
2019-06-26 20:39:06,983 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203906968045
2019-06-26 20:39:07,009 [salt.minion      :1432][INFO    ][11495] Starting a new job with PID 11495
2019-06-26 20:39:07,031 [salt.minion      :1711][INFO    ][11495] Returning information for job: 20190626203906968045
2019-06-26 20:39:21,384 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1447.31377101s left)
2019-06-26 20:39:37,028 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626203937015952
2019-06-26 20:39:37,060 [salt.minion      :1432][INFO    ][11658] Starting a new job with PID 11658
2019-06-26 20:39:37,086 [salt.minion      :1711][INFO    ][11658] Returning information for job: 20190626203937015952
2019-06-26 20:39:53,539 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1415.15950012s left)
2019-06-26 20:40:07,252 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204007237190
2019-06-26 20:40:07,283 [salt.minion      :1432][INFO    ][11689] Starting a new job with PID 11689
2019-06-26 20:40:07,306 [salt.minion      :1711][INFO    ][11689] Returning information for job: 20190626204007237190
2019-06-26 20:40:25,617 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1383.08091998s left)
2019-06-26 20:40:37,288 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204037271923
2019-06-26 20:40:37,315 [salt.minion      :1432][INFO    ][11745] Starting a new job with PID 11745
2019-06-26 20:40:37,340 [salt.minion      :1711][INFO    ][11745] Returning information for job: 20190626204037271923
2019-06-26 20:40:57,448 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1351.25012207s left)
2019-06-26 20:41:07,341 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204107329170
2019-06-26 20:41:07,373 [salt.minion      :1432][INFO    ][11774] Starting a new job with PID 11774
2019-06-26 20:41:07,399 [salt.minion      :1711][INFO    ][11774] Returning information for job: 20190626204107329170
2019-06-26 20:41:29,469 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1319.22915101s left)
2019-06-26 20:41:37,424 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204137408492
2019-06-26 20:41:37,452 [salt.minion      :1432][INFO    ][11820] Starting a new job with PID 11820
2019-06-26 20:41:37,481 [salt.minion      :1711][INFO    ][11820] Returning information for job: 20190626204137408492
2019-06-26 20:42:01,223 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1287.47483993s left)
2019-06-26 20:42:07,497 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204207480965
2019-06-26 20:42:07,525 [salt.minion      :1432][INFO    ][11848] Starting a new job with PID 11848
2019-06-26 20:42:07,557 [salt.minion      :1711][INFO    ][11848] Returning information for job: 20190626204207480965
2019-06-26 20:42:33,212 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1255.486413s left)
2019-06-26 20:42:37,613 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204237597433
2019-06-26 20:42:37,640 [salt.minion      :1432][INFO    ][11893] Starting a new job with PID 11893
2019-06-26 20:42:37,663 [salt.minion      :1711][INFO    ][11893] Returning information for job: 20190626204237597433
2019-06-26 20:43:05,080 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1223.61764002s left)
2019-06-26 20:43:07,697 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204307681690
2019-06-26 20:43:07,716 [salt.minion      :1432][INFO    ][11927] Starting a new job with PID 11927
2019-06-26 20:43:07,740 [salt.minion      :1711][INFO    ][11927] Returning information for job: 20190626204307681690
2019-06-26 20:43:36,972 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1191.72551703s left)
2019-06-26 20:43:37,797 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204337786737
2019-06-26 20:43:37,823 [salt.minion      :1432][INFO    ][11973] Starting a new job with PID 11973
2019-06-26 20:43:37,846 [salt.minion      :1711][INFO    ][11973] Returning information for job: 20190626204337786737
2019-06-26 20:44:07,933 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204407921311
2019-06-26 20:44:07,954 [salt.minion      :1432][INFO    ][11999] Starting a new job with PID 11999
2019-06-26 20:44:07,980 [salt.minion      :1711][INFO    ][11999] Returning information for job: 20190626204407921311
2019-06-26 20:44:08,871 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1159.82698298s left)
2019-06-26 20:44:38,035 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204438024403
2019-06-26 20:44:38,062 [salt.minion      :1432][INFO    ][12043] Starting a new job with PID 12043
2019-06-26 20:44:38,084 [salt.minion      :1711][INFO    ][12043] Returning information for job: 20190626204438024403
2019-06-26 20:44:41,035 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1127.66330504s left)
2019-06-26 20:45:08,203 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204508191742
2019-06-26 20:45:08,229 [salt.minion      :1432][INFO    ][12070] Starting a new job with PID 12070
2019-06-26 20:45:08,251 [salt.minion      :1711][INFO    ][12070] Returning information for job: 20190626204508191742
2019-06-26 20:45:12,917 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1095.78054094s left)
2019-06-26 20:45:38,337 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204538321817
2019-06-26 20:45:38,362 [salt.minion      :1432][INFO    ][12117] Starting a new job with PID 12117
2019-06-26 20:45:38,384 [salt.minion      :1711][INFO    ][12117] Returning information for job: 20190626204538321817
2019-06-26 20:45:44,786 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1063.91279292s left)
2019-06-26 20:46:08,516 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204608506252
2019-06-26 20:46:08,548 [salt.minion      :1432][INFO    ][12147] Starting a new job with PID 12147
2019-06-26 20:46:08,573 [salt.minion      :1711][INFO    ][12147] Returning information for job: 20190626204608506252
2019-06-26 20:46:16,763 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1031.93496299s left)
2019-06-26 20:46:38,695 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204638683121
2019-06-26 20:46:38,723 [salt.minion      :1432][INFO    ][12193] Starting a new job with PID 12193
2019-06-26 20:46:38,746 [salt.minion      :1711][INFO    ][12193] Returning information for job: 20190626204638683121
2019-06-26 20:46:48,764 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (999.933773994s left)
2019-06-26 20:47:08,929 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204708912311
2019-06-26 20:47:08,958 [salt.minion      :1432][INFO    ][12358] Starting a new job with PID 12358
2019-06-26 20:47:08,982 [salt.minion      :1711][INFO    ][12358] Returning information for job: 20190626204708912311
2019-06-26 20:47:20,682 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (968.015574932s left)
2019-06-26 20:47:39,164 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204739147013
2019-06-26 20:47:39,192 [salt.minion      :1432][INFO    ][12414] Starting a new job with PID 12414
2019-06-26 20:47:39,215 [salt.minion      :1711][INFO    ][12414] Returning information for job: 20190626204739147013
2019-06-26 20:47:52,601 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (936.096863031s left)
2019-06-26 20:48:09,196 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204809180109
2019-06-26 20:48:09,220 [salt.minion      :1432][INFO    ][12446] Starting a new job with PID 12446
2019-06-26 20:48:09,250 [salt.minion      :1711][INFO    ][12446] Returning information for job: 20190626204809180109
2019-06-26 20:48:24,625 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (904.072849989s left)
2019-06-26 20:48:39,245 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204839230736
2019-06-26 20:48:39,275 [salt.minion      :1432][INFO    ][12492] Starting a new job with PID 12492
2019-06-26 20:48:39,298 [salt.minion      :1711][INFO    ][12492] Returning information for job: 20190626204839230736
2019-06-26 20:48:56,442 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (872.255882978s left)
2019-06-26 20:49:09,324 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204909309245
2019-06-26 20:49:09,354 [salt.minion      :1432][INFO    ][12522] Starting a new job with PID 12522
2019-06-26 20:49:09,378 [salt.minion      :1711][INFO    ][12522] Returning information for job: 20190626204909309245
2019-06-26 20:49:28,356 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (840.342150927s left)
2019-06-26 20:49:39,393 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626204939381874
2019-06-26 20:49:39,417 [salt.minion      :1432][INFO    ][12566] Starting a new job with PID 12566
2019-06-26 20:49:39,439 [salt.minion      :1711][INFO    ][12566] Returning information for job: 20190626204939381874
2019-06-26 20:50:00,273 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (808.425147057s left)
2019-06-26 20:50:09,451 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205009438232
2019-06-26 20:50:09,480 [salt.minion      :1432][INFO    ][12594] Starting a new job with PID 12594
2019-06-26 20:50:09,504 [salt.minion      :1711][INFO    ][12594] Returning information for job: 20190626205009438232
2019-06-26 20:50:32,292 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (776.406229019s left)
2019-06-26 20:50:39,576 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205039559788
2019-06-26 20:50:39,606 [salt.minion      :1432][INFO    ][12638] Starting a new job with PID 12638
2019-06-26 20:50:39,629 [salt.minion      :1711][INFO    ][12638] Returning information for job: 20190626205039559788
2019-06-26 20:51:04,121 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (744.577316999s left)
2019-06-26 20:51:09,684 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205109667339
2019-06-26 20:51:09,714 [salt.minion      :1432][INFO    ][12667] Starting a new job with PID 12667
2019-06-26 20:51:09,738 [salt.minion      :1711][INFO    ][12667] Returning information for job: 20190626205109667339
2019-06-26 20:51:36,128 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (712.569840908s left)
2019-06-26 20:51:39,848 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205139835287
2019-06-26 20:51:39,875 [salt.minion      :1432][INFO    ][12710] Starting a new job with PID 12710
2019-06-26 20:51:39,900 [salt.minion      :1711][INFO    ][12710] Returning information for job: 20190626205139835287
2019-06-26 20:52:08,172 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (680.525558949s left)
2019-06-26 20:52:10,030 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205210017930
2019-06-26 20:52:10,061 [salt.minion      :1432][INFO    ][12743] Starting a new job with PID 12743
2019-06-26 20:52:10,084 [salt.minion      :1711][INFO    ][12743] Returning information for job: 20190626205210017930
2019-06-26 20:52:40,049 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (648.649459124s left)
2019-06-26 20:52:40,221 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205240207275
2019-06-26 20:52:40,249 [salt.minion      :1432][INFO    ][12783] Starting a new job with PID 12783
2019-06-26 20:52:40,276 [salt.minion      :1711][INFO    ][12783] Returning information for job: 20190626205240207275
2019-06-26 20:53:10,421 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205310404432
2019-06-26 20:53:10,445 [salt.minion      :1432][INFO    ][12821] Starting a new job with PID 12821
2019-06-26 20:53:10,472 [salt.minion      :1711][INFO    ][12821] Returning information for job: 20190626205310404432
2019-06-26 20:53:12,262 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (616.435630083s left)
2019-06-26 20:53:40,467 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205340452876
2019-06-26 20:53:40,497 [salt.minion      :1432][INFO    ][12854] Starting a new job with PID 12854
2019-06-26 20:53:40,520 [salt.minion      :1711][INFO    ][12854] Returning information for job: 20190626205340452876
2019-06-26 20:53:44,264 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (584.434417963s left)
2019-06-26 20:54:10,509 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205410489316
2019-06-26 20:54:10,535 [salt.minion      :1432][INFO    ][12904] Starting a new job with PID 12904
2019-06-26 20:54:10,565 [salt.minion      :1711][INFO    ][12904] Returning information for job: 20190626205410489316
2019-06-26 20:54:16,122 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (552.576123953s left)
2019-06-26 20:54:40,566 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205440550979
2019-06-26 20:54:40,591 [salt.minion      :1432][INFO    ][12932] Starting a new job with PID 12932
2019-06-26 20:54:40,614 [salt.minion      :1711][INFO    ][12932] Returning information for job: 20190626205440550979
2019-06-26 20:54:47,995 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (520.703479052s left)
2019-06-26 20:55:10,627 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205510612863
2019-06-26 20:55:10,651 [salt.minion      :1432][INFO    ][12985] Starting a new job with PID 12985
2019-06-26 20:55:10,676 [salt.minion      :1711][INFO    ][12985] Returning information for job: 20190626205510612863
2019-06-26 20:55:19,899 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (488.798696995s left)
2019-06-26 20:55:40,712 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205540695133
2019-06-26 20:55:40,740 [salt.minion      :1432][INFO    ][13008] Starting a new job with PID 13008
2019-06-26 20:55:40,764 [salt.minion      :1711][INFO    ][13008] Returning information for job: 20190626205540695133
2019-06-26 20:55:51,754 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (456.943733931s left)
2019-06-26 20:56:10,857 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205610843129
2019-06-26 20:56:10,885 [salt.minion      :1432][INFO    ][13063] Starting a new job with PID 13063
2019-06-26 20:56:10,909 [salt.minion      :1711][INFO    ][13063] Returning information for job: 20190626205610843129
2019-06-26 20:56:23,656 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (425.042220116s left)
2019-06-26 20:56:40,999 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205640983878
2019-06-26 20:56:41,026 [salt.minion      :1432][INFO    ][13086] Starting a new job with PID 13086
2019-06-26 20:56:41,051 [salt.minion      :1711][INFO    ][13086] Returning information for job: 20190626205640983878
2019-06-26 20:56:55,793 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (392.905064106s left)
2019-06-26 20:57:11,159 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205711149278
2019-06-26 20:57:11,185 [salt.minion      :1432][INFO    ][13149] Starting a new job with PID 13149
2019-06-26 20:57:11,215 [salt.minion      :1711][INFO    ][13149] Returning information for job: 20190626205711149278
2019-06-26 20:57:27,708 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (360.989836931s left)
2019-06-26 20:57:41,333 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205741315457
2019-06-26 20:57:41,362 [salt.minion      :1432][INFO    ][13180] Starting a new job with PID 13180
2019-06-26 20:57:41,386 [salt.minion      :1711][INFO    ][13180] Returning information for job: 20190626205741315457
2019-06-26 20:57:59,650 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (329.048800945s left)
2019-06-26 20:58:11,561 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205811544238
2019-06-26 20:58:11,588 [salt.minion      :1432][INFO    ][13235] Starting a new job with PID 13235
2019-06-26 20:58:11,617 [salt.minion      :1711][INFO    ][13235] Returning information for job: 20190626205811544238
2019-06-26 20:58:31,427 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (297.27105093s left)
2019-06-26 20:58:41,770 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205841754803
2019-06-26 20:58:41,797 [salt.minion      :1432][INFO    ][13265] Starting a new job with PID 13265
2019-06-26 20:58:41,824 [salt.minion      :1711][INFO    ][13265] Returning information for job: 20190626205841754803
2019-06-26 20:59:03,457 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (265.241866112s left)
2019-06-26 20:59:11,809 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205911796669
2019-06-26 20:59:11,839 [salt.minion      :1432][INFO    ][13315] Starting a new job with PID 13315
2019-06-26 20:59:11,871 [salt.minion      :1711][INFO    ][13315] Returning information for job: 20190626205911796669
2019-06-26 20:59:35,303 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (233.395452976s left)
2019-06-26 20:59:42,004 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626205941990962
2019-06-26 20:59:42,030 [salt.minion      :1432][INFO    ][13339] Starting a new job with PID 13339
2019-06-26 20:59:42,054 [salt.minion      :1711][INFO    ][13339] Returning information for job: 20190626205941990962
2019-06-26 21:00:07,221 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (201.477216005s left)
2019-06-26 21:00:12,076 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210012063784
2019-06-26 21:00:12,103 [salt.minion      :1432][INFO    ][13393] Starting a new job with PID 13393
2019-06-26 21:00:12,127 [salt.minion      :1711][INFO    ][13393] Returning information for job: 20190626210012063784
2019-06-26 21:00:38,992 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (169.705514908s left)
2019-06-26 21:00:42,173 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210042158653
2019-06-26 21:00:42,201 [salt.minion      :1432][INFO    ][13416] Starting a new job with PID 13416
2019-06-26 21:00:42,224 [salt.minion      :1711][INFO    ][13416] Returning information for job: 20190626210042158653
2019-06-26 21:01:11,013 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (137.684852123s left)
2019-06-26 21:01:12,276 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210112262547
2019-06-26 21:01:12,298 [salt.minion      :1432][INFO    ][13471] Starting a new job with PID 13471
2019-06-26 21:01:12,321 [salt.minion      :1711][INFO    ][13471] Returning information for job: 20190626210112262547
2019-06-26 21:01:42,419 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210142408657
2019-06-26 21:01:42,438 [salt.minion      :1432][INFO    ][13492] Starting a new job with PID 13492
2019-06-26 21:01:42,463 [salt.minion      :1711][INFO    ][13492] Returning information for job: 20190626210142408657
2019-06-26 21:01:42,850 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (105.847585917s left)
2019-06-26 21:02:12,569 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210212551263
2019-06-26 21:02:12,596 [salt.minion      :1432][INFO    ][13543] Starting a new job with PID 13543
2019-06-26 21:02:12,618 [salt.minion      :1711][INFO    ][13543] Returning information for job: 20190626210212551263
2019-06-26 21:02:14,823 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (73.8747079372s left)
2019-06-26 21:02:42,715 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210242698453
2019-06-26 21:02:42,742 [salt.minion      :1432][INFO    ][13563] Starting a new job with PID 13563
2019-06-26 21:02:42,776 [salt.minion      :1711][INFO    ][13563] Returning information for job: 20190626210242698453
2019-06-26 21:02:46,914 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (41.7846970558s left)
2019-06-26 21:03:12,868 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210312854599
2019-06-26 21:03:12,892 [salt.minion      :1432][INFO    ][13620] Starting a new job with PID 13620
2019-06-26 21:03:12,921 [salt.minion      :1711][INFO    ][13620] Returning information for job: 20190626210312854599
2019-06-26 21:03:18,850 [salt.loaded.ext.module.maas:1023][INFO    ][8656] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (9.84772801399s left)
2019-06-26 21:03:43,089 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210343071852
2019-06-26 21:03:43,116 [salt.minion      :1432][INFO    ][13640] Starting a new job with PID 13640
2019-06-26 21:03:43,140 [salt.minion      :1711][INFO    ][13640] Returning information for job: 20190626210343071852
2019-06-26 21:03:50,708 [salt.state       :302 ][ERROR   ][8656] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['gtw01']not in Deployed state
2019-06-26 21:03:50,709 [salt.state       :1951][INFO    ][8656] Completed state [maas.wait_for_machine_status] at time 21:03:50.709320 duration_in_ms=2272032.947
2019-06-26 21:03:50,719 [salt.minion      :1711][INFO    ][8656] Returning information for job: 20190626202548327313
2019-06-26 21:04:01,552 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command pillar.get with jid 20190626210401535534
2019-06-26 21:04:01,581 [salt.minion      :1432][INFO    ][13668] Starting a new job with PID 13668
2019-06-26 21:04:01,590 [salt.minion      :1711][INFO    ][13668] Returning information for job: 20190626210401535534
2019-06-26 21:04:02,157 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command service.status with jid 20190626210402145238
2019-06-26 21:04:02,188 [salt.minion      :1432][INFO    ][13673] Starting a new job with PID 13673
2019-06-26 21:04:02,770 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13673] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:02,815 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13673] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-26 21:04:02,839 [salt.minion      :1711][INFO    ][13673] Returning information for job: 20190626210402145238
2019-06-26 21:04:03,415 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210403403629
2019-06-26 21:04:03,444 [salt.minion      :1432][INFO    ][13684] Starting a new job with PID 13684
2019-06-26 21:04:11,628 [salt.state       :915 ][INFO    ][13684] Loading fresh modules for state activity
2019-06-26 21:04:12,208 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 21:04:12,514 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 21:04:13,493 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 21:04:13,784 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'salt-minion --version' in directory '/root'
2019-06-26 21:04:15,607 [salt.state       :1780][INFO    ][13684] Running state [salt-minion] at time 21:04:15.607814
2019-06-26 21:04:15,608 [salt.state       :1813][INFO    ][13684] Executing state pkg.installed for [salt-minion]
2019-06-26 21:04:15,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 21:04:15,714 [salt.state       :300 ][INFO    ][13684] All specified packages are already installed
2019-06-26 21:04:15,714 [salt.state       :1951][INFO    ][13684] Completed state [salt-minion] at time 21:04:15.714792 duration_in_ms=106.979
2019-06-26 21:04:15,715 [salt.state       :1780][INFO    ][13684] Running state [salt_minion_dependency_packages] at time 21:04:15.715128
2019-06-26 21:04:15,715 [salt.state       :1813][INFO    ][13684] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-26 21:04:15,726 [salt.state       :300 ][INFO    ][13684] All specified packages are already installed
2019-06-26 21:04:15,726 [salt.state       :1951][INFO    ][13684] Completed state [salt_minion_dependency_packages] at time 21:04:15.726242 duration_in_ms=11.114
2019-06-26 21:04:15,729 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/minion.d/minion.conf] at time 21:04:15.729201
2019-06-26 21:04:15,729 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-26 21:04:16,007 [salt.state       :300 ][INFO    ][13684] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-26 21:04:16,008 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/minion.d/minion.conf] at time 21:04:16.008081 duration_in_ms=278.879
2019-06-26 21:04:16,011 [salt.state       :1780][INFO    ][13684] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:04:16.011240
2019-06-26 21:04:16,011 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-26 21:04:16,025 [salt.state       :300 ][INFO    ][13684] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-26 21:04:16,025 [salt.state       :1951][INFO    ][13684] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:04:16.025901 duration_in_ms=14.66
2019-06-26 21:04:16,027 [salt.state       :1780][INFO    ][13684] Running state [salt-minion] at time 21:04:16.027822
2019-06-26 21:04:16,028 [salt.state       :1813][INFO    ][13684] Executing state service.running for [salt-minion]
2019-06-26 21:04:16,029 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:16,076 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-26 21:04:16,098 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-26 21:04:16,121 [salt.state       :300 ][INFO    ][13684] The service salt-minion is already running
2019-06-26 21:04:16,122 [salt.state       :1951][INFO    ][13684] Completed state [salt-minion] at time 21:04:16.122399 duration_in_ms=94.577
2019-06-26 21:04:16,124 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains.d] at time 21:04:16.124723
2019-06-26 21:04:16,125 [salt.state       :1813][INFO    ][13684] Executing state file.directory for [/etc/salt/grains.d]
2019-06-26 21:04:16,126 [salt.state       :300 ][INFO    ][13684] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-26 21:04:16,127 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains.d] at time 21:04:16.127173 duration_in_ms=2.449
2019-06-26 21:04:16,128 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains] at time 21:04:16.128136
2019-06-26 21:04:16,128 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/grains]
2019-06-26 21:04:16,129 [salt.state       :300 ][INFO    ][13684] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-26 21:04:16,129 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains] at time 21:04:16.129551 duration_in_ms=1.415
2019-06-26 21:04:16,132 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains.d/placeholder] at time 21:04:16.132529
2019-06-26 21:04:16,132 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-26 21:04:16,133 [salt.state       :300 ][INFO    ][13684] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-26 21:04:16,133 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains.d/placeholder] at time 21:04:16.133547 duration_in_ms=1.018
2019-06-26 21:04:16,134 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains.d/sphinx] at time 21:04:16.134061
2019-06-26 21:04:16,134 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-26 21:04:16,135 [salt.state       :300 ][INFO    ][13684] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-26 21:04:16,135 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains.d/sphinx] at time 21:04:16.135698 duration_in_ms=1.637
2019-06-26 21:04:16,138 [salt.state       :1780][INFO    ][13684] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.138233
2019-06-26 21:04:16,138 [salt.state       :1813][INFO    ][13684] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 21:04:16,138 [salt.state       :300 ][INFO    ][13684] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-26 21:04:16,139 [salt.state       :1951][INFO    ][13684] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.139070 duration_in_ms=0.838
2019-06-26 21:04:16,139 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains.d/dns_records] at time 21:04:16.139573
2019-06-26 21:04:16,139 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-26 21:04:16,140 [salt.state       :300 ][INFO    ][13684] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-26 21:04:16,141 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains.d/dns_records] at time 21:04:16.141011 duration_in_ms=1.438
2019-06-26 21:04:16,144 [salt.state       :1780][INFO    ][13684] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.144248
2019-06-26 21:04:16,144 [salt.state       :1813][INFO    ][13684] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 21:04:16,144 [salt.state       :300 ][INFO    ][13684] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-26 21:04:16,145 [salt.state       :1951][INFO    ][13684] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.145005 duration_in_ms=0.757
2019-06-26 21:04:16,145 [salt.state       :1780][INFO    ][13684] Running state [/etc/salt/grains.d/salt] at time 21:04:16.145467
2019-06-26 21:04:16,146 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-26 21:04:16,146 [salt.state       :300 ][INFO    ][13684] File /etc/salt/grains.d/salt is in the correct state
2019-06-26 21:04:16,147 [salt.state       :1951][INFO    ][13684] Completed state [/etc/salt/grains.d/salt] at time 21:04:16.147118 duration_in_ms=1.651
2019-06-26 21:04:16,148 [salt.state       :1780][INFO    ][13684] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.147985
2019-06-26 21:04:16,148 [salt.state       :1813][INFO    ][13684] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-26 21:04:16,148 [salt.state       :300 ][INFO    ][13684] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-26 21:04:16,148 [salt.state       :1951][INFO    ][13684] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:04:16.148733 duration_in_ms=0.748
2019-06-26 21:04:16,150 [salt.state       :1780][INFO    ][13684] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:04:16.150936
2019-06-26 21:04:16,151 [salt.state       :1813][INFO    ][13684] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-26 21:04:16,151 [salt.state       :300 ][INFO    ][13684] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-26 21:04:16,151 [salt.state       :1951][INFO    ][13684] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:04:16.151721 duration_in_ms=0.785
2019-06-26 21:04:16,152 [salt.state       :1780][INFO    ][13684] Running state [mine.update] at time 21:04:16.152378
2019-06-26 21:04:16,152 [salt.state       :1813][INFO    ][13684] Executing state module.wait for [mine.update]
2019-06-26 21:04:16,152 [salt.state       :300 ][INFO    ][13684] No changes made for mine.update
2019-06-26 21:04:16,153 [salt.state       :1951][INFO    ][13684] Completed state [mine.update] at time 21:04:16.153076 duration_in_ms=0.698
2019-06-26 21:04:16,153 [salt.state       :1780][INFO    ][13684] Running state [ca-certificates] at time 21:04:16.153311
2019-06-26 21:04:16,153 [salt.state       :1813][INFO    ][13684] Executing state pkg.installed for [ca-certificates]
2019-06-26 21:04:16,170 [salt.state       :300 ][INFO    ][13684] All specified packages are already installed
2019-06-26 21:04:16,171 [salt.state       :1951][INFO    ][13684] Completed state [ca-certificates] at time 21:04:16.171036 duration_in_ms=17.725
2019-06-26 21:04:16,171 [salt.state       :1780][INFO    ][13684] Running state [update-ca-certificates] at time 21:04:16.171931
2019-06-26 21:04:16,172 [salt.state       :1813][INFO    ][13684] Executing state cmd.wait for [update-ca-certificates]
2019-06-26 21:04:16,173 [salt.state       :300 ][INFO    ][13684] No changes made for update-ca-certificates
2019-06-26 21:04:16,173 [salt.state       :1951][INFO    ][13684] Completed state [update-ca-certificates] at time 21:04:16.173573 duration_in_ms=1.641
2019-06-26 21:04:16,174 [salt.state       :1780][INFO    ][13684] Running state [iptables] at time 21:04:16.174723
2019-06-26 21:04:16,175 [salt.state       :1813][INFO    ][13684] Executing state pkg.installed for [iptables]
2019-06-26 21:04:16,187 [salt.state       :300 ][INFO    ][13684] All specified packages are already installed
2019-06-26 21:04:16,187 [salt.state       :1951][INFO    ][13684] Completed state [iptables] at time 21:04:16.187198 duration_in_ms=12.475
2019-06-26 21:04:16,187 [salt.state       :1780][INFO    ][13684] Running state [iptables-persistent] at time 21:04:16.187437
2019-06-26 21:04:16,187 [salt.state       :1813][INFO    ][13684] Executing state pkg.installed for [iptables-persistent]
2019-06-26 21:04:16,197 [salt.state       :300 ][INFO    ][13684] All specified packages are already installed
2019-06-26 21:04:16,197 [salt.state       :1951][INFO    ][13684] Completed state [iptables-persistent] at time 21:04:16.197426 duration_in_ms=9.989
2019-06-26 21:04:16,198 [salt.state       :1780][INFO    ][13684] Running state [iptables_modules_v4_load] at time 21:04:16.198800
2019-06-26 21:04:16,199 [salt.state       :1813][INFO    ][13684] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-26 21:04:16,199 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'lsmod' in directory '/root'
2019-06-26 21:04:16,218 [salt.state       :300 ][INFO    ][13684] Kernel modules iptable_filter, ip_tables are already present
2019-06-26 21:04:16,218 [salt.state       :1951][INFO    ][13684] Completed state [iptables_modules_v4_load] at time 21:04:16.218333 duration_in_ms=19.533
2019-06-26 21:04:16,219 [salt.state       :1780][INFO    ][13684] Running state [/etc/iptables/rules.v4] at time 21:04:16.218985
2019-06-26 21:04:16,219 [salt.state       :1813][INFO    ][13684] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-26 21:04:16,329 [salt.state       :300 ][INFO    ][13684] File /etc/iptables/rules.v4 is in the correct state
2019-06-26 21:04:16,329 [salt.state       :1951][INFO    ][13684] Completed state [/etc/iptables/rules.v4] at time 21:04:16.329478 duration_in_ms=110.493
2019-06-26 21:04:16,331 [salt.state       :1780][INFO    ][13684] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:04:16.331186
2019-06-26 21:04:16,331 [salt.state       :1813][INFO    ][13684] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-26 21:04:16,331 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-26 21:04:16,354 [salt.state       :300 ][INFO    ][13684] onlyif execution failed
2019-06-26 21:04:16,355 [salt.state       :1951][INFO    ][13684] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:04:16.354989 duration_in_ms=23.803
2019-06-26 21:04:16,356 [salt.state       :1780][INFO    ][13684] Running state [netfilter-persistent] at time 21:04:16.356800
2019-06-26 21:04:16,357 [salt.state       :1813][INFO    ][13684] Executing state service.running for [netfilter-persistent]
2019-06-26 21:04:16,361 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:16,387 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-26 21:04:16,412 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-26 21:04:16,433 [salt.state       :300 ][INFO    ][13684] The service netfilter-persistent is already running
2019-06-26 21:04:16,434 [salt.state       :1951][INFO    ][13684] Completed state [netfilter-persistent] at time 21:04:16.434336 duration_in_ms=77.536
2019-06-26 21:04:16,436 [salt.state       :1780][INFO    ][13684] Running state [iptables_extra.remove_stale_tables] at time 21:04:16.435964
2019-06-26 21:04:16,436 [salt.state       :1813][INFO    ][13684] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-26 21:04:16,437 [salt.state       :300 ][INFO    ][13684] No changes made for iptables_extra.remove_stale_tables
2019-06-26 21:04:16,437 [salt.state       :1951][INFO    ][13684] Completed state [iptables_extra.remove_stale_tables] at time 21:04:16.437513 duration_in_ms=1.549
2019-06-26 21:04:16,438 [salt.state       :1780][INFO    ][13684] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:04:16.438208
2019-06-26 21:04:16,438 [salt.state       :1813][INFO    ][13684] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-26 21:04:16,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13684] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-26 21:04:16,459 [salt.state       :300 ][INFO    ][13684] onlyif execution failed
2019-06-26 21:04:16,460 [salt.state       :1951][INFO    ][13684] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:04:16.460354 duration_in_ms=22.145
2019-06-26 21:04:16,462 [salt.state       :1780][INFO    ][13684] Running state [/etc/iptables/rules.v6] at time 21:04:16.462510
2019-06-26 21:04:16,463 [salt.state       :1813][INFO    ][13684] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-26 21:04:16,463 [salt.state       :300 ][INFO    ][13684] File /etc/iptables/rules.v6 is not present
2019-06-26 21:04:16,464 [salt.state       :1951][INFO    ][13684] Completed state [/etc/iptables/rules.v6] at time 21:04:16.464096 duration_in_ms=1.587
2019-06-26 21:04:16,465 [salt.state       :1780][INFO    ][13684] Running state [iptables_extra.flush_all] at time 21:04:16.465282
2019-06-26 21:04:16,467 [salt.state       :1813][INFO    ][13684] Executing state module.wait for [iptables_extra.flush_all]
2019-06-26 21:04:16,468 [salt.state       :300 ][INFO    ][13684] No changes made for iptables_extra.flush_all
2019-06-26 21:04:16,468 [salt.state       :1951][INFO    ][13684] Completed state [iptables_extra.flush_all] at time 21:04:16.468358 duration_in_ms=3.076
2019-06-26 21:04:16,472 [salt.minion      :1711][INFO    ][13684] Returning information for job: 20190626210403403629
2019-06-26 21:04:17,044 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210417031270
2019-06-26 21:04:17,073 [salt.minion      :1432][INFO    ][13791] Starting a new job with PID 13791
2019-06-26 21:04:18,116 [salt.state       :915 ][INFO    ][13791] Loading fresh modules for state activity
2019-06-26 21:04:19,049 [salt.state       :1780][INFO    ][13791] Running state [maas-rack-controller] at time 21:04:19.048908
2019-06-26 21:04:19,049 [salt.state       :1813][INFO    ][13791] Executing state pkg.installed for [maas-rack-controller]
2019-06-26 21:04:19,050 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13791] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 21:04:19,161 [salt.state       :300 ][INFO    ][13791] All specified packages are already installed
2019-06-26 21:04:19,161 [salt.state       :1951][INFO    ][13791] Completed state [maas-rack-controller] at time 21:04:19.161478 duration_in_ms=112.57
2019-06-26 21:04:19,161 [salt.state       :1780][INFO    ][13791] Running state [ipmitool] at time 21:04:19.161869
2019-06-26 21:04:19,162 [salt.state       :1813][INFO    ][13791] Executing state pkg.installed for [ipmitool]
2019-06-26 21:04:19,172 [salt.state       :300 ][INFO    ][13791] All specified packages are already installed
2019-06-26 21:04:19,173 [salt.state       :1951][INFO    ][13791] Completed state [ipmitool] at time 21:04:19.173099 duration_in_ms=11.229
2019-06-26 21:04:19,177 [salt.state       :1780][INFO    ][13791] Running state [/etc/maas/rackd.conf] at time 21:04:19.177192
2019-06-26 21:04:19,177 [salt.state       :1813][INFO    ][13791] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-26 21:04:19,179 [salt.state       :300 ][INFO    ][13791] No changes needed to be made
2019-06-26 21:04:19,180 [salt.state       :1951][INFO    ][13791] Completed state [/etc/maas/rackd.conf] at time 21:04:19.180048 duration_in_ms=2.856
2019-06-26 21:04:19,180 [salt.state       :1780][INFO    ][13791] Running state [/etc/maas/rackd.conf] at time 21:04:19.180304
2019-06-26 21:04:19,180 [salt.state       :1813][INFO    ][13791] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-26 21:04:19,180 [salt.loaded.int.states.file:2298][WARNING ][13791] 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-06-26 21:04:19,181 [salt.state       :300 ][INFO    ][13791] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-26 21:04:19,182 [salt.state       :1951][INFO    ][13791] Completed state [/etc/maas/rackd.conf] at time 21:04:19.182078 duration_in_ms=1.774
2019-06-26 21:04:19,183 [salt.state       :1780][INFO    ][13791] Running state [maas-rackd] at time 21:04:19.183143
2019-06-26 21:04:19,183 [salt.state       :1813][INFO    ][13791] Executing state service.running for [maas-rackd]
2019-06-26 21:04:19,184 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13791] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:19,225 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13791] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-26 21:04:19,244 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13791] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-26 21:04:19,267 [salt.state       :300 ][INFO    ][13791] The service maas-rackd is already running
2019-06-26 21:04:19,267 [salt.state       :1951][INFO    ][13791] Completed state [maas-rackd] at time 21:04:19.267391 duration_in_ms=84.247
2019-06-26 21:04:19,269 [salt.minion      :1711][INFO    ][13791] Returning information for job: 20190626210417031270
2019-06-26 21:04:19,829 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210419816211
2019-06-26 21:04:19,855 [salt.minion      :1432][INFO    ][13815] Starting a new job with PID 13815
2019-06-26 21:04:20,901 [salt.state       :915 ][INFO    ][13815] Loading fresh modules for state activity
2019-06-26 21:04:21,961 [salt.state       :1780][INFO    ][13815] Running state [maas-region-controller] at time 21:04:21.961438
2019-06-26 21:04:21,962 [salt.state       :1813][INFO    ][13815] Executing state pkg.installed for [maas-region-controller]
2019-06-26 21:04:21,963 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-26 21:04:22,081 [salt.state       :300 ][INFO    ][13815] All specified packages are already installed
2019-06-26 21:04:22,081 [salt.state       :1951][INFO    ][13815] Completed state [maas-region-controller] at time 21:04:22.081384 duration_in_ms=119.946
2019-06-26 21:04:22,082 [salt.state       :1780][INFO    ][13815] Running state [python-oauth] at time 21:04:22.082723
2019-06-26 21:04:22,083 [salt.state       :1813][INFO    ][13815] Executing state pkg.installed for [python-oauth]
2019-06-26 21:04:22,091 [salt.state       :300 ][INFO    ][13815] All specified packages are already installed
2019-06-26 21:04:22,091 [salt.state       :1951][INFO    ][13815] Completed state [python-oauth] at time 21:04:22.091560 duration_in_ms=8.837
2019-06-26 21:04:22,095 [salt.state       :1780][INFO    ][13815] Running state [/etc/maas/regiond.conf] at time 21:04:22.095426
2019-06-26 21:04:22,095 [salt.state       :1813][INFO    ][13815] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-26 21:04:22,100 [salt.state       :300 ][INFO    ][13815] No changes needed to be made
2019-06-26 21:04:22,100 [salt.state       :1951][INFO    ][13815] Completed state [/etc/maas/regiond.conf] at time 21:04:22.100371 duration_in_ms=4.945
2019-06-26 21:04:22,100 [salt.state       :1780][INFO    ][13815] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:04:22.100860
2019-06-26 21:04:22,101 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-26 21:04:22,174 [salt.state       :300 ][INFO    ][13815] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-26 21:04:22,175 [salt.state       :1951][INFO    ][13815] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:04:22.175161 duration_in_ms=74.301
2019-06-26 21:04:22,175 [salt.state       :1780][INFO    ][13815] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:04:22.175673
2019-06-26 21:04:22,175 [salt.state       :1813][INFO    ][13815] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-26 21:04:22,184 [salt.state       :300 ][INFO    ][13815] No changes needed to be made
2019-06-26 21:04:22,184 [salt.state       :1951][INFO    ][13815] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:04:22.184403 duration_in_ms=8.73
2019-06-26 21:04:22,184 [salt.state       :1780][INFO    ][13815] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:04:22.184893
2019-06-26 21:04:22,185 [salt.state       :1813][INFO    ][13815] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-26 21:04:22,188 [salt.state       :300 ][INFO    ][13815] No changes needed to be made
2019-06-26 21:04:22,188 [salt.state       :1951][INFO    ][13815] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:04:22.188707 duration_in_ms=3.813
2019-06-26 21:04:22,189 [salt.state       :1780][INFO    ][13815] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:04:22.189184
2019-06-26 21:04:22,189 [salt.state       :1813][INFO    ][13815] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-26 21:04:22,230 [salt.state       :300 ][INFO    ][13815] No changes needed to be made
2019-06-26 21:04:22,230 [salt.state       :1951][INFO    ][13815] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:04:22.230546 duration_in_ms=41.362
2019-06-26 21:04:22,231 [salt.state       :1780][INFO    ][13815] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:04:22.231105
2019-06-26 21:04:22,231 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-26 21:04:22,249 [salt.state       :300 ][INFO    ][13815] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-26 21:04:22,252 [salt.state       :1951][INFO    ][13815] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:04:22.252618 duration_in_ms=21.511
2019-06-26 21:04:22,254 [salt.state       :1780][INFO    ][13815] Running state [a2enmod headers] at time 21:04:22.254301
2019-06-26 21:04:22,254 [salt.state       :1813][INFO    ][13815] Executing state cmd.run for [a2enmod headers]
2019-06-26 21:04:22,255 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command 'a2enmod headers' in directory '/root'
2019-06-26 21:04:22,321 [salt.state       :300 ][INFO    ][13815] {'pid': 13841, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-26 21:04:22,323 [salt.state       :1951][INFO    ][13815] Completed state [a2enmod headers] at time 21:04:22.323641 duration_in_ms=69.341
2019-06-26 21:04:22,324 [salt.state       :1780][INFO    ][13815] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:04:22.324237
2019-06-26 21:04:22,325 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-26 21:04:22,353 [salt.state       :300 ][INFO    ][13815] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-26 21:04:22,353 [salt.state       :1951][INFO    ][13815] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:04:22.353660 duration_in_ms=29.423
2019-06-26 21:04:22,354 [salt.state       :1780][INFO    ][13815] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:04:22.354751
2019-06-26 21:04:22,355 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-26 21:04:22,424 [salt.state       :300 ][INFO    ][13815] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-26 21:04:22,424 [salt.state       :1951][INFO    ][13815] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:04:22.424745 duration_in_ms=69.995
2019-06-26 21:04:22,425 [salt.state       :1780][INFO    ][13815] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:04:22.425276
2019-06-26 21:04:22,425 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-26 21:04:22,486 [salt.state       :300 ][INFO    ][13815] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-26 21:04:22,486 [salt.state       :1951][INFO    ][13815] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:04:22.486891 duration_in_ms=61.614
2019-06-26 21:04:22,487 [salt.state       :1780][INFO    ][13815] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:04:22.487756
2019-06-26 21:04:22,488 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-26 21:04:22,568 [salt.state       :300 ][INFO    ][13815] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-26 21:04:22,568 [salt.state       :1951][INFO    ][13815] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:04:22.568305 duration_in_ms=80.549
2019-06-26 21:04:22,568 [salt.state       :1780][INFO    ][13815] Running state [/root/.pgpass] at time 21:04:22.568551
2019-06-26 21:04:22,568 [salt.state       :1813][INFO    ][13815] Executing state file.managed for [/root/.pgpass]
2019-06-26 21:04:22,621 [salt.state       :300 ][INFO    ][13815] File /root/.pgpass is in the correct state
2019-06-26 21:04:22,621 [salt.state       :1951][INFO    ][13815] Completed state [/root/.pgpass] at time 21:04:22.621263 duration_in_ms=52.712
2019-06-26 21:04:22,627 [salt.state       :1780][INFO    ][13815] Running state [maas-region syncdb --noinput] at time 21:04:22.627595
2019-06-26 21:04:22,627 [salt.state       :1813][INFO    ][13815] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-26 21:04:22,628 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-26 21:04:25,146 [salt.state       :300 ][INFO    ][13815] {'pid': 13854, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: piston3, metadataserver, sites, auth, sessions, contenttypes, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-26 21:04:25,147 [salt.state       :1951][INFO    ][13815] Completed state [maas-region syncdb --noinput] at time 21:04:25.147376 duration_in_ms=2519.779
2019-06-26 21:04:25,148 [salt.state       :2022][WARNING ][13815] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-26 21:04:25,152 [salt.state       :1780][INFO    ][13815] Running state [maas-regiond] at time 21:04:25.151951
2019-06-26 21:04:25,152 [salt.state       :1813][INFO    ][13815] Executing state service.running for [maas-regiond]
2019-06-26 21:04:25,155 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:25,205 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-26 21:04:25,229 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-26 21:04:25,253 [salt.state       :300 ][INFO    ][13815] The service maas-regiond is already running
2019-06-26 21:04:25,253 [salt.state       :1951][INFO    ][13815] Completed state [maas-regiond] at time 21:04:25.253689 duration_in_ms=101.739
2019-06-26 21:04:25,257 [salt.state       :1780][INFO    ][13815] Running state [bind9] at time 21:04:25.256941
2019-06-26 21:04:25,257 [salt.state       :1813][INFO    ][13815] Executing state service.running for [bind9]
2019-06-26 21:04:25,258 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:25,285 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-26 21:04:25,307 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-26 21:04:25,331 [salt.state       :300 ][INFO    ][13815] The service bind9 is already running
2019-06-26 21:04:25,331 [salt.state       :1951][INFO    ][13815] Completed state [bind9] at time 21:04:25.331576 duration_in_ms=74.636
2019-06-26 21:04:25,335 [salt.state       :1780][INFO    ][13815] Running state [apache2] at time 21:04:25.335407
2019-06-26 21:04:25,335 [salt.state       :1813][INFO    ][13815] Executing state service.running for [apache2]
2019-06-26 21:04:25,337 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-26 21:04:25,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-26 21:04:25,382 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-26 21:04:25,410 [salt.state       :300 ][INFO    ][13815] The service apache2 is already running
2019-06-26 21:04:25,410 [salt.state       :1951][INFO    ][13815] Completed state [apache2] at time 21:04:25.410653 duration_in_ms=75.245
2019-06-26 21:04:25,412 [salt.state       :1780][INFO    ][13815] Running state [maasng.wait_for_http_code] at time 21:04:25.412641
2019-06-26 21:04:25,413 [salt.state       :1813][INFO    ][13815] Executing state module.run for [maasng.wait_for_http_code]
2019-06-26 21:04:25,414 [salt.utils.decorators:613 ][WARNING ][13815] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:25,558 [salt.state       :300 ][INFO    ][13815] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-26 21:04:25,559 [salt.state       :1951][INFO    ][13815] Completed state [maasng.wait_for_http_code] at time 21:04:25.558990 duration_in_ms=146.348
2019-06-26 21:04:25,560 [salt.state       :1780][INFO    ][13815] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:04:25.560041
2019-06-26 21:04:25,560 [salt.state       :1813][INFO    ][13815] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-26 21:04:25,561 [salt.state       :300 ][INFO    ][13815] /var/lib/maas/.setup_admin exists
2019-06-26 21:04:25,562 [salt.state       :1951][INFO    ][13815] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:04:25.561636 duration_in_ms=1.594
2019-06-26 21:04:25,563 [salt.state       :1780][INFO    ][13815] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:25.563580
2019-06-26 21:04:25,563 [salt.state       :1813][INFO    ][13815] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:04:25,565 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13815] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:04:27,272 [salt.state       :300 ][INFO    ][13815] {'pid': 13875, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:04:27,273 [salt.state       :1951][INFO    ][13815] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:27.273511 duration_in_ms=1709.928
2019-06-26 21:04:27,284 [salt.state       :1780][INFO    ][13815] Running state [maas_region_boot_source_resources_mirror] at time 21:04:27.284607
2019-06-26 21:04:27,284 [salt.state       :1813][INFO    ][13815] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-26 21:04:27,386 [salt.state       :300 ][INFO    ][13815] {'changes': {}}
2019-06-26 21:04:27,387 [salt.state       :1951][INFO    ][13815] Completed state [maas_region_boot_source_resources_mirror] at time 21:04:27.387006 duration_in_ms=102.399
2019-06-26 21:04:27,387 [salt.state       :1780][INFO    ][13815] Running state [maasng.boot_resources_import] at time 21:04:27.387934
2019-06-26 21:04:27,388 [salt.state       :1813][INFO    ][13815] Executing state module.run for [maasng.boot_resources_import]
2019-06-26 21:04:27,388 [salt.utils.decorators:613 ][WARNING ][13815] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:27,478 [salt.loaded.ext.module.maasng:1600][INFO    ][13815] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-26 21:04:32,527 [salt.loaded.ext.module.maasng:1600][INFO    ][13815] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-26 21:04:34,870 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210434849329
2019-06-26 21:04:34,920 [salt.minion      :1432][INFO    ][14029] Starting a new job with PID 14029
2019-06-26 21:04:34,964 [salt.minion      :1711][INFO    ][14029] Returning information for job: 20190626210434849329
2019-06-26 21:04:37,628 [salt.state       :300 ][INFO    ][13815] {'ret': True}
2019-06-26 21:04:37,628 [salt.state       :1951][INFO    ][13815] Completed state [maasng.boot_resources_import] at time 21:04:37.628701 duration_in_ms=10240.767
2019-06-26 21:04:37,630 [salt.state       :1780][INFO    ][13815] Running state [maas_region_boot_sources_selection_xenial] at time 21:04:37.630415
2019-06-26 21:04:37,630 [salt.state       :1813][INFO    ][13815] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-26 21:04:37,813 [salt.state       :300 ][INFO    ][13815] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-26 21:04:37,814 [salt.state       :1951][INFO    ][13815] Completed state [maas_region_boot_sources_selection_xenial] at time 21:04:37.813658 duration_in_ms=183.242
2019-06-26 21:04:37,816 [salt.state       :1780][INFO    ][13815] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:04:37.815920
2019-06-26 21:04:37,816 [salt.state       :1813][INFO    ][13815] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-26 21:04:37,817 [salt.utils.decorators:613 ][WARNING ][13815] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:37,817 [salt.loaded.ext.module.maasng:1771][INFO    ][13815] boot-sources sync initiated for ALL Rack's
2019-06-26 21:04:38,893 [salt.state       :300 ][INFO    ][13815] {'ret': True}
2019-06-26 21:04:38,895 [salt.state       :1951][INFO    ][13815] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:04:38.895451 duration_in_ms=1079.53
2019-06-26 21:04:38,898 [salt.state       :1780][INFO    ][13815] Running state [maas.process_maas_config] at time 21:04:38.897958
2019-06-26 21:04:38,898 [salt.state       :1813][INFO    ][13815] Executing state module.run for [maas.process_maas_config]
2019-06-26 21:04:38,899 [salt.utils.decorators:613 ][WARNING ][13815] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:38,899 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=enable_http_proxy value=True
2019-06-26 21:04:38,955 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=upstream_dns value=8.8.8.8
2019-06-26 21:04:39,010 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=commissioning_distro_series value=xenial
2019-06-26 21:04:39,070 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=default_osystem value=ubuntu
2019-06-26 21:04:40,425 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=active_discovery_interval value=600
2019-06-26 21:04:40,488 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=dnssec_validation value=no
2019-06-26 21:04:40,532 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=maas_name value=mas01
2019-06-26 21:04:40,577 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=network_discovery value=enabled
2019-06-26 21:04:40,668 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=enable_third_party_drivers value=True
2019-06-26 21:04:40,731 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=default_storage_layout value=lvm
2019-06-26 21:04:40,779 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=ntp_external_only value=True
2019-06-26 21:04:40,829 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-26 21:04:40,880 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=default_distro_series value=xenial
2019-06-26 21:04:40,943 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-26 21:04:41,058 [salt.state       :300 ][INFO    ][13815] {'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-06-26 21:04:41,059 [salt.state       :1951][INFO    ][13815] Completed state [maas.process_maas_config] at time 21:04:41.058937 duration_in_ms=2160.979
2019-06-26 21:04:41,059 [salt.state       :1780][INFO    ][13815] Running state [pxe_admin] at time 21:04:41.059586
2019-06-26 21:04:41,059 [salt.state       :1813][INFO    ][13815] Executing state maasng.fabric_present for [pxe_admin]
2019-06-26 21:04:41,111 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, 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'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'primary_rack': u'hpd6dr', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:41,170 [salt.loaded.ext.module.maasng:1008][WARNING ][13815] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-26 21:04:41,170 [salt.loaded.ext.module.maasng:1011][WARNING ][13815] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-26 21:04:41,233 [salt.state       :300 ][INFO    ][13815] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-26 21:04:41,235 [salt.state       :1951][INFO    ][13815] Completed state [pxe_admin] at time 21:04:41.233684 duration_in_ms=174.097
2019-06-26 21:04:41,235 [salt.state       :1780][INFO    ][13815] Running state [vlan 0] at time 21:04:41.235410
2019-06-26 21:04:41,235 [salt.state       :1813][INFO    ][13815] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-26 21:04:41,287 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'id': 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'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'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 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'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'fabric': u'fabric-2'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'hpd6dr', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:41,418 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None, u'name': u'fabric-2', u'id': 2}, {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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'hpd6dr', u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u'', u'name': u'pxe_admin', u'id': 1}]
2019-06-26 21:04:41,659 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, 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'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'primary_rack': u'hpd6dr', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:41,744 [salt.state       :300 ][INFO    ][13815] {'new': 'Vlan untagged was updated'}
2019-06-26 21:04:41,745 [salt.state       :1951][INFO    ][13815] Completed state [vlan 0] at time 21:04:41.745187 duration_in_ms=509.777
2019-06-26 21:04:41,746 [salt.state       :1780][INFO    ][13815] Running state [192.168.11.0/24] at time 21:04:41.746533
2019-06-26 21:04:41,747 [salt.state       :1813][INFO    ][13815] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-26 21:04:41,926 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'id': 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'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'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 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'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'fabric': u'fabric-2'}], u'class_type': None, u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'hpd6dr', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:41,927 [salt.loaded.ext.module.maasng:1235][WARNING ][13815] Ignoring parameter vlan:0
2019-06-26 21:04:41,992 [salt.state       :300 ][INFO    ][13815] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-26 21:04:41,993 [salt.state       :1951][INFO    ][13815] Completed state [192.168.11.0/24] at time 21:04:41.993137 duration_in_ms=246.603
2019-06-26 21:04:41,995 [salt.state       :1780][INFO    ][13815] Running state [maas_create_iprange_1] at time 21:04:41.995414
2019-06-26 21:04:41,995 [salt.state       :1813][INFO    ][13815] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-26 21:04:42,041 [salt.state       :300 ][INFO    ][13815] Iprange maas_create_iprange_1 already exist.
2019-06-26 21:04:42,041 [salt.state       :1951][INFO    ][13815] Completed state [maas_create_iprange_1] at time 21:04:42.041254 duration_in_ms=45.84
2019-06-26 21:04:42,041 [salt.state       :1780][INFO    ][13815] Running state [vlan 0] at time 21:04:42.041525
2019-06-26 21:04:42,042 [salt.state       :1813][INFO    ][13815] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-26 21:04:42,084 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, 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'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'primary_rack': u'hpd6dr', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:42,199 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'hpd6dr', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin', u'class_type': u''}]
2019-06-26 21:04:42,479 [salt.loaded.ext.module.maasng:945 ][INFO    ][13815] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, 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'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'primary_rack': u'hpd6dr', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-06-26 21:04:42,588 [salt.state       :300 ][INFO    ][13815] {'new': 'Vlan untagged was updated'}
2019-06-26 21:04:42,588 [salt.state       :1951][INFO    ][13815] Completed state [vlan 0] at time 21:04:42.588728 duration_in_ms=547.201
2019-06-26 21:04:42,589 [salt.state       :1780][INFO    ][13815] Running state [opnfv] at time 21:04:42.589433
2019-06-26 21:04:42,592 [salt.state       :1813][INFO    ][13815] Executing state maasng.sshkey_present for [opnfv]
2019-06-26 21:04:42,632 [salt.loaded.ext.module.maasng:1903][INFO    ][13815] [{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-06-26 21:04:42,632 [salt.state       :300 ][INFO    ][13815] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-06-26 21:04:42,632 [salt.state       :1951][INFO    ][13815] Completed state [opnfv] at time 21:04:42.632689 duration_in_ms=43.256
2019-06-26 21:04:42,633 [salt.state       :1780][INFO    ][13815] Running state [maas.process_tags] at time 21:04:42.633419
2019-06-26 21:04:42,634 [salt.state       :1813][INFO    ][13815] Executing state module.run for [maas.process_tags]
2019-06-26 21:04:42,634 [salt.utils.decorators:613 ][WARNING ][13815] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:42,691 [salt.loaded.ext.module.maas:92  ][INFO    ][13815] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-26 21:04:42,752 [salt.state       :300 ][INFO    ][13815] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-26 21:04:42,752 [salt.state       :1951][INFO    ][13815] Completed state [maas.process_tags] at time 21:04:42.752785 duration_in_ms=119.367
2019-06-26 21:04:42,755 [salt.minion      :1711][INFO    ][13815] Returning information for job: 20190626210419816211
2019-06-26 21:04:43,379 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210443363929
2019-06-26 21:04:43,405 [salt.minion      :1432][INFO    ][14261] Starting a new job with PID 14261
2019-06-26 21:04:51,593 [salt.state       :915 ][INFO    ][14261] Loading fresh modules for state activity
2019-06-26 21:04:51,703 [salt.state       :1780][INFO    ][14261] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:51.703619
2019-06-26 21:04:51,703 [salt.state       :1813][INFO    ][14261] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:04:51,705 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14261] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:04:53,497 [salt.state       :300 ][INFO    ][14261] {'pid': 14284, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:04:53,498 [salt.state       :1951][INFO    ][14261] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:53.498585 duration_in_ms=1794.966
2019-06-26 21:04:53,500 [salt.state       :1780][INFO    ][14261] Running state [maas.process_machines] at time 21:04:53.500691
2019-06-26 21:04:53,501 [salt.state       :1813][INFO    ][14261] Executing state module.run for [maas.process_machines]
2019-06-26 21:04:53,501 [salt.utils.decorators:613 ][WARNING ][14261] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:04:53,980 [salt.loaded.ext.module.maas:412 ][WARNING ][14261] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 21:04:53,981 [salt.loaded.ext.module.maas:92  ][INFO    ][14261] machine hostname=gtw01 power_type=ipmi mac_addresses=['14:58:d0:54:6a:60'] power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 system_id=tarten architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 21:04:55,167 [salt.loaded.ext.module.maas:412 ][WARNING ][14261] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 21:04:55,168 [salt.loaded.ext.module.maas:92  ][INFO    ][14261] 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=bxh6nq architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 21:04:56,384 [salt.loaded.ext.module.maas:412 ][WARNING ][14261] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 21:04:56,385 [salt.loaded.ext.module.maas:92  ][INFO    ][14261] 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=ffgqpr architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 21:04:57,616 [salt.loaded.ext.module.maas:412 ][WARNING ][14261] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-26 21:04:57,617 [salt.loaded.ext.module.maas:92  ][INFO    ][14261] machine hostname=ctl01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=gqdm3y architecture=amd64/generic power_parameters_power_user=opnfv
2019-06-26 21:04:58,475 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210458465606
2019-06-26 21:04:58,495 [salt.minion      :1432][INFO    ][14475] Starting a new job with PID 14475
2019-06-26 21:04:58,519 [salt.minion      :1711][INFO    ][14475] Returning information for job: 20190626210458465606
2019-06-26 21:04:58,831 [salt.state       :300 ][INFO    ][14261] {'ret': {'updated': ['gtw01', 'cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-26 21:04:58,831 [salt.state       :1951][INFO    ][14261] Completed state [maas.process_machines] at time 21:04:58.831865 duration_in_ms=5331.173
2019-06-26 21:04:58,835 [salt.minion      :1711][INFO    ][14261] Returning information for job: 20190626210443363929
2019-06-26 21:05:31,437 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210531422544
2019-06-26 21:05:31,460 [salt.minion      :1432][INFO    ][14519] Starting a new job with PID 14519
2019-06-26 21:05:39,566 [salt.state       :915 ][INFO    ][14519] Loading fresh modules for state activity
2019-06-26 21:05:39,675 [salt.state       :1780][INFO    ][14519] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:39.675708
2019-06-26 21:05:39,676 [salt.state       :1813][INFO    ][14519] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:05:39,678 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14519] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:05:41,393 [salt.state       :300 ][INFO    ][14519] {'pid': 14528, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:05:41,394 [salt.state       :1951][INFO    ][14519] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:41.394537 duration_in_ms=1718.829
2019-06-26 21:05:41,398 [salt.state       :1780][INFO    ][14519] Running state [maas.wait_for_machine_status] at time 21:05:41.397694
2019-06-26 21:05:41,398 [salt.state       :1813][INFO    ][14519] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 21:05:41,399 [salt.utils.decorators:613 ][WARNING ][14519] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:05:43,306 [salt.state       :300 ][INFO    ][14519] {'ret': True}
2019-06-26 21:05:43,306 [salt.state       :1951][INFO    ][14519] Completed state [maas.wait_for_machine_status] at time 21:05:43.306560 duration_in_ms=1908.864
2019-06-26 21:05:43,312 [salt.minion      :1711][INFO    ][14519] Returning information for job: 20190626210531422544
2019-06-26 21:05:43,891 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210543876070
2019-06-26 21:05:43,920 [salt.minion      :1432][INFO    ][14541] Starting a new job with PID 14541
2019-06-26 21:05:44,993 [salt.state       :915 ][INFO    ][14541] Loading fresh modules for state activity
2019-06-26 21:05:45,139 [salt.state       :1780][INFO    ][14541] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:45.139599
2019-06-26 21:05:45,139 [salt.state       :1813][INFO    ][14541] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:05:45,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14541] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:05:46,813 [salt.state       :300 ][INFO    ][14541] {'pid': 14548, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:05:46,815 [salt.state       :1951][INFO    ][14541] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:46.815065 duration_in_ms=1675.466
2019-06-26 21:05:46,816 [salt.state       :1780][INFO    ][14541] Running state [maas_machines_storage_cmp002_lvm] at time 21:05:46.816802
2019-06-26 21:05:46,817 [salt.state       :1813][INFO    ][14541] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-26 21:05:47,302 [salt.state       :300 ][INFO    ][14541] Machine cmp002 is not in Ready state.
2019-06-26 21:05:47,302 [salt.state       :1951][INFO    ][14541] Completed state [maas_machines_storage_cmp002_lvm] at time 21:05:47.302559 duration_in_ms=485.756
2019-06-26 21:05:47,303 [salt.state       :1780][INFO    ][14541] Running state [maas_machines_storage_cmp001_lvm] at time 21:05:47.303168
2019-06-26 21:05:47,303 [salt.state       :1813][INFO    ][14541] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-26 21:05:47,787 [salt.state       :300 ][INFO    ][14541] Machine cmp001 is not in Ready state.
2019-06-26 21:05:47,787 [salt.state       :1951][INFO    ][14541] Completed state [maas_machines_storage_cmp001_lvm] at time 21:05:47.787535 duration_in_ms=484.368
2019-06-26 21:05:47,790 [salt.minion      :1711][INFO    ][14541] Returning information for job: 20190626210543876070
2019-06-26 21:05:48,348 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210548335359
2019-06-26 21:05:48,376 [salt.minion      :1432][INFO    ][14558] Starting a new job with PID 14558
2019-06-26 21:05:49,410 [salt.state       :915 ][INFO    ][14558] Loading fresh modules for state activity
2019-06-26 21:05:49,500 [salt.state       :1780][INFO    ][14558] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:49.500859
2019-06-26 21:05:49,501 [salt.state       :1813][INFO    ][14558] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:05:49,503 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14558] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:05:51,183 [salt.state       :300 ][INFO    ][14558] {'pid': 14565, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:05:51,184 [salt.state       :1951][INFO    ][14558] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:51.184654 duration_in_ms=1683.795
2019-06-26 21:05:51,188 [salt.state       :1780][INFO    ][14558] Running state [maas.deploy_machines] at time 21:05:51.188072
2019-06-26 21:05:51,188 [salt.state       :1813][INFO    ][14558] Executing state module.run for [maas.deploy_machines]
2019-06-26 21:05:51,188 [salt.utils.decorators:613 ][WARNING ][14558] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:05:51,678 [salt.loaded.ext.module.maas:684 ][INFO    ][14558] deploymachines hwe_kernel=hwe-16.04 system_id=tarten distro_series=xenial
2019-06-26 21:05:54,238 [salt.state       :300 ][INFO    ][14558] {'ret': {'updated': ['cmp002', 'cmp001', 'ctl01'], 'errors': {}, 'success': ['gtw01']}}
2019-06-26 21:05:54,239 [salt.state       :1951][INFO    ][14558] Completed state [maas.deploy_machines] at time 21:05:54.238823 duration_in_ms=3050.75
2019-06-26 21:05:54,246 [salt.minion      :1711][INFO    ][14558] Returning information for job: 20190626210548335359
2019-06-26 21:05:54,823 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command state.apply with jid 20190626210554808139
2019-06-26 21:05:54,851 [salt.minion      :1432][INFO    ][14642] Starting a new job with PID 14642
2019-06-26 21:06:03,029 [salt.state       :915 ][INFO    ][14642] Loading fresh modules for state activity
2019-06-26 21:06:03,123 [salt.state       :1780][INFO    ][14642] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:06:03.123290
2019-06-26 21:06:03,123 [salt.state       :1813][INFO    ][14642] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-26 21:06:03,125 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14642] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-26 21:06:04,878 [salt.state       :300 ][INFO    ][14642] {'pid': 14654, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-26 21:06:04,879 [salt.state       :1951][INFO    ][14642] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:06:04.879297 duration_in_ms=1756.006
2019-06-26 21:06:04,882 [salt.state       :1780][INFO    ][14642] Running state [maas.wait_for_machine_status] at time 21:06:04.882210
2019-06-26 21:06:04,882 [salt.state       :1813][INFO    ][14642] Executing state module.run for [maas.wait_for_machine_status]
2019-06-26 21:06:04,883 [salt.utils.decorators:613 ][WARNING ][14642] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-26 21:06:06,861 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2248.03594208s left)
2019-06-26 21:06:09,880 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210609871117
2019-06-26 21:06:09,898 [salt.minion      :1432][INFO    ][14666] Starting a new job with PID 14666
2019-06-26 21:06:09,923 [salt.minion      :1711][INFO    ][14666] Returning information for job: 20190626210609871117
2019-06-26 21:06:38,753 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2216.14343214s left)
2019-06-26 21:06:40,102 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210640048981
2019-06-26 21:06:40,133 [salt.minion      :1432][INFO    ][14717] Starting a new job with PID 14717
2019-06-26 21:06:40,156 [salt.minion      :1711][INFO    ][14717] Returning information for job: 20190626210640048981
2019-06-26 21:07:10,187 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210710174977
2019-06-26 21:07:10,217 [salt.minion      :1432][INFO    ][14766] Starting a new job with PID 14766
2019-06-26 21:07:10,244 [salt.minion      :1711][INFO    ][14766] Returning information for job: 20190626210710174977
2019-06-26 21:07:10,784 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2184.11254811s left)
2019-06-26 21:07:40,281 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210740266873
2019-06-26 21:07:40,311 [salt.minion      :1432][INFO    ][14954] Starting a new job with PID 14954
2019-06-26 21:07:40,335 [salt.minion      :1711][INFO    ][14954] Returning information for job: 20190626210740266873
2019-06-26 21:07:42,757 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2152.13979602s left)
2019-06-26 21:08:05,550 [salt.utils.schedule:1377][INFO    ][5494] Running scheduled job: __mine_interval
2019-06-26 21:08:10,373 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210810360446
2019-06-26 21:08:10,400 [salt.minion      :1432][INFO    ][15002] Starting a new job with PID 15002
2019-06-26 21:08:10,424 [salt.minion      :1711][INFO    ][15002] Returning information for job: 20190626210810360446
2019-06-26 21:08:14,669 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2120.22746205s left)
2019-06-26 21:08:40,468 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210840452911
2019-06-26 21:08:40,493 [salt.minion      :1432][INFO    ][15035] Starting a new job with PID 15035
2019-06-26 21:08:40,520 [salt.minion      :1711][INFO    ][15035] Returning information for job: 20190626210840452911
2019-06-26 21:08:46,649 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2088.24770212s left)
2019-06-26 21:09:10,558 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210910545555
2019-06-26 21:09:10,585 [salt.minion      :1432][INFO    ][15083] Starting a new job with PID 15083
2019-06-26 21:09:10,612 [salt.minion      :1711][INFO    ][15083] Returning information for job: 20190626210910545555
2019-06-26 21:09:18,606 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2056.29022002s left)
2019-06-26 21:09:40,648 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626210940631521
2019-06-26 21:09:40,675 [salt.minion      :1432][INFO    ][15111] Starting a new job with PID 15111
2019-06-26 21:09:40,698 [salt.minion      :1711][INFO    ][15111] Returning information for job: 20190626210940631521
2019-06-26 21:09:50,477 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (2024.419842s left)
2019-06-26 21:10:10,745 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211010734586
2019-06-26 21:10:10,771 [salt.minion      :1432][INFO    ][15184] Starting a new job with PID 15184
2019-06-26 21:10:10,795 [salt.minion      :1711][INFO    ][15184] Returning information for job: 20190626211010734586
2019-06-26 21:10:22,587 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1992.30910802s left)
2019-06-26 21:10:40,807 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211040793882
2019-06-26 21:10:40,837 [salt.minion      :1432][INFO    ][15211] Starting a new job with PID 15211
2019-06-26 21:10:40,858 [salt.minion      :1711][INFO    ][15211] Returning information for job: 20190626211040793882
2019-06-26 21:10:54,609 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1960.28752613s left)
2019-06-26 21:11:10,929 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211110916193
2019-06-26 21:11:10,955 [salt.minion      :1432][INFO    ][15375] Starting a new job with PID 15375
2019-06-26 21:11:10,988 [salt.minion      :1711][INFO    ][15375] Returning information for job: 20190626211110916193
2019-06-26 21:11:26,599 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1928.297966s left)
2019-06-26 21:11:41,032 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211141020383
2019-06-26 21:11:41,060 [salt.minion      :1432][INFO    ][15425] Starting a new job with PID 15425
2019-06-26 21:11:41,083 [salt.minion      :1711][INFO    ][15425] Returning information for job: 20190626211141020383
2019-06-26 21:11:58,505 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1896.39167905s left)
2019-06-26 21:12:11,153 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211211142205
2019-06-26 21:12:11,181 [salt.minion      :1432][INFO    ][15519] Starting a new job with PID 15519
2019-06-26 21:12:11,207 [salt.minion      :1711][INFO    ][15519] Returning information for job: 20190626211211142205
2019-06-26 21:12:30,438 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1864.45938897s left)
2019-06-26 21:12:41,261 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211241252003
2019-06-26 21:12:41,286 [salt.minion      :1432][INFO    ][15542] Starting a new job with PID 15542
2019-06-26 21:12:41,309 [salt.minion      :1711][INFO    ][15542] Returning information for job: 20190626211241252003
2019-06-26 21:13:02,461 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1832.43554115s left)
2019-06-26 21:13:11,421 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211311403566
2019-06-26 21:13:11,453 [salt.minion      :1432][INFO    ][15661] Starting a new job with PID 15661
2019-06-26 21:13:11,480 [salt.minion      :1711][INFO    ][15661] Returning information for job: 20190626211311403566
2019-06-26 21:13:34,613 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1800.28403401s left)
2019-06-26 21:13:41,574 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211341564147
2019-06-26 21:13:41,603 [salt.minion      :1432][INFO    ][15685] Starting a new job with PID 15685
2019-06-26 21:13:41,632 [salt.minion      :1711][INFO    ][15685] Returning information for job: 20190626211341564147
2019-06-26 21:14:06,704 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1768.19222617s left)
2019-06-26 21:14:11,741 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211411728344
2019-06-26 21:14:11,765 [salt.minion      :1432][INFO    ][15860] Starting a new job with PID 15860
2019-06-26 21:14:11,790 [salt.minion      :1711][INFO    ][15860] Returning information for job: 20190626211411728344
2019-06-26 21:14:38,671 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1736.22544718s left)
2019-06-26 21:14:41,897 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211441880225
2019-06-26 21:14:41,920 [salt.minion      :1432][INFO    ][15883] Starting a new job with PID 15883
2019-06-26 21:14:41,947 [salt.minion      :1711][INFO    ][15883] Returning information for job: 20190626211441880225
2019-06-26 21:15:10,797 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1704.09955215s left)
2019-06-26 21:15:12,056 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211512042455
2019-06-26 21:15:12,084 [salt.minion      :1432][INFO    ][15936] Starting a new job with PID 15936
2019-06-26 21:15:12,117 [salt.minion      :1711][INFO    ][15936] Returning information for job: 20190626211512042455
2019-06-26 21:15:42,260 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211542244164
2019-06-26 21:15:42,289 [salt.minion      :1432][INFO    ][15959] Starting a new job with PID 15959
2019-06-26 21:15:42,317 [salt.minion      :1711][INFO    ][15959] Returning information for job: 20190626211542244164
2019-06-26 21:15:42,745 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1672.15167999s left)
2019-06-26 21:16:12,435 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211612419049
2019-06-26 21:16:12,462 [salt.minion      :1432][INFO    ][16019] Starting a new job with PID 16019
2019-06-26 21:16:12,492 [salt.minion      :1711][INFO    ][16019] Returning information for job: 20190626211612419049
2019-06-26 21:16:14,862 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1640.03506804s left)
2019-06-26 21:16:42,619 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211642603169
2019-06-26 21:16:42,651 [salt.minion      :1432][INFO    ][16041] Starting a new job with PID 16041
2019-06-26 21:16:42,669 [salt.minion      :1711][INFO    ][16041] Returning information for job: 20190626211642603169
2019-06-26 21:16:46,805 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1608.09181809s left)
2019-06-26 21:17:12,807 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211712792001
2019-06-26 21:17:12,838 [salt.minion      :1432][INFO    ][16116] Starting a new job with PID 16116
2019-06-26 21:17:12,858 [salt.minion      :1711][INFO    ][16116] Returning information for job: 20190626211712792001
2019-06-26 21:17:18,759 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1576.13736296s left)
2019-06-26 21:17:43,000 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211742984518
2019-06-26 21:17:43,032 [salt.minion      :1432][INFO    ][16142] Starting a new job with PID 16142
2019-06-26 21:17:43,053 [salt.minion      :1711][INFO    ][16142] Returning information for job: 20190626211742984518
2019-06-26 21:17:50,704 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1544.19226503s left)
2019-06-26 21:18:13,194 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211813179581
2019-06-26 21:18:13,220 [salt.minion      :1432][INFO    ][16217] Starting a new job with PID 16217
2019-06-26 21:18:13,243 [salt.minion      :1711][INFO    ][16217] Returning information for job: 20190626211813179581
2019-06-26 21:18:22,952 [salt.loaded.ext.module.maas:1023][INFO    ][14642] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1511.94465518s left)
2019-06-26 21:18:43,365 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command saltutil.find_job with jid 20190626211843351755
2019-06-26 21:18:43,396 [salt.minion      :1432][INFO    ][16264] Starting a new job with PID 16264
2019-06-26 21:18:43,421 [salt.minion      :1711][INFO    ][16264] Returning information for job: 20190626211843351755
2019-06-26 21:18:54,899 [salt.state       :300 ][INFO    ][14642] {'ret': True}
2019-06-26 21:18:54,900 [salt.state       :1951][INFO    ][14642] Completed state [maas.wait_for_machine_status] at time 21:18:54.900139 duration_in_ms=770017.927
2019-06-26 21:18:54,905 [salt.minion      :1711][INFO    ][14642] Returning information for job: 20190626210554808139
2019-06-26 22:08:05,550 [salt.utils.schedule:1377][INFO    ][5494] Running scheduled job: __mine_interval
2019-06-26 22:11:08,151 [salt.minion      :1308][INFO    ][5494] User sudo_ubuntu Executing command cp.push_dir with jid 20190626221108140038
2019-06-26 22:11:08,183 [salt.minion      :1432][INFO    ][20192] Starting a new job with PID 20192
