2019-04-18 09:26:02,566 [salt.minion      :870 ][ERROR   ][380] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-18 09:26:52,615 [salt.minion      :870 ][ERROR   ][380] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-18 09:27:42,656 [salt.minion      :870 ][ERROR   ][380] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-18 09:28:32,703 [salt.minion      :870 ][ERROR   ][380] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-18 09:29:22,749 [salt.minion      :870 ][ERROR   ][380] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-04-18 09:31:40,449 [salt.utils.decorators:613 ][WARNING ][2997] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:31:41,458 [salt.utils.decorators:613 ][WARNING ][2997] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:31:52,123 [salt.loaded.int.states.file:2298][WARNING ][3131] 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-04-18 09:31:56,325 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3348] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-18 09:31:56,349 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3348] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-04-18 09:31:56,383 [salt.utils.parsers:1051][WARNING ][380] Minion received a SIGTERM. Exiting.
2019-04-18 09:31:57,591 [salt.cli.daemons :293 ][INFO    ][3506] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-04-18 09:31:57,774 [salt.cli.daemons :82  ][INFO    ][3506] Starting up the Salt Minion
2019-04-18 09:31:57,775 [salt.utils.event :1017][INFO    ][3506] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-04-18 09:31:58,966 [salt.minion      :976 ][INFO    ][3506] Creating minion process manager
2019-04-18 09:32:00,018 [salt.state       :2022][WARNING ][3347] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-18 09:32:01,595 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][3506] Executing command ['date', '+%z'] in directory '/root'
2019-04-18 09:32:01,620 [salt.utils.schedule:568 ][INFO    ][3506] Updating job settings for scheduled job: __mine_interval
2019-04-18 09:32:01,622 [salt.minion      :1108][INFO    ][3506] Added mine.update to scheduler
2019-04-18 09:32:01,630 [salt.minion      :1975][INFO    ][3506] Minion is starting as user 'root'
2019-04-18 09:32:01,644 [salt.minion      :2336][INFO    ][3506] Minion is ready to receive requests!
2019-04-18 09:32:02,161 [salt.utils.decorators:613 ][WARNING ][3347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:32:08,315 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093208303720
2019-04-18 09:32:08,342 [salt.minion      :1432][INFO    ][4006] Starting a new job with PID 4006
2019-04-18 09:32:08,400 [salt.minion      :1711][INFO    ][4006] Returning information for job: 20190418093208303720
2019-04-18 09:32:12,756 [salt.utils.decorators:613 ][WARNING ][3347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:32:36,452 [salt.utils.decorators:613 ][WARNING ][3347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:32:37,348 [salt.utils.decorators:613 ][WARNING ][3347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:32:38,482 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093238471272
2019-04-18 09:32:38,507 [salt.minion      :1432][INFO    ][4773] Starting a new job with PID 4773
2019-04-18 09:32:38,554 [salt.minion      :1711][INFO    ][4773] Returning information for job: 20190418093238471272
2019-04-18 09:32:39,225 [salt.loaded.ext.module.maasng:1008][WARNING ][3347] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-04-18 09:32:39,225 [salt.loaded.ext.module.maasng:1011][WARNING ][3347] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-04-18 09:32:39,892 [salt.loaded.ext.module.maasng:1235][WARNING ][3347] Ignoring parameter vlan:0
2019-04-18 09:32:41,336 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418093241325458
2019-04-18 09:32:41,364 [salt.minion      :1432][INFO    ][4841] Starting a new job with PID 4841
2019-04-18 09:32:49,470 [salt.state       :915 ][INFO    ][4841] Loading fresh modules for state activity
2019-04-18 09:32:49,524 [salt.fileclient  :1219][INFO    ][4841] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-04-18 09:32:49,568 [salt.state       :1780][INFO    ][4841] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:49.567963
2019-04-18 09:32:49,568 [salt.state       :1813][INFO    ][4841] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 09:32:49,570 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4841] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 09:32:51,288 [salt.state       :300 ][INFO    ][4841] {'pid': 4867, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 09:32:51,289 [salt.state       :1951][INFO    ][4841] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:32:51.289392 duration_in_ms=1721.43
2019-04-18 09:32:51,293 [salt.state       :1780][INFO    ][4841] Running state [maas.process_machines] at time 09:32:51.293209
2019-04-18 09:32:51,293 [salt.state       :1813][INFO    ][4841] Executing state module.run for [maas.process_machines]
2019-04-18 09:32:51,293 [salt.utils.decorators:613 ][WARNING ][4841] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:32:51,349 [salt.loaded.ext.module.maas:412 ][WARNING ][4841] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 09:32:51,350 [salt.loaded.ext.module.maas:92  ][INFO    ][4841] machine hostname=cmp002 power_type=ipmi mac_addresses=9c:b6:54:8a:10:18 power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 09:32:52,701 [salt.loaded.ext.module.maas:412 ][WARNING ][4841] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 09:32:52,701 [salt.loaded.ext.module.maas:92  ][INFO    ][4841] machine hostname=cmp001 power_type=ipmi mac_addresses=9c:b6:54:8a:95:a0 power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 09:32:53,937 [salt.loaded.ext.module.maas:412 ][WARNING ][4841] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 09:32:53,938 [salt.loaded.ext.module.maas:92  ][INFO    ][4841] machine hostname=kvm01 power_type=ipmi mac_addresses=14:58:d0:54:e7:88 power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 09:32:55,188 [salt.loaded.ext.module.maas:412 ][WARNING ][4841] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 09:32:55,189 [salt.loaded.ext.module.maas:92  ][INFO    ][4841] machine hostname=kvm03 power_type=ipmi mac_addresses=14:58:d0:54:7a:28 power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 09:32:56,421 [salt.loaded.ext.module.maas:412 ][WARNING ][4841] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 09:32:56,422 [salt.loaded.ext.module.maas:92  ][INFO    ][4841] machine hostname=kvm02 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 09:32:56,456 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093256445114
2019-04-18 09:32:56,481 [salt.minion      :1432][INFO    ][5113] Starting a new job with PID 5113
2019-04-18 09:32:56,509 [salt.minion      :1711][INFO    ][5113] Returning information for job: 20190418093256445114
2019-04-18 09:32:57,709 [salt.state       :300 ][INFO    ][4841] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-04-18 09:32:57,710 [salt.state       :1951][INFO    ][4841] Completed state [maas.process_machines] at time 09:32:57.710404 duration_in_ms=6417.193
2019-04-18 09:32:57,716 [salt.minion      :1711][INFO    ][4841] Returning information for job: 20190418093241325458
2019-04-18 09:33:37,821 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418093337805365
2019-04-18 09:33:37,838 [salt.minion      :1432][INFO    ][5232] Starting a new job with PID 5232
2019-04-18 09:33:45,824 [salt.state       :915 ][INFO    ][5232] Loading fresh modules for state activity
2019-04-18 09:33:45,872 [salt.fileclient  :1219][INFO    ][5232] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-04-18 09:33:45,923 [salt.state       :1780][INFO    ][5232] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:33:45.923629
2019-04-18 09:33:45,923 [salt.state       :1813][INFO    ][5232] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 09:33:45,925 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5232] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 09:33:47,622 [salt.state       :300 ][INFO    ][5232] {'pid': 5241, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 09:33:47,624 [salt.state       :1951][INFO    ][5232] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:33:47.624097 duration_in_ms=1700.467
2019-04-18 09:33:47,628 [salt.state       :1780][INFO    ][5232] Running state [maas.wait_for_machine_status] at time 09:33:47.627913
2019-04-18 09:33:47,628 [salt.state       :1813][INFO    ][5232] Executing state module.run for [maas.wait_for_machine_status]
2019-04-18 09:33:47,629 [salt.utils.decorators:613 ][WARNING ][5232] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:33:48,371 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.26803684s left)
2019-04-18 09:33:52,894 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093352884196
2019-04-18 09:33:52,917 [salt.minion      :1432][INFO    ][5253] Starting a new job with PID 5253
2019-04-18 09:33:52,939 [salt.minion      :1711][INFO    ][5253] Returning information for job: 20190418093352884196
2019-04-18 09:34:19,130 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.50962687s left)
2019-04-18 09:34:23,060 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093423014044
2019-04-18 09:34:23,078 [salt.minion      :1432][INFO    ][5322] Starting a new job with PID 5322
2019-04-18 09:34:23,101 [salt.minion      :1711][INFO    ][5322] Returning information for job: 20190418093423014044
2019-04-18 09:34:49,945 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.69404697s left)
2019-04-18 09:34:53,119 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093453104945
2019-04-18 09:34:53,142 [salt.minion      :1432][INFO    ][5357] Starting a new job with PID 5357
2019-04-18 09:34:53,161 [salt.minion      :1711][INFO    ][5357] Returning information for job: 20190418093453104945
2019-04-18 09:35:20,937 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.70276093s left)
2019-04-18 09:35:23,184 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093523177400
2019-04-18 09:35:23,198 [salt.minion      :1432][INFO    ][5449] Starting a new job with PID 5449
2019-04-18 09:35:23,219 [salt.minion      :1711][INFO    ][5449] Returning information for job: 20190418093523177400
2019-04-18 09:35:52,031 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.60821605s left)
2019-04-18 09:35:53,393 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093553375605
2019-04-18 09:35:53,410 [salt.minion      :1432][INFO    ][5540] Starting a new job with PID 5540
2019-04-18 09:35:53,432 [salt.minion      :1711][INFO    ][5540] Returning information for job: 20190418093553375605
2019-04-18 09:36:23,245 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.39400196s left)
2019-04-18 09:36:23,482 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093623471185
2019-04-18 09:36:23,503 [salt.minion      :1432][INFO    ][5793] Starting a new job with PID 5793
2019-04-18 09:36:23,525 [salt.minion      :1711][INFO    ][5793] Returning information for job: 20190418093623471185
2019-04-18 09:36:53,708 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093653694115
2019-04-18 09:36:53,725 [salt.minion      :1432][INFO    ][5859] Starting a new job with PID 5859
2019-04-18 09:36:53,750 [salt.minion      :1711][INFO    ][5859] Returning information for job: 20190418093653694115
2019-04-18 09:36:54,562 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1313.077461s left)
2019-04-18 09:37:23,804 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093723793877
2019-04-18 09:37:23,827 [salt.minion      :1432][INFO    ][6142] Starting a new job with PID 6142
2019-04-18 09:37:23,852 [salt.minion      :1711][INFO    ][6142] Returning information for job: 20190418093723793877
2019-04-18 09:37:26,208 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1281.43154883s left)
2019-04-18 09:37:53,905 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093753896337
2019-04-18 09:37:53,930 [salt.minion      :1432][INFO    ][6306] Starting a new job with PID 6306
2019-04-18 09:37:53,957 [salt.minion      :1711][INFO    ][6306] Returning information for job: 20190418093753896337
2019-04-18 09:37:58,300 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1249.33924985s left)
2019-04-18 09:38:24,008 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093823991717
2019-04-18 09:38:24,025 [salt.minion      :1432][INFO    ][6655] Starting a new job with PID 6655
2019-04-18 09:38:24,050 [salt.minion      :1711][INFO    ][6655] Returning information for job: 20190418093823991717
2019-04-18 09:38:30,457 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1217.18200088s left)
2019-04-18 09:38:54,045 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093854031834
2019-04-18 09:38:54,072 [salt.minion      :1432][INFO    ][6743] Starting a new job with PID 6743
2019-04-18 09:38:54,108 [salt.minion      :1711][INFO    ][6743] Returning information for job: 20190418093854031834
2019-04-18 09:39:02,950 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1184.68954682s left)
2019-04-18 09:39:24,082 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093924068680
2019-04-18 09:39:24,107 [salt.minion      :1432][INFO    ][6900] Starting a new job with PID 6900
2019-04-18 09:39:24,131 [salt.minion      :1711][INFO    ][6900] Returning information for job: 20190418093924068680
2019-04-18 09:39:35,379 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1152.26048398s left)
2019-04-18 09:39:54,301 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418093954294109
2019-04-18 09:39:54,314 [salt.minion      :1432][INFO    ][6968] Starting a new job with PID 6968
2019-04-18 09:39:54,337 [salt.minion      :1711][INFO    ][6968] Returning information for job: 20190418093954294109
2019-04-18 09:40:07,968 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1119.67096686s left)
2019-04-18 09:40:24,409 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094024398270
2019-04-18 09:40:24,432 [salt.minion      :1432][INFO    ][7116] Starting a new job with PID 7116
2019-04-18 09:40:24,461 [salt.minion      :1711][INFO    ][7116] Returning information for job: 20190418094024398270
2019-04-18 09:40:40,507 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1087.13186193s left)
2019-04-18 09:40:54,633 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094054617607
2019-04-18 09:40:54,648 [salt.minion      :1432][INFO    ][7193] Starting a new job with PID 7193
2019-04-18 09:40:54,670 [salt.minion      :1711][INFO    ][7193] Returning information for job: 20190418094054617607
2019-04-18 09:41:13,077 [salt.loaded.ext.module.maas:1023][INFO    ][5232] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1054.56231189s left)
2019-04-18 09:41:24,849 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094124840697
2019-04-18 09:41:24,871 [salt.minion      :1432][INFO    ][7306] Starting a new job with PID 7306
2019-04-18 09:41:24,893 [salt.minion      :1711][INFO    ][7306] Returning information for job: 20190418094124840697
2019-04-18 09:41:45,766 [salt.state       :300 ][INFO    ][5232] {'ret': True}
2019-04-18 09:41:45,766 [salt.state       :1951][INFO    ][5232] Completed state [maas.wait_for_machine_status] at time 09:41:45.766519 duration_in_ms=478138.606
2019-04-18 09:41:45,770 [salt.minion      :1711][INFO    ][5232] Returning information for job: 20190418093337805365
2019-04-18 09:41:46,322 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418094146313447
2019-04-18 09:41:46,344 [salt.minion      :1432][INFO    ][7376] Starting a new job with PID 7376
2019-04-18 09:41:54,469 [salt.state       :915 ][INFO    ][7376] Loading fresh modules for state activity
2019-04-18 09:41:54,520 [salt.fileclient  :1219][INFO    ][7376] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-04-18 09:41:54,620 [salt.state       :1780][INFO    ][7376] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:54.619969
2019-04-18 09:41:54,620 [salt.state       :1813][INFO    ][7376] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 09:41:54,621 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7376] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 09:41:56,412 [salt.state       :300 ][INFO    ][7376] {'pid': 7412, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 09:41:56,413 [salt.state       :1951][INFO    ][7376] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:41:56.413215 duration_in_ms=1793.245
2019-04-18 09:41:56,418 [salt.state       :1780][INFO    ][7376] Running state [maas_machines_storage_cmp002_lvm] at time 09:41:56.417954
2019-04-18 09:41:56,418 [salt.state       :1813][INFO    ][7376] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-18 09:41:57,554 [salt.loaded.ext.module.maasng:610 ][INFO    ][7376] b7kawf
2019-04-18 09:41:57,554 [salt.loaded.ext.module.maasng:626 ][INFO    ][7376] sda
2019-04-18 09:41:58,152 [salt.loaded.ext.module.maasng:361 ][INFO    ][7376] b7kawf
2019-04-18 09:41:58,221 [salt.loaded.ext.module.maasng:367 ][INFO    ][7376] [{u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'b7kawf', u'block_size': 4096, u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id': 1, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'used_size': 800106479616, u'model': u'LOGICAL VOLUME', u'partitions': [{u'size': 800101236736, u'uuid': u'09d7baa2-b1a3-43ea-af0b-3f754e9595f4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b7kawf', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'27d94375-a3cc-4c40-8710-baf22751ccad', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'device_id': 1}]}, {u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/3/', u'uuid': u'b18d26ba-2539-4418-98fc-287fd7a344e7', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'39257da0-d2d2-44fe-8e4b-815346a90204', u'fstype': u'ext4', u'mount_options': None}, u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'b7kawf', u'block_size': 4096, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id': 3, u'available_size': 0, u'serial': None, u'size': 800097042432, u'used_size': 800097042432, u'model': None, u'partitions': []}]
2019-04-18 09:41:58,222 [salt.loaded.ext.module.maasng:632 ][INFO    ][7376] vgroot
2019-04-18 09:41:58,222 [salt.loaded.ext.module.maasng:635 ][INFO    ][7376] lvroot
2019-04-18 09:41:58,222 [salt.loaded.ext.module.maasng:639 ][INFO    ][7376] 107374182400
2019-04-18 09:41:58,733 [salt.loaded.ext.module.maasng:645 ][INFO    ][7376] {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'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'cpu_count': 40, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/', u'available_size': 0, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'947d0607-4266-4cff-a3e3-83ab2b2511bd', u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b7kawf', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'0d4bcdcc-d224-42b2-a66e-1cb1c9775ab6', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 1, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'b7kawf', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456}, u'blockdevice_set': [{u'size': 800109715456, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'947d0607-4266-4cff-a3e3-83ab2b2511bd', u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b7kawf', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'0d4bcdcc-d224-42b2-a66e-1cb1c9775ab6', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 1, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'b7kawf', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/'}, {u'size': 107374182400, u'available_size': 0, u'uuid': u'0af0565c-8346-4b65-9a27-89f27b4c9438', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'b7kawf', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'71350bba-cf63-4d1e-bd40-ebdedd868fc0', u'fstype': u'ext4', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/11/'}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'b7kawf', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/11/', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'0af0565c-8346-4b65-9a27-89f27b4c9438', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'b7kawf', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'71350bba-cf63-4d1e-bd40-ebdedd868fc0', u'fstype': u'ext4', u'mount_options': None}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'serial': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'b7kawf', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'interface_set': [{u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 17, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'b7kawf', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/4/'}, {u'discovered': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:07:51', u'system_id': u'b7kawf', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/14/'}, {u'discovered': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:07:50', u'system_id': u'b7kawf', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/15/'}, {u'discovered': None, u'name': u'ens2f1', u'links': [{u'id': 18, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:12:49', u'system_id': u'b7kawf', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/11/'}, {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 19, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:1c', u'system_id': u'b7kawf', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/12/'}, {u'discovered': None, u'name': u'ens2f0', u'links': [{u'id': 20, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'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'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:12:48', u'system_id': u'b7kawf', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/13/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/', u'available_size': 0, u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'947d0607-4266-4cff-a3e3-83ab2b2511bd', u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b7kawf', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'0d4bcdcc-d224-42b2-a66e-1cb1c9775ab6', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 1, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'b7kawf', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'id': 1, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'boot_interface': {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 17, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'system_id': u'b7kawf', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/b7kawf/interfaces/4/'}, u'current_commissioning_result_id': 2, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/b7kawf/'}
2019-04-18 09:41:58,735 [salt.state       :300 ][INFO    ][7376] {'new': {'storage_layout': 'lvm'}}
2019-04-18 09:41:58,735 [salt.state       :1951][INFO    ][7376] Completed state [maas_machines_storage_cmp002_lvm] at time 09:41:58.735894 duration_in_ms=2317.94
2019-04-18 09:41:58,736 [salt.state       :1780][INFO    ][7376] Running state [maas_machines_storage_cmp001_lvm] at time 09:41:58.736257
2019-04-18 09:41:58,736 [salt.state       :1813][INFO    ][7376] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-18 09:41:59,705 [salt.loaded.ext.module.maasng:610 ][INFO    ][7376] hqd87d
2019-04-18 09:41:59,706 [salt.loaded.ext.module.maasng:626 ][INFO    ][7376] sda
2019-04-18 09:42:00,346 [salt.loaded.ext.module.maasng:361 ][INFO    ][7376] hqd87d
2019-04-18 09:42:00,419 [salt.loaded.ext.module.maasng:367 ][INFO    ][7376] [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/', u'type': u'physical', u'tags': [u'ssd'], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'system_id': u'hqd87d', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 2, u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'uuid': u'242274ba-04d8-4553-8b8e-eb93dc364d52', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hqd87d', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'051eb416-667c-4d5d-bdf1-8e7bc3684acc', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/partition/2', u'type': u'partition', u'id': 2, u'size': 800101236736}], u'used_size': 800106479616, u'model': u'LOGICAL VOLUME', u'size': 800109715456}, {u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/4/', u'type': u'virtual', u'tags': [], u'uuid': u'1dbffb1e-e1cd-4b07-a976-ebefa5948e2c', u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'hqd87d', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'af4056ad-beb0-49f7-af90-f183a4c9ffb6', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id': 4, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'used_size': 800097042432, u'model': None, u'size': 800097042432}]
2019-04-18 09:42:00,419 [salt.loaded.ext.module.maasng:632 ][INFO    ][7376] vgroot
2019-04-18 09:42:00,420 [salt.loaded.ext.module.maasng:635 ][INFO    ][7376] lvroot
2019-04-18 09:42:00,420 [salt.loaded.ext.module.maasng:639 ][INFO    ][7376] 107374182400
2019-04-18 09:42:00,901 [salt.loaded.ext.module.maasng:645 ][INFO    ][7376] {u'hwe_kernel': u'', u'status_action': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, 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': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 23, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/5/'}, u'min_hwe_kernel': u'ga-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'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'hqd87d', u'block_size': 4096, u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'size': 800109715456, u'used_size': 800106479616, u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'size': 800101236736, u'uuid': u'56d01d2d-64fc-4dae-b5c8-de37c50b8828', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hqd87d', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'b698781f-9b88-496b-887d-b77468ee87b4', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'device_id': 2}]}, u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/hqd87d/', u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'hqd87d', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.39', u'192.168.11.41'], u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'system_id': u'hqd87d', u'block_size': 4096, u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id': 2, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'used_size': 800106479616, u'model': u'LOGICAL VOLUME', u'partitions': [{u'size': 800101236736, u'uuid': u'56d01d2d-64fc-4dae-b5c8-de37c50b8828', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hqd87d', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'b698781f-9b88-496b-887d-b77468ee87b4', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'device_id': 2}]}, {u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/12/', u'uuid': u'5e44ea1c-6294-4dd5-bd52-2042afae2212', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'7faef4ca-2dfa-4fa0-89bf-5c1ae52f6591', u'fstype': u'ext4', u'mount_options': None}, u'used_for': u'ext4 formatted filesystem mounted at /', u'id_path': None, u'system_id': u'hqd87d', u'block_size': 4096, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id': 12, u'available_size': 0, u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'model': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 40, u'power_state': u'off', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/', u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'filesystem': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'hqd87d', u'block_size': 4096, u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'size': 800109715456, u'used_size': 800106479616, u'id': 2, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'size': 800101236736, u'uuid': u'56d01d2d-64fc-4dae-b5c8-de37c50b8828', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hqd87d', u'filesystem': {u'label': None, u'mount_point': None, u'uuid': u'b698781f-9b88-496b-887d-b77468ee87b4', u'fstype': u'lvm-pv', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'device_id': 2}]}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'hqd87d', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, 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': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 23, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/5/'}, {u'vlan': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'38:ea:a7:8f:1f:d4', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/18/'}, {u'vlan': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'38:ea:a7:8f:1f:d5', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/20/'}, {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, 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': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 24, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'parents': [], u'mac_address': u'9c:b6:54:8a:95:a4', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/16/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f1', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'38:ea:a7:8f:52:cd', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/17/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f0', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [u'sriov'], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'mac_address': u'38:ea:a7:8f:52:cc', u'params': u'', u'system_id': u'hqd87d', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/interfaces/19/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/hqd87d/blockdevices/12/', u'uuid': u'5e44ea1c-6294-4dd5-bd52-2042afae2212', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'label': u'root', u'mount_point': u'/', u'uuid': u'7faef4ca-2dfa-4fa0-89bf-5c1ae52f6591', u'fstype': u'ext4', u'mount_options': None}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hqd87d', u'block_size': 4096, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'id': 12, u'serial': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-04-18 09:42:00,904 [salt.state       :300 ][INFO    ][7376] {'new': {'storage_layout': 'lvm'}}
2019-04-18 09:42:00,904 [salt.state       :1951][INFO    ][7376] Completed state [maas_machines_storage_cmp001_lvm] at time 09:42:00.904339 duration_in_ms=2168.082
2019-04-18 09:42:00,906 [salt.minion      :1711][INFO    ][7376] Returning information for job: 20190418094146313447
2019-04-18 09:42:01,422 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418094201411242
2019-04-18 09:42:01,436 [salt.minion      :1432][INFO    ][7443] Starting a new job with PID 7443
2019-04-18 09:42:02,604 [salt.state       :915 ][INFO    ][7443] Loading fresh modules for state activity
2019-04-18 09:42:02,666 [salt.fileclient  :1219][INFO    ][7443] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-04-18 09:42:02,714 [salt.state       :1780][INFO    ][7443] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:42:02.714229
2019-04-18 09:42:02,714 [salt.state       :1813][INFO    ][7443] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 09:42:02,716 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7443] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 09:42:04,554 [salt.state       :300 ][INFO    ][7443] {'pid': 7451, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 09:42:04,555 [salt.state       :1951][INFO    ][7443] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:42:04.555677 duration_in_ms=1841.447
2019-04-18 09:42:04,558 [salt.state       :1780][INFO    ][7443] Running state [maas.deploy_machines] at time 09:42:04.558739
2019-04-18 09:42:04,559 [salt.state       :1813][INFO    ][7443] Executing state module.run for [maas.deploy_machines]
2019-04-18 09:42:04,560 [salt.utils.decorators:613 ][WARNING ][7443] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:42:05,142 [salt.loaded.ext.module.maas:684 ][INFO    ][7443] deploymachines hwe_kernel=ga-16.04 system_id=b7kawf distro_series=xenial
2019-04-18 09:42:07,604 [salt.loaded.ext.module.maas:684 ][INFO    ][7443] deploymachines hwe_kernel=ga-16.04 system_id=hqd87d distro_series=xenial
2019-04-18 09:42:09,959 [salt.loaded.ext.module.maas:684 ][INFO    ][7443] deploymachines hwe_kernel=ga-16.04 system_id=rmt3p3 distro_series=xenial
2019-04-18 09:42:12,368 [salt.loaded.ext.module.maas:684 ][INFO    ][7443] deploymachines hwe_kernel=ga-16.04 system_id=66wwpb distro_series=xenial
2019-04-18 09:42:14,736 [salt.loaded.ext.module.maas:684 ][INFO    ][7443] deploymachines hwe_kernel=ga-16.04 system_id=e3h8xt distro_series=xenial
2019-04-18 09:42:16,521 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094216513000
2019-04-18 09:42:16,538 [salt.minion      :1432][INFO    ][7766] Starting a new job with PID 7766
2019-04-18 09:42:16,561 [salt.minion      :1711][INFO    ][7766] Returning information for job: 20190418094216513000
2019-04-18 09:42:17,143 [salt.state       :300 ][INFO    ][7443] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-04-18 09:42:17,144 [salt.state       :1951][INFO    ][7443] Completed state [maas.deploy_machines] at time 09:42:17.144237 duration_in_ms=12585.498
2019-04-18 09:42:17,146 [salt.minion      :1711][INFO    ][7443] Returning information for job: 20190418094201411242
2019-04-18 09:42:17,706 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418094217692645
2019-04-18 09:42:17,725 [salt.minion      :1432][INFO    ][7784] Starting a new job with PID 7784
2019-04-18 09:42:25,840 [salt.state       :915 ][INFO    ][7784] Loading fresh modules for state activity
2019-04-18 09:42:25,894 [salt.fileclient  :1219][INFO    ][7784] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-04-18 09:42:25,938 [salt.state       :1780][INFO    ][7784] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:42:25.938284
2019-04-18 09:42:25,938 [salt.state       :1813][INFO    ][7784] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 09:42:25,940 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7784] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 09:42:27,667 [salt.state       :300 ][INFO    ][7784] {'pid': 7810, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 09:42:27,668 [salt.state       :1951][INFO    ][7784] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:42:27.668100 duration_in_ms=1729.817
2019-04-18 09:42:27,670 [salt.state       :1780][INFO    ][7784] Running state [maas.wait_for_machine_status] at time 09:42:27.669963
2019-04-18 09:42:27,670 [salt.state       :1813][INFO    ][7784] Executing state module.run for [maas.wait_for_machine_status]
2019-04-18 09:42:27,670 [salt.utils.decorators:613 ][WARNING ][7784] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 09:42:30,402 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.27822423s left)
2019-04-18 09:42:32,808 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094232798650
2019-04-18 09:42:32,829 [salt.minion      :1432][INFO    ][7829] Starting a new job with PID 7829
2019-04-18 09:42:32,851 [salt.minion      :1711][INFO    ][7829] Returning information for job: 20190418094232798650
2019-04-18 09:43:03,001 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094302993809
2019-04-18 09:43:03,017 [salt.minion      :1432][INFO    ][7881] Starting a new job with PID 7881
2019-04-18 09:43:03,041 [salt.minion      :1711][INFO    ][7881] Returning information for job: 20190418094302993809
2019-04-18 09:43:03,098 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.58256721s left)
2019-04-18 09:43:33,032 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094333016519
2019-04-18 09:43:33,054 [salt.minion      :1432][INFO    ][7923] Starting a new job with PID 7923
2019-04-18 09:43:33,083 [salt.minion      :1711][INFO    ][7923] Returning information for job: 20190418094333016519
2019-04-18 09:43:35,900 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2181.78000212s left)
2019-04-18 09:44:03,115 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094403106740
2019-04-18 09:44:03,138 [salt.minion      :1432][INFO    ][7978] Starting a new job with PID 7978
2019-04-18 09:44:03,165 [salt.minion      :1711][INFO    ][7978] Returning information for job: 20190418094403106740
2019-04-18 09:44:08,849 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2148.83150411s left)
2019-04-18 09:44:33,184 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094433169655
2019-04-18 09:44:33,202 [salt.minion      :1432][INFO    ][8028] Starting a new job with PID 8028
2019-04-18 09:44:33,223 [salt.minion      :1711][INFO    ][8028] Returning information for job: 20190418094433169655
2019-04-18 09:44:41,543 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2116.13732219s left)
2019-04-18 09:45:03,246 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094503229614
2019-04-18 09:45:03,263 [salt.minion      :1432][INFO    ][8105] Starting a new job with PID 8105
2019-04-18 09:45:03,287 [salt.minion      :1711][INFO    ][8105] Returning information for job: 20190418094503229614
2019-04-18 09:45:14,390 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2083.2907052s left)
2019-04-18 09:45:33,330 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094533313266
2019-04-18 09:45:33,353 [salt.minion      :1432][INFO    ][8213] Starting a new job with PID 8213
2019-04-18 09:45:33,374 [salt.minion      :1711][INFO    ][8213] Returning information for job: 20190418094533313266
2019-04-18 09:45:47,225 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2050.45488501s left)
2019-04-18 09:46:03,414 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094603404319
2019-04-18 09:46:03,431 [salt.minion      :1432][INFO    ][8314] Starting a new job with PID 8314
2019-04-18 09:46:03,456 [salt.minion      :1711][INFO    ][8314] Returning information for job: 20190418094603404319
2019-04-18 09:46:20,016 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2017.66440916s left)
2019-04-18 09:46:33,491 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094633484281
2019-04-18 09:46:33,504 [salt.minion      :1432][INFO    ][8653] Starting a new job with PID 8653
2019-04-18 09:46:33,524 [salt.minion      :1711][INFO    ][8653] Returning information for job: 20190418094633484281
2019-04-18 09:46:52,969 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1984.71107912s left)
2019-04-18 09:47:03,693 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094703674671
2019-04-18 09:47:03,720 [salt.minion      :1432][INFO    ][8808] Starting a new job with PID 8808
2019-04-18 09:47:03,754 [salt.minion      :1711][INFO    ][8808] Returning information for job: 20190418094703674671
2019-04-18 09:47:25,690 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1951.99053121s left)
2019-04-18 09:47:33,729 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094733721715
2019-04-18 09:47:33,744 [salt.minion      :1432][INFO    ][9041] Starting a new job with PID 9041
2019-04-18 09:47:33,769 [salt.minion      :1711][INFO    ][9041] Returning information for job: 20190418094733721715
2019-04-18 09:47:58,549 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1919.13155603s left)
2019-04-18 09:48:03,851 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094803836681
2019-04-18 09:48:03,877 [salt.minion      :1432][INFO    ][9155] Starting a new job with PID 9155
2019-04-18 09:48:03,910 [salt.minion      :1711][INFO    ][9155] Returning information for job: 20190418094803836681
2019-04-18 09:48:31,346 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1886.33453608s left)
2019-04-18 09:48:33,997 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094833989468
2019-04-18 09:48:34,009 [salt.minion      :1432][INFO    ][9480] Starting a new job with PID 9480
2019-04-18 09:48:34,032 [salt.minion      :1711][INFO    ][9480] Returning information for job: 20190418094833989468
2019-04-18 09:49:04,118 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094904105103
2019-04-18 09:49:04,142 [salt.minion      :1432][INFO    ][9616] Starting a new job with PID 9616
2019-04-18 09:49:04,175 [salt.minion      :1711][INFO    ][9616] Returning information for job: 20190418094904105103
2019-04-18 09:49:04,742 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1852.93814707s left)
2019-04-18 09:49:34,293 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418094934284312
2019-04-18 09:49:34,317 [salt.minion      :1432][INFO    ][9900] Starting a new job with PID 9900
2019-04-18 09:49:34,345 [salt.minion      :1711][INFO    ][9900] Returning information for job: 20190418094934284312
2019-04-18 09:49:37,454 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1820.22620821s left)
2019-04-18 09:50:04,435 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095004417844
2019-04-18 09:50:04,460 [salt.minion      :1432][INFO    ][10054] Starting a new job with PID 10054
2019-04-18 09:50:04,485 [salt.minion      :1711][INFO    ][10054] Returning information for job: 20190418095004417844
2019-04-18 09:50:10,136 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1787.54452705s left)
2019-04-18 09:50:34,579 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095034571144
2019-04-18 09:50:34,595 [salt.minion      :1432][INFO    ][10164] Starting a new job with PID 10164
2019-04-18 09:50:34,618 [salt.minion      :1711][INFO    ][10164] Returning information for job: 20190418095034571144
2019-04-18 09:50:42,668 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1755.012012s left)
2019-04-18 09:51:04,632 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095104624844
2019-04-18 09:51:04,654 [salt.minion      :1432][INFO    ][10324] Starting a new job with PID 10324
2019-04-18 09:51:04,679 [salt.minion      :1711][INFO    ][10324] Returning information for job: 20190418095104624844
2019-04-18 09:51:15,534 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1722.14648008s left)
2019-04-18 09:51:34,696 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095134686385
2019-04-18 09:51:34,710 [salt.minion      :1432][INFO    ][10418] Starting a new job with PID 10418
2019-04-18 09:51:34,728 [salt.minion      :1711][INFO    ][10418] Returning information for job: 20190418095134686385
2019-04-18 09:51:48,230 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1689.45035315s left)
2019-04-18 09:52:04,734 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095204724226
2019-04-18 09:52:04,752 [salt.minion      :1432][INFO    ][10689] Starting a new job with PID 10689
2019-04-18 09:52:04,777 [salt.minion      :1711][INFO    ][10689] Returning information for job: 20190418095204724226
2019-04-18 09:52:20,976 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1656.7041111s left)
2019-04-18 09:52:34,941 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095234933091
2019-04-18 09:52:34,964 [salt.minion      :1432][INFO    ][10802] Starting a new job with PID 10802
2019-04-18 09:52:34,986 [salt.minion      :1711][INFO    ][10802] Returning information for job: 20190418095234933091
2019-04-18 09:52:53,659 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1624.0210011s left)
2019-04-18 09:53:05,102 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095305090316
2019-04-18 09:53:05,120 [salt.minion      :1432][INFO    ][10930] Starting a new job with PID 10930
2019-04-18 09:53:05,143 [salt.minion      :1711][INFO    ][10930] Returning information for job: 20190418095305090316
2019-04-18 09:53:26,556 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1591.12399101s left)
2019-04-18 09:53:35,273 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095335260869
2019-04-18 09:53:35,296 [salt.minion      :1432][INFO    ][11001] Starting a new job with PID 11001
2019-04-18 09:53:35,316 [salt.minion      :1711][INFO    ][11001] Returning information for job: 20190418095335260869
2019-04-18 09:53:59,242 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1558.4384222s left)
2019-04-18 09:54:05,313 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095405298330
2019-04-18 09:54:05,337 [salt.minion      :1432][INFO    ][11067] Starting a new job with PID 11067
2019-04-18 09:54:05,359 [salt.minion      :1711][INFO    ][11067] Returning information for job: 20190418095405298330
2019-04-18 09:54:31,980 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1525.70027018s left)
2019-04-18 09:54:35,366 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095435353541
2019-04-18 09:54:35,390 [salt.minion      :1432][INFO    ][11125] Starting a new job with PID 11125
2019-04-18 09:54:35,416 [salt.minion      :1711][INFO    ][11125] Returning information for job: 20190418095435353541
2019-04-18 09:55:05,378 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095505370506
2019-04-18 09:55:05,398 [salt.minion      :1432][INFO    ][11375] Starting a new job with PID 11375
2019-04-18 09:55:05,420 [salt.minion      :1711][INFO    ][11375] Returning information for job: 20190418095505370506
2019-04-18 09:55:05,458 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1492.22253823s left)
2019-04-18 09:55:35,569 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095535561060
2019-04-18 09:55:35,589 [salt.minion      :1432][INFO    ][11452] Starting a new job with PID 11452
2019-04-18 09:55:35,613 [salt.minion      :1711][INFO    ][11452] Returning information for job: 20190418095535561060
2019-04-18 09:55:38,267 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1459.41339517s left)
2019-04-18 09:56:05,778 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095605765809
2019-04-18 09:56:05,801 [salt.minion      :1432][INFO    ][11584] Starting a new job with PID 11584
2019-04-18 09:56:05,824 [salt.minion      :1711][INFO    ][11584] Returning information for job: 20190418095605765809
2019-04-18 09:56:10,854 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1426.82643604s left)
2019-04-18 09:56:35,976 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095635963353
2019-04-18 09:56:35,996 [salt.minion      :1432][INFO    ][11620] Starting a new job with PID 11620
2019-04-18 09:56:36,020 [salt.minion      :1711][INFO    ][11620] Returning information for job: 20190418095635963353
2019-04-18 09:56:43,681 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1393.99937201s left)
2019-04-18 09:57:06,205 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095706190784
2019-04-18 09:57:06,226 [salt.minion      :1432][INFO    ][11686] Starting a new job with PID 11686
2019-04-18 09:57:06,250 [salt.minion      :1711][INFO    ][11686] Returning information for job: 20190418095706190784
2019-04-18 09:57:16,507 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1361.17286205s left)
2019-04-18 09:57:36,427 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095736413929
2019-04-18 09:57:36,453 [salt.minion      :1432][INFO    ][11722] Starting a new job with PID 11722
2019-04-18 09:57:36,476 [salt.minion      :1711][INFO    ][11722] Returning information for job: 20190418095736413929
2019-04-18 09:57:49,138 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1328.54252005s left)
2019-04-18 09:58:06,456 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095806441140
2019-04-18 09:58:06,477 [salt.minion      :1432][INFO    ][11788] Starting a new job with PID 11788
2019-04-18 09:58:06,499 [salt.minion      :1711][INFO    ][11788] Returning information for job: 20190418095806441140
2019-04-18 09:58:21,813 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1295.86774707s left)
2019-04-18 09:58:36,661 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095836650054
2019-04-18 09:58:36,677 [salt.minion      :1432][INFO    ][11825] Starting a new job with PID 11825
2019-04-18 09:58:36,701 [salt.minion      :1711][INFO    ][11825] Returning information for job: 20190418095836650054
2019-04-18 09:58:54,564 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1263.1163702s left)
2019-04-18 09:59:06,728 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095906716539
2019-04-18 09:59:06,751 [salt.minion      :1432][INFO    ][11900] Starting a new job with PID 11900
2019-04-18 09:59:06,773 [salt.minion      :1711][INFO    ][11900] Returning information for job: 20190418095906716539
2019-04-18 09:59:27,331 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1230.34889007s left)
2019-04-18 09:59:36,885 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418095936873830
2019-04-18 09:59:36,907 [salt.minion      :1432][INFO    ][11939] Starting a new job with PID 11939
2019-04-18 09:59:36,929 [salt.minion      :1711][INFO    ][11939] Returning information for job: 20190418095936873830
2019-04-18 10:00:00,026 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1197.65448117s left)
2019-04-18 10:00:07,002 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100006986659
2019-04-18 10:00:07,025 [salt.minion      :1432][INFO    ][12006] Starting a new job with PID 12006
2019-04-18 10:00:07,048 [salt.minion      :1711][INFO    ][12006] Returning information for job: 20190418100006986659
2019-04-18 10:00:32,653 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1165.0276401s left)
2019-04-18 10:00:37,077 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100037070259
2019-04-18 10:00:37,091 [salt.minion      :1432][INFO    ][12043] Starting a new job with PID 12043
2019-04-18 10:00:37,112 [salt.minion      :1711][INFO    ][12043] Returning information for job: 20190418100037070259
2019-04-18 10:01:05,682 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1131.99828601s left)
2019-04-18 10:01:07,193 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100107177808
2019-04-18 10:01:07,217 [salt.minion      :1432][INFO    ][12110] Starting a new job with PID 12110
2019-04-18 10:01:07,241 [salt.minion      :1711][INFO    ][12110] Returning information for job: 20190418100107177808
2019-04-18 10:01:37,324 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100137315380
2019-04-18 10:01:37,344 [salt.minion      :1432][INFO    ][12146] Starting a new job with PID 12146
2019-04-18 10:01:37,369 [salt.minion      :1711][INFO    ][12146] Returning information for job: 20190418100137315380
2019-04-18 10:01:38,402 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1099.27811408s left)
2019-04-18 10:02:07,450 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100207441165
2019-04-18 10:02:07,470 [salt.minion      :1432][INFO    ][12222] Starting a new job with PID 12222
2019-04-18 10:02:07,494 [salt.minion      :1711][INFO    ][12222] Returning information for job: 20190418100207441165
2019-04-18 10:02:11,222 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1066.45877409s left)
2019-04-18 10:02:37,622 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100237608041
2019-04-18 10:02:37,641 [salt.minion      :1432][INFO    ][12268] Starting a new job with PID 12268
2019-04-18 10:02:37,666 [salt.minion      :1711][INFO    ][12268] Returning information for job: 20190418100237608041
2019-04-18 10:02:43,778 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1033.90217018s left)
2019-04-18 10:03:07,750 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100307742006
2019-04-18 10:03:07,772 [salt.minion      :1432][INFO    ][12334] Starting a new job with PID 12334
2019-04-18 10:03:07,795 [salt.minion      :1711][INFO    ][12334] Returning information for job: 20190418100307742006
2019-04-18 10:03:16,512 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1001.16872215s left)
2019-04-18 10:03:37,879 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100337867379
2019-04-18 10:03:37,902 [salt.minion      :1432][INFO    ][12373] Starting a new job with PID 12373
2019-04-18 10:03:37,928 [salt.minion      :1711][INFO    ][12373] Returning information for job: 20190418100337867379
2019-04-18 10:03:49,041 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (968.638852119s left)
2019-04-18 10:04:08,030 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100408023651
2019-04-18 10:04:08,049 [salt.minion      :1432][INFO    ][12441] Starting a new job with PID 12441
2019-04-18 10:04:08,078 [salt.minion      :1711][INFO    ][12441] Returning information for job: 20190418100408023651
2019-04-18 10:04:21,848 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (935.832714081s left)
2019-04-18 10:04:38,231 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100438224637
2019-04-18 10:04:38,245 [salt.minion      :1432][INFO    ][12478] Starting a new job with PID 12478
2019-04-18 10:04:38,268 [salt.minion      :1711][INFO    ][12478] Returning information for job: 20190418100438224637
2019-04-18 10:04:54,665 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (903.015157223s left)
2019-04-18 10:05:08,428 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100508413830
2019-04-18 10:05:08,450 [salt.minion      :1432][INFO    ][12548] Starting a new job with PID 12548
2019-04-18 10:05:08,473 [salt.minion      :1711][INFO    ][12548] Returning information for job: 20190418100508413830
2019-04-18 10:05:27,282 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (870.398424149s left)
2019-04-18 10:05:38,460 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100538444126
2019-04-18 10:05:38,482 [salt.minion      :1432][INFO    ][12584] Starting a new job with PID 12584
2019-04-18 10:05:38,508 [salt.minion      :1711][INFO    ][12584] Returning information for job: 20190418100538444126
2019-04-18 10:06:00,021 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (837.659650087s left)
2019-04-18 10:06:08,474 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100608467580
2019-04-18 10:06:08,495 [salt.minion      :1432][INFO    ][12652] Starting a new job with PID 12652
2019-04-18 10:06:08,518 [salt.minion      :1711][INFO    ][12652] Returning information for job: 20190418100608467580
2019-04-18 10:06:32,736 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (804.943946123s left)
2019-04-18 10:06:38,538 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100638524161
2019-04-18 10:06:38,557 [salt.minion      :1432][INFO    ][12688] Starting a new job with PID 12688
2019-04-18 10:06:38,583 [salt.minion      :1711][INFO    ][12688] Returning information for job: 20190418100638524161
2019-04-18 10:07:05,606 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (772.074757099s left)
2019-04-18 10:07:08,587 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100708579107
2019-04-18 10:07:08,600 [salt.minion      :1432][INFO    ][12755] Starting a new job with PID 12755
2019-04-18 10:07:08,622 [salt.minion      :1711][INFO    ][12755] Returning information for job: 20190418100708579107
2019-04-18 10:07:38,472 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (739.207872152s left)
2019-04-18 10:07:38,650 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100738637526
2019-04-18 10:07:38,671 [salt.minion      :1432][INFO    ][12793] Starting a new job with PID 12793
2019-04-18 10:07:38,694 [salt.minion      :1711][INFO    ][12793] Returning information for job: 20190418100738637526
2019-04-18 10:08:08,780 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100808771455
2019-04-18 10:08:08,796 [salt.minion      :1432][INFO    ][12858] Starting a new job with PID 12858
2019-04-18 10:08:08,819 [salt.minion      :1711][INFO    ][12858] Returning information for job: 20190418100808771455
2019-04-18 10:08:11,207 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (706.472858191s left)
2019-04-18 10:08:38,874 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100838862229
2019-04-18 10:08:38,893 [salt.minion      :1432][INFO    ][12893] Starting a new job with PID 12893
2019-04-18 10:08:38,917 [salt.minion      :1711][INFO    ][12893] Returning information for job: 20190418100838862229
2019-04-18 10:08:43,942 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (673.738608122s left)
2019-04-18 10:09:09,005 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100908997877
2019-04-18 10:09:09,023 [salt.minion      :1432][INFO    ][12960] Starting a new job with PID 12960
2019-04-18 10:09:09,048 [salt.minion      :1711][INFO    ][12960] Returning information for job: 20190418100908997877
2019-04-18 10:09:16,645 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (641.035089016s left)
2019-04-18 10:09:39,133 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418100939118565
2019-04-18 10:09:39,152 [salt.minion      :1432][INFO    ][12998] Starting a new job with PID 12998
2019-04-18 10:09:39,179 [salt.minion      :1711][INFO    ][12998] Returning information for job: 20190418100939118565
2019-04-18 10:09:49,329 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (608.351553202s left)
2019-04-18 10:10:09,331 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101009317916
2019-04-18 10:10:09,353 [salt.minion      :1432][INFO    ][13066] Starting a new job with PID 13066
2019-04-18 10:10:09,372 [salt.minion      :1711][INFO    ][13066] Returning information for job: 20190418101009317916
2019-04-18 10:10:22,205 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (575.474868059s left)
2019-04-18 10:10:39,481 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101039471892
2019-04-18 10:10:39,502 [salt.minion      :1432][INFO    ][13102] Starting a new job with PID 13102
2019-04-18 10:10:39,525 [salt.minion      :1711][INFO    ][13102] Returning information for job: 20190418101039471892
2019-04-18 10:10:54,883 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (542.797727108s left)
2019-04-18 10:11:09,514 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101109506205
2019-04-18 10:11:09,532 [salt.minion      :1432][INFO    ][13172] Starting a new job with PID 13172
2019-04-18 10:11:09,554 [salt.minion      :1711][INFO    ][13172] Returning information for job: 20190418101109506205
2019-04-18 10:11:27,589 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (510.091078043s left)
2019-04-18 10:11:39,691 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101139678602
2019-04-18 10:11:39,713 [salt.minion      :1432][INFO    ][13208] Starting a new job with PID 13208
2019-04-18 10:11:39,734 [salt.minion      :1711][INFO    ][13208] Returning information for job: 20190418101139678602
2019-04-18 10:12:00,353 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (477.326982021s left)
2019-04-18 10:12:09,761 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101209745568
2019-04-18 10:12:09,779 [salt.minion      :1432][INFO    ][13419] Starting a new job with PID 13419
2019-04-18 10:12:09,800 [salt.minion      :1711][INFO    ][13419] Returning information for job: 20190418101209745568
2019-04-18 10:12:33,013 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (444.66684413s left)
2019-04-18 10:12:39,973 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101239965545
2019-04-18 10:12:39,994 [salt.minion      :1432][INFO    ][13463] Starting a new job with PID 13463
2019-04-18 10:12:40,017 [salt.minion      :1711][INFO    ][13463] Returning information for job: 20190418101239965545
2019-04-18 10:13:05,733 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (411.946985006s left)
2019-04-18 10:13:10,113 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101310104474
2019-04-18 10:13:10,139 [salt.minion      :1432][INFO    ][13528] Starting a new job with PID 13528
2019-04-18 10:13:10,169 [salt.minion      :1711][INFO    ][13528] Returning information for job: 20190418101310104474
2019-04-18 10:13:38,488 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (379.192414045s left)
2019-04-18 10:13:40,270 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101340258434
2019-04-18 10:13:40,293 [salt.minion      :1432][INFO    ][13564] Starting a new job with PID 13564
2019-04-18 10:13:40,318 [salt.minion      :1711][INFO    ][13564] Returning information for job: 20190418101340258434
2019-04-18 10:14:10,399 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101410385506
2019-04-18 10:14:10,421 [salt.minion      :1432][INFO    ][13631] Starting a new job with PID 13631
2019-04-18 10:14:10,446 [salt.minion      :1711][INFO    ][13631] Returning information for job: 20190418101410385506
2019-04-18 10:14:11,233 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (346.447709084s left)
2019-04-18 10:14:40,593 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101440578766
2019-04-18 10:14:40,615 [salt.minion      :1432][INFO    ][13667] Starting a new job with PID 13667
2019-04-18 10:14:40,640 [salt.minion      :1711][INFO    ][13667] Returning information for job: 20190418101440578766
2019-04-18 10:14:43,864 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (313.816110134s left)
2019-04-18 10:15:10,701 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101510685465
2019-04-18 10:15:10,723 [salt.minion      :1432][INFO    ][13732] Starting a new job with PID 13732
2019-04-18 10:15:10,746 [salt.minion      :1711][INFO    ][13732] Returning information for job: 20190418101510685465
2019-04-18 10:15:16,583 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (281.096970081s left)
2019-04-18 10:15:40,929 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101540918224
2019-04-18 10:15:40,951 [salt.minion      :1432][INFO    ][13768] Starting a new job with PID 13768
2019-04-18 10:15:40,980 [salt.minion      :1711][INFO    ][13768] Returning information for job: 20190418101540918224
2019-04-18 10:15:49,410 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (248.270545006s left)
2019-04-18 10:16:11,059 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101611050392
2019-04-18 10:16:11,075 [salt.minion      :1432][INFO    ][13836] Starting a new job with PID 13836
2019-04-18 10:16:11,099 [salt.minion      :1711][INFO    ][13836] Returning information for job: 20190418101611050392
2019-04-18 10:16:22,317 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (215.363365173s left)
2019-04-18 10:16:41,085 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101641072155
2019-04-18 10:16:41,108 [salt.minion      :1432][INFO    ][13874] Starting a new job with PID 13874
2019-04-18 10:16:41,132 [salt.minion      :1711][INFO    ][13874] Returning information for job: 20190418101641072155
2019-04-18 10:16:55,063 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (182.61770916s left)
2019-04-18 10:17:11,300 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101711287039
2019-04-18 10:17:11,322 [salt.minion      :1432][INFO    ][13946] Starting a new job with PID 13946
2019-04-18 10:17:11,341 [salt.minion      :1711][INFO    ][13946] Returning information for job: 20190418101711287039
2019-04-18 10:17:27,779 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (149.901402235s left)
2019-04-18 10:17:41,371 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101741362025
2019-04-18 10:17:41,394 [salt.minion      :1432][INFO    ][13982] Starting a new job with PID 13982
2019-04-18 10:17:41,416 [salt.minion      :1711][INFO    ][13982] Returning information for job: 20190418101741362025
2019-04-18 10:18:00,450 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (117.23032403s left)
2019-04-18 10:18:11,597 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101811581188
2019-04-18 10:18:11,616 [salt.minion      :1432][INFO    ][14049] Starting a new job with PID 14049
2019-04-18 10:18:11,639 [salt.minion      :1711][INFO    ][14049] Returning information for job: 20190418101811581188
2019-04-18 10:18:33,293 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (84.3869850636s left)
2019-04-18 10:18:41,698 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101841690424
2019-04-18 10:18:41,717 [salt.minion      :1432][INFO    ][14085] Starting a new job with PID 14085
2019-04-18 10:18:41,741 [salt.minion      :1711][INFO    ][14085] Returning information for job: 20190418101841690424
2019-04-18 10:19:06,232 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (51.4479711056s left)
2019-04-18 10:19:11,761 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101911752183
2019-04-18 10:19:11,779 [salt.minion      :1432][INFO    ][14157] Starting a new job with PID 14157
2019-04-18 10:19:11,805 [salt.minion      :1711][INFO    ][14157] Returning information for job: 20190418101911752183
2019-04-18 10:19:39,036 [salt.loaded.ext.module.maas:1023][INFO    ][7784] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (18.6440131664s left)
2019-04-18 10:19:41,921 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418101941912893
2019-04-18 10:19:41,939 [salt.minion      :1432][INFO    ][14190] Starting a new job with PID 14190
2019-04-18 10:19:41,961 [salt.minion      :1711][INFO    ][14190] Returning information for job: 20190418101941912893
2019-04-18 10:20:11,793 [salt.state       :302 ][ERROR   ][7784] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['kvm02']not in Deployed state
2019-04-18 10:20:11,793 [salt.state       :1951][INFO    ][7784] Completed state [maas.wait_for_machine_status] at time 10:20:11.793502 duration_in_ms=2264123.525
2019-04-18 10:20:11,797 [salt.minion      :1711][INFO    ][7784] Returning information for job: 20190418094217692645
2019-04-18 10:20:22,590 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command pillar.get with jid 20190418102022578177
2019-04-18 10:20:22,607 [salt.minion      :1432][INFO    ][14263] Starting a new job with PID 14263
2019-04-18 10:20:22,616 [salt.minion      :1711][INFO    ][14263] Returning information for job: 20190418102022578177
2019-04-18 10:20:23,153 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command service.status with jid 20190418102023142469
2019-04-18 10:20:23,172 [salt.minion      :1432][INFO    ][14268] Starting a new job with PID 14268
2019-04-18 10:20:23,845 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14268] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:23,881 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][14268] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-04-18 10:20:23,901 [salt.minion      :1711][INFO    ][14268] Returning information for job: 20190418102023142469
2019-04-18 10:20:24,475 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102024462335
2019-04-18 10:20:24,498 [salt.minion      :1432][INFO    ][14286] Starting a new job with PID 14286
2019-04-18 10:20:32,588 [salt.state       :915 ][INFO    ][14286] Loading fresh modules for state activity
2019-04-18 10:20:33,167 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'salt-minion --version' in directory '/root'
2019-04-18 10:20:33,480 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'salt-minion --version' in directory '/root'
2019-04-18 10:20:34,452 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'salt-minion --version' in directory '/root'
2019-04-18 10:20:34,726 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'salt-minion --version' in directory '/root'
2019-04-18 10:20:36,448 [salt.state       :1780][INFO    ][14286] Running state [salt-minion] at time 10:20:36.448524
2019-04-18 10:20:36,448 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [salt-minion]
2019-04-18 10:20:36,449 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-18 10:20:36,563 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:36,564 [salt.state       :1951][INFO    ][14286] Completed state [salt-minion] at time 10:20:36.564019 duration_in_ms=115.496
2019-04-18 10:20:36,564 [salt.state       :1780][INFO    ][14286] Running state [salt_minion_dependency_packages] at time 10:20:36.564345
2019-04-18 10:20:36,564 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-04-18 10:20:36,573 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:36,574 [salt.state       :1951][INFO    ][14286] Completed state [salt_minion_dependency_packages] at time 10:20:36.574018 duration_in_ms=9.673
2019-04-18 10:20:36,576 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/minion.d/minion.conf] at time 10:20:36.576918
2019-04-18 10:20:36,577 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-04-18 10:20:36,851 [salt.state       :300 ][INFO    ][14286] File /etc/salt/minion.d/minion.conf is in the correct state
2019-04-18 10:20:36,852 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/minion.d/minion.conf] at time 10:20:36.852381 duration_in_ms=275.462
2019-04-18 10:20:36,853 [salt.state       :1780][INFO    ][14286] Running state [python-netaddr] at time 10:20:36.852931
2019-04-18 10:20:36,853 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [python-netaddr]
2019-04-18 10:20:36,863 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:36,863 [salt.state       :1951][INFO    ][14286] Completed state [python-netaddr] at time 10:20:36.863572 duration_in_ms=10.642
2019-04-18 10:20:36,866 [salt.state       :1780][INFO    ][14286] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 10:20:36.866571
2019-04-18 10:20:36,867 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-04-18 10:20:36,881 [salt.state       :300 ][INFO    ][14286] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-04-18 10:20:36,881 [salt.state       :1951][INFO    ][14286] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 10:20:36.881766 duration_in_ms=15.194
2019-04-18 10:20:36,884 [salt.state       :1780][INFO    ][14286] Running state [salt-minion] at time 10:20:36.884415
2019-04-18 10:20:36,884 [salt.state       :1813][INFO    ][14286] Executing state service.running for [salt-minion]
2019-04-18 10:20:36,885 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:36,920 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-04-18 10:20:36,936 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-04-18 10:20:36,955 [salt.state       :300 ][INFO    ][14286] The service salt-minion is already running
2019-04-18 10:20:36,956 [salt.state       :1951][INFO    ][14286] Completed state [salt-minion] at time 10:20:36.955954 duration_in_ms=71.538
2019-04-18 10:20:36,959 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains.d] at time 10:20:36.959298
2019-04-18 10:20:36,959 [salt.state       :1813][INFO    ][14286] Executing state file.directory for [/etc/salt/grains.d]
2019-04-18 10:20:36,961 [salt.state       :300 ][INFO    ][14286] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-04-18 10:20:36,962 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains.d] at time 10:20:36.962005 duration_in_ms=2.707
2019-04-18 10:20:36,965 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains] at time 10:20:36.965152
2019-04-18 10:20:36,965 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/grains]
2019-04-18 10:20:36,966 [salt.state       :300 ][INFO    ][14286] File /etc/salt/grains exists with proper permissions. No changes made.
2019-04-18 10:20:36,966 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains] at time 10:20:36.966205 duration_in_ms=1.053
2019-04-18 10:20:36,966 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains.d/placeholder] at time 10:20:36.966713
2019-04-18 10:20:36,967 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-04-18 10:20:36,967 [salt.state       :300 ][INFO    ][14286] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-04-18 10:20:36,968 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains.d/placeholder] at time 10:20:36.968034 duration_in_ms=1.321
2019-04-18 10:20:36,968 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains.d/sphinx] at time 10:20:36.968541
2019-04-18 10:20:36,968 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-04-18 10:20:36,970 [salt.state       :300 ][INFO    ][14286] File /etc/salt/grains.d/sphinx is in the correct state
2019-04-18 10:20:36,970 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains.d/sphinx] at time 10:20:36.970376 duration_in_ms=1.835
2019-04-18 10:20:36,972 [salt.state       :1780][INFO    ][14286] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.972835
2019-04-18 10:20:36,973 [salt.state       :1813][INFO    ][14286] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-04-18 10:20:36,973 [salt.state       :300 ][INFO    ][14286] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-04-18 10:20:36,973 [salt.state       :1951][INFO    ][14286] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.973659 duration_in_ms=0.824
2019-04-18 10:20:36,974 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains.d/dns_records] at time 10:20:36.974483
2019-04-18 10:20:36,974 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-04-18 10:20:36,977 [salt.state       :300 ][INFO    ][14286] File /etc/salt/grains.d/dns_records is in the correct state
2019-04-18 10:20:36,977 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains.d/dns_records] at time 10:20:36.977432 duration_in_ms=2.949
2019-04-18 10:20:36,978 [salt.state       :1780][INFO    ][14286] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.978341
2019-04-18 10:20:36,978 [salt.state       :1813][INFO    ][14286] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-04-18 10:20:36,978 [salt.state       :300 ][INFO    ][14286] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-04-18 10:20:36,979 [salt.state       :1951][INFO    ][14286] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.979112 duration_in_ms=0.771
2019-04-18 10:20:36,979 [salt.state       :1780][INFO    ][14286] Running state [/etc/salt/grains.d/salt] at time 10:20:36.979585
2019-04-18 10:20:36,979 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-04-18 10:20:36,980 [salt.state       :300 ][INFO    ][14286] File /etc/salt/grains.d/salt is in the correct state
2019-04-18 10:20:36,981 [salt.state       :1951][INFO    ][14286] Completed state [/etc/salt/grains.d/salt] at time 10:20:36.981064 duration_in_ms=1.48
2019-04-18 10:20:36,981 [salt.state       :1780][INFO    ][14286] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.981915
2019-04-18 10:20:36,982 [salt.state       :1813][INFO    ][14286] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-04-18 10:20:36,982 [salt.state       :300 ][INFO    ][14286] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-04-18 10:20:36,982 [salt.state       :1951][INFO    ][14286] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 10:20:36.982638 duration_in_ms=0.723
2019-04-18 10:20:36,984 [salt.state       :1780][INFO    ][14286] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 10:20:36.984551
2019-04-18 10:20:36,984 [salt.state       :1813][INFO    ][14286] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-04-18 10:20:36,985 [salt.state       :300 ][INFO    ][14286] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-04-18 10:20:36,985 [salt.state       :1951][INFO    ][14286] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 10:20:36.985315 duration_in_ms=0.764
2019-04-18 10:20:36,986 [salt.state       :1780][INFO    ][14286] Running state [mine.update] at time 10:20:36.985963
2019-04-18 10:20:36,986 [salt.state       :1813][INFO    ][14286] Executing state module.wait for [mine.update]
2019-04-18 10:20:36,986 [salt.state       :300 ][INFO    ][14286] No changes made for mine.update
2019-04-18 10:20:36,986 [salt.state       :1951][INFO    ][14286] Completed state [mine.update] at time 10:20:36.986674 duration_in_ms=0.711
2019-04-18 10:20:36,988 [salt.state       :1780][INFO    ][14286] Running state [ca-certificates] at time 10:20:36.988820
2019-04-18 10:20:36,989 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [ca-certificates]
2019-04-18 10:20:36,997 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:36,997 [salt.state       :1951][INFO    ][14286] Completed state [ca-certificates] at time 10:20:36.997921 duration_in_ms=9.1
2019-04-18 10:20:36,998 [salt.state       :1780][INFO    ][14286] Running state [update-ca-certificates] at time 10:20:36.998601
2019-04-18 10:20:36,999 [salt.state       :1813][INFO    ][14286] Executing state cmd.wait for [update-ca-certificates]
2019-04-18 10:20:37,000 [salt.state       :300 ][INFO    ][14286] No changes made for update-ca-certificates
2019-04-18 10:20:37,000 [salt.state       :1951][INFO    ][14286] Completed state [update-ca-certificates] at time 10:20:37.000735 duration_in_ms=2.135
2019-04-18 10:20:37,001 [salt.state       :1780][INFO    ][14286] Running state [iptables] at time 10:20:37.000967
2019-04-18 10:20:37,001 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [iptables]
2019-04-18 10:20:37,009 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:37,009 [salt.state       :1951][INFO    ][14286] Completed state [iptables] at time 10:20:37.009816 duration_in_ms=8.849
2019-04-18 10:20:37,010 [salt.state       :1780][INFO    ][14286] Running state [iptables-persistent] at time 10:20:37.010049
2019-04-18 10:20:37,010 [salt.state       :1813][INFO    ][14286] Executing state pkg.installed for [iptables-persistent]
2019-04-18 10:20:37,019 [salt.state       :300 ][INFO    ][14286] All specified packages are already installed
2019-04-18 10:20:37,019 [salt.state       :1951][INFO    ][14286] Completed state [iptables-persistent] at time 10:20:37.019849 duration_in_ms=9.8
2019-04-18 10:20:37,020 [salt.state       :1780][INFO    ][14286] Running state [iptables_modules_v4_load] at time 10:20:37.020799
2019-04-18 10:20:37,021 [salt.state       :1813][INFO    ][14286] Executing state kmod.present for [iptables_modules_v4_load]
2019-04-18 10:20:37,021 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'lsmod' in directory '/root'
2019-04-18 10:20:37,039 [salt.state       :300 ][INFO    ][14286] Kernel modules iptable_filter, ip_tables are already present
2019-04-18 10:20:37,040 [salt.state       :1951][INFO    ][14286] Completed state [iptables_modules_v4_load] at time 10:20:37.040176 duration_in_ms=19.376
2019-04-18 10:20:37,041 [salt.state       :1780][INFO    ][14286] Running state [/etc/iptables/rules.v4] at time 10:20:37.041355
2019-04-18 10:20:37,041 [salt.state       :1813][INFO    ][14286] Executing state file.managed for [/etc/iptables/rules.v4]
2019-04-18 10:20:37,139 [salt.state       :300 ][INFO    ][14286] File /etc/iptables/rules.v4 is in the correct state
2019-04-18 10:20:37,139 [salt.state       :1951][INFO    ][14286] Completed state [/etc/iptables/rules.v4] at time 10:20:37.139635 duration_in_ms=98.281
2019-04-18 10:20:37,140 [salt.state       :1780][INFO    ][14286] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 10:20:37.140701
2019-04-18 10:20:37,140 [salt.state       :1813][INFO    ][14286] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-04-18 10:20:37,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-04-18 10:20:37,161 [salt.state       :300 ][INFO    ][14286] onlyif execution failed
2019-04-18 10:20:37,162 [salt.state       :1951][INFO    ][14286] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 10:20:37.162238 duration_in_ms=21.536
2019-04-18 10:20:37,164 [salt.state       :1780][INFO    ][14286] Running state [netfilter-persistent] at time 10:20:37.164331
2019-04-18 10:20:37,164 [salt.state       :1813][INFO    ][14286] Executing state service.running for [netfilter-persistent]
2019-04-18 10:20:37,166 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:37,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-04-18 10:20:37,211 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-04-18 10:20:37,233 [salt.state       :300 ][INFO    ][14286] The service netfilter-persistent is already running
2019-04-18 10:20:37,233 [salt.state       :1951][INFO    ][14286] Completed state [netfilter-persistent] at time 10:20:37.233584 duration_in_ms=69.252
2019-04-18 10:20:37,235 [salt.state       :1780][INFO    ][14286] Running state [iptables_extra.remove_stale_tables] at time 10:20:37.235093
2019-04-18 10:20:37,235 [salt.state       :1813][INFO    ][14286] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-04-18 10:20:37,236 [salt.state       :300 ][INFO    ][14286] No changes made for iptables_extra.remove_stale_tables
2019-04-18 10:20:37,236 [salt.state       :1951][INFO    ][14286] Completed state [iptables_extra.remove_stale_tables] at time 10:20:37.236522 duration_in_ms=1.43
2019-04-18 10:20:37,237 [salt.state       :1780][INFO    ][14286] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 10:20:37.236952
2019-04-18 10:20:37,237 [salt.state       :1813][INFO    ][14286] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-04-18 10:20:37,238 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14286] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-04-18 10:20:37,256 [salt.state       :300 ][INFO    ][14286] onlyif execution failed
2019-04-18 10:20:37,257 [salt.state       :1951][INFO    ][14286] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 10:20:37.256994 duration_in_ms=20.042
2019-04-18 10:20:37,258 [salt.state       :1780][INFO    ][14286] Running state [/etc/iptables/rules.v6] at time 10:20:37.258349
2019-04-18 10:20:37,258 [salt.state       :1813][INFO    ][14286] Executing state file.absent for [/etc/iptables/rules.v6]
2019-04-18 10:20:37,259 [salt.state       :300 ][INFO    ][14286] File /etc/iptables/rules.v6 is not present
2019-04-18 10:20:37,260 [salt.state       :1951][INFO    ][14286] Completed state [/etc/iptables/rules.v6] at time 10:20:37.259996 duration_in_ms=1.647
2019-04-18 10:20:37,261 [salt.state       :1780][INFO    ][14286] Running state [iptables_extra.flush_all] at time 10:20:37.261121
2019-04-18 10:20:37,261 [salt.state       :1813][INFO    ][14286] Executing state module.wait for [iptables_extra.flush_all]
2019-04-18 10:20:37,261 [salt.state       :300 ][INFO    ][14286] No changes made for iptables_extra.flush_all
2019-04-18 10:20:37,262 [salt.state       :1951][INFO    ][14286] Completed state [iptables_extra.flush_all] at time 10:20:37.262138 duration_in_ms=1.016
2019-04-18 10:20:37,268 [salt.minion      :1711][INFO    ][14286] Returning information for job: 20190418102024462335
2019-04-18 10:20:37,822 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102037807756
2019-04-18 10:20:37,843 [salt.minion      :1432][INFO    ][14375] Starting a new job with PID 14375
2019-04-18 10:20:39,032 [salt.state       :915 ][INFO    ][14375] Loading fresh modules for state activity
2019-04-18 10:20:39,886 [salt.state       :1780][INFO    ][14375] Running state [maas-rack-controller] at time 10:20:39.886073
2019-04-18 10:20:39,886 [salt.state       :1813][INFO    ][14375] Executing state pkg.installed for [maas-rack-controller]
2019-04-18 10:20:39,887 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14375] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-18 10:20:39,991 [salt.state       :300 ][INFO    ][14375] All specified packages are already installed
2019-04-18 10:20:39,991 [salt.state       :1951][INFO    ][14375] Completed state [maas-rack-controller] at time 10:20:39.991898 duration_in_ms=105.824
2019-04-18 10:20:39,992 [salt.state       :1780][INFO    ][14375] Running state [ipmitool] at time 10:20:39.992358
2019-04-18 10:20:39,992 [salt.state       :1813][INFO    ][14375] Executing state pkg.installed for [ipmitool]
2019-04-18 10:20:40,002 [salt.state       :300 ][INFO    ][14375] All specified packages are already installed
2019-04-18 10:20:40,002 [salt.state       :1951][INFO    ][14375] Completed state [ipmitool] at time 10:20:40.002882 duration_in_ms=10.524
2019-04-18 10:20:40,007 [salt.state       :1780][INFO    ][14375] Running state [/etc/maas/rackd.conf] at time 10:20:40.007246
2019-04-18 10:20:40,007 [salt.state       :1813][INFO    ][14375] Executing state file.line for [/etc/maas/rackd.conf]
2019-04-18 10:20:40,008 [salt.state       :300 ][INFO    ][14375] No changes needed to be made
2019-04-18 10:20:40,008 [salt.state       :1951][INFO    ][14375] Completed state [/etc/maas/rackd.conf] at time 10:20:40.008673 duration_in_ms=1.427
2019-04-18 10:20:40,008 [salt.state       :1780][INFO    ][14375] Running state [/etc/maas/rackd.conf] at time 10:20:40.008918
2019-04-18 10:20:40,009 [salt.state       :1813][INFO    ][14375] Executing state file.managed for [/etc/maas/rackd.conf]
2019-04-18 10:20:40,009 [salt.loaded.int.states.file:2298][WARNING ][14375] 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-04-18 10:20:40,010 [salt.state       :300 ][INFO    ][14375] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-04-18 10:20:40,010 [salt.state       :1951][INFO    ][14375] Completed state [/etc/maas/rackd.conf] at time 10:20:40.010441 duration_in_ms=1.523
2019-04-18 10:20:40,012 [salt.state       :1780][INFO    ][14375] Running state [maas-rackd] at time 10:20:40.012603
2019-04-18 10:20:40,012 [salt.state       :1813][INFO    ][14375] Executing state service.running for [maas-rackd]
2019-04-18 10:20:40,013 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14375] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:40,048 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14375] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-04-18 10:20:40,064 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14375] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-04-18 10:20:40,081 [salt.state       :300 ][INFO    ][14375] The service maas-rackd is already running
2019-04-18 10:20:40,081 [salt.state       :1951][INFO    ][14375] Completed state [maas-rackd] at time 10:20:40.081754 duration_in_ms=69.151
2019-04-18 10:20:40,086 [salt.minion      :1711][INFO    ][14375] Returning information for job: 20190418102037807756
2019-04-18 10:20:40,637 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102040622543
2019-04-18 10:20:40,654 [salt.minion      :1432][INFO    ][14401] Starting a new job with PID 14401
2019-04-18 10:20:41,809 [salt.state       :915 ][INFO    ][14401] Loading fresh modules for state activity
2019-04-18 10:20:42,814 [salt.state       :1780][INFO    ][14401] Running state [maas-region-controller] at time 10:20:42.814258
2019-04-18 10:20:42,814 [salt.state       :1813][INFO    ][14401] Executing state pkg.installed for [maas-region-controller]
2019-04-18 10:20:42,815 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-04-18 10:20:42,918 [salt.state       :300 ][INFO    ][14401] All specified packages are already installed
2019-04-18 10:20:42,919 [salt.state       :1951][INFO    ][14401] Completed state [maas-region-controller] at time 10:20:42.918959 duration_in_ms=104.701
2019-04-18 10:20:42,919 [salt.state       :1780][INFO    ][14401] Running state [python-oauth] at time 10:20:42.919281
2019-04-18 10:20:42,919 [salt.state       :1813][INFO    ][14401] Executing state pkg.installed for [python-oauth]
2019-04-18 10:20:42,929 [salt.state       :300 ][INFO    ][14401] All specified packages are already installed
2019-04-18 10:20:42,929 [salt.state       :1951][INFO    ][14401] Completed state [python-oauth] at time 10:20:42.929235 duration_in_ms=9.954
2019-04-18 10:20:42,932 [salt.state       :1780][INFO    ][14401] Running state [/etc/maas/regiond.conf] at time 10:20:42.932128
2019-04-18 10:20:42,932 [salt.state       :1813][INFO    ][14401] Executing state file.replace for [/etc/maas/regiond.conf]
2019-04-18 10:20:42,938 [salt.state       :300 ][INFO    ][14401] No changes needed to be made
2019-04-18 10:20:42,940 [salt.state       :1951][INFO    ][14401] Completed state [/etc/maas/regiond.conf] at time 10:20:42.940015 duration_in_ms=7.886
2019-04-18 10:20:42,941 [salt.state       :1780][INFO    ][14401] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 10:20:42.940957
2019-04-18 10:20:42,941 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-04-18 10:20:43,003 [salt.state       :300 ][INFO    ][14401] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-04-18 10:20:43,003 [salt.state       :1951][INFO    ][14401] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 10:20:43.003539 duration_in_ms=62.581
2019-04-18 10:20:43,004 [salt.state       :1780][INFO    ][14401] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:20:43.004018
2019-04-18 10:20:43,004 [salt.state       :1813][INFO    ][14401] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-18 10:20:43,007 [salt.state       :300 ][INFO    ][14401] No changes needed to be made
2019-04-18 10:20:43,007 [salt.state       :1951][INFO    ][14401] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:20:43.007922 duration_in_ms=3.904
2019-04-18 10:20:43,008 [salt.state       :1780][INFO    ][14401] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:20:43.008397
2019-04-18 10:20:43,008 [salt.state       :1813][INFO    ][14401] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-04-18 10:20:43,013 [salt.state       :300 ][INFO    ][14401] No changes needed to be made
2019-04-18 10:20:43,013 [salt.state       :1951][INFO    ][14401] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:20:43.013271 duration_in_ms=4.873
2019-04-18 10:20:43,013 [salt.state       :1780][INFO    ][14401] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 10:20:43.013740
2019-04-18 10:20:43,014 [salt.state       :1813][INFO    ][14401] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-04-18 10:20:43,039 [salt.state       :300 ][INFO    ][14401] No changes needed to be made
2019-04-18 10:20:43,040 [salt.state       :1951][INFO    ][14401] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 10:20:43.039970 duration_in_ms=26.229
2019-04-18 10:20:43,040 [salt.state       :1780][INFO    ][14401] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 10:20:43.040454
2019-04-18 10:20:43,040 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-04-18 10:20:43,052 [salt.state       :300 ][INFO    ][14401] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-04-18 10:20:43,052 [salt.state       :1951][INFO    ][14401] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 10:20:43.052530 duration_in_ms=12.074
2019-04-18 10:20:43,053 [salt.state       :1780][INFO    ][14401] Running state [a2enmod headers] at time 10:20:43.053743
2019-04-18 10:20:43,054 [salt.state       :1813][INFO    ][14401] Executing state cmd.run for [a2enmod headers]
2019-04-18 10:20:43,054 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command 'a2enmod headers' in directory '/root'
2019-04-18 10:20:43,121 [salt.state       :300 ][INFO    ][14401] {'pid': 14420, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-04-18 10:20:43,122 [salt.state       :1951][INFO    ][14401] Completed state [a2enmod headers] at time 10:20:43.121935 duration_in_ms=68.191
2019-04-18 10:20:43,122 [salt.state       :1780][INFO    ][14401] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 10:20:43.122582
2019-04-18 10:20:43,123 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-04-18 10:20:43,140 [salt.state       :300 ][INFO    ][14401] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-04-18 10:20:43,140 [salt.state       :1951][INFO    ][14401] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 10:20:43.140622 duration_in_ms=18.041
2019-04-18 10:20:43,141 [salt.state       :1780][INFO    ][14401] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 10:20:43.141201
2019-04-18 10:20:43,141 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-04-18 10:20:43,197 [salt.state       :300 ][INFO    ][14401] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-04-18 10:20:43,197 [salt.state       :1951][INFO    ][14401] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 10:20:43.197603 duration_in_ms=56.402
2019-04-18 10:20:43,198 [salt.state       :1780][INFO    ][14401] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 10:20:43.198124
2019-04-18 10:20:43,198 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-04-18 10:20:43,253 [salt.state       :300 ][INFO    ][14401] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-04-18 10:20:43,253 [salt.state       :1951][INFO    ][14401] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 10:20:43.253313 duration_in_ms=55.189
2019-04-18 10:20:43,253 [salt.state       :1780][INFO    ][14401] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 10:20:43.253806
2019-04-18 10:20:43,254 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-04-18 10:20:43,316 [salt.state       :300 ][INFO    ][14401] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-04-18 10:20:43,316 [salt.state       :1951][INFO    ][14401] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 10:20:43.316799 duration_in_ms=62.993
2019-04-18 10:20:43,317 [salt.state       :1780][INFO    ][14401] Running state [/root/.pgpass] at time 10:20:43.317082
2019-04-18 10:20:43,317 [salt.state       :1813][INFO    ][14401] Executing state file.managed for [/root/.pgpass]
2019-04-18 10:20:43,357 [salt.state       :300 ][INFO    ][14401] File /root/.pgpass is in the correct state
2019-04-18 10:20:43,358 [salt.state       :1951][INFO    ][14401] Completed state [/root/.pgpass] at time 10:20:43.358015 duration_in_ms=40.933
2019-04-18 10:20:43,363 [salt.state       :1780][INFO    ][14401] Running state [maas-region syncdb --noinput] at time 10:20:43.363663
2019-04-18 10:20:43,363 [salt.state       :1813][INFO    ][14401] Executing state cmd.run for [maas-region syncdb --noinput]
2019-04-18 10:20:43,364 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-04-18 10:20:45,839 [salt.state       :300 ][INFO    ][14401] {'pid': 14433, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: piston3, metadataserver, auth, contenttypes, maasserver, sessions, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-04-18 10:20:45,840 [salt.state       :1951][INFO    ][14401] Completed state [maas-region syncdb --noinput] at time 10:20:45.840383 duration_in_ms=2476.718
2019-04-18 10:20:45,840 [salt.state       :2022][WARNING ][14401] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-04-18 10:20:45,845 [salt.state       :1780][INFO    ][14401] Running state [maas-regiond] at time 10:20:45.845339
2019-04-18 10:20:45,845 [salt.state       :1813][INFO    ][14401] Executing state service.running for [maas-regiond]
2019-04-18 10:20:45,846 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:45,878 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-04-18 10:20:45,897 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-04-18 10:20:45,917 [salt.state       :300 ][INFO    ][14401] The service maas-regiond is already running
2019-04-18 10:20:45,917 [salt.state       :1951][INFO    ][14401] Completed state [maas-regiond] at time 10:20:45.917679 duration_in_ms=72.339
2019-04-18 10:20:45,920 [salt.state       :1780][INFO    ][14401] Running state [bind9] at time 10:20:45.920511
2019-04-18 10:20:45,921 [salt.state       :1813][INFO    ][14401] Executing state service.running for [bind9]
2019-04-18 10:20:45,922 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:45,940 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-04-18 10:20:45,959 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-04-18 10:20:45,980 [salt.state       :300 ][INFO    ][14401] The service bind9 is already running
2019-04-18 10:20:45,981 [salt.state       :1951][INFO    ][14401] Completed state [bind9] at time 10:20:45.980987 duration_in_ms=60.476
2019-04-18 10:20:45,984 [salt.state       :1780][INFO    ][14401] Running state [apache2] at time 10:20:45.984112
2019-04-18 10:20:45,984 [salt.state       :1813][INFO    ][14401] Executing state service.running for [apache2]
2019-04-18 10:20:45,985 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-04-18 10:20:46,006 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-04-18 10:20:46,022 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-04-18 10:20:46,046 [salt.state       :300 ][INFO    ][14401] The service apache2 is already running
2019-04-18 10:20:46,046 [salt.state       :1951][INFO    ][14401] Completed state [apache2] at time 10:20:46.046554 duration_in_ms=62.442
2019-04-18 10:20:46,051 [salt.state       :1780][INFO    ][14401] Running state [maasng.wait_for_http_code] at time 10:20:46.051000
2019-04-18 10:20:46,051 [salt.state       :1813][INFO    ][14401] Executing state module.run for [maasng.wait_for_http_code]
2019-04-18 10:20:46,052 [salt.utils.decorators:613 ][WARNING ][14401] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:20:46,062 [salt.state       :300 ][INFO    ][14401] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-04-18 10:20:46,062 [salt.state       :1951][INFO    ][14401] Completed state [maasng.wait_for_http_code] at time 10:20:46.062572 duration_in_ms=11.572
2019-04-18 10:20:46,063 [salt.state       :1780][INFO    ][14401] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 10:20:46.063397
2019-04-18 10:20:46,063 [salt.state       :1813][INFO    ][14401] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-04-18 10:20:46,064 [salt.state       :300 ][INFO    ][14401] /var/lib/maas/.setup_admin exists
2019-04-18 10:20:46,064 [salt.state       :1951][INFO    ][14401] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 10:20:46.064342 duration_in_ms=0.945
2019-04-18 10:20:46,065 [salt.state       :1780][INFO    ][14401] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:20:46.065071
2019-04-18 10:20:46,065 [salt.state       :1813][INFO    ][14401] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:20:46,065 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14401] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:20:47,738 [salt.state       :300 ][INFO    ][14401] {'pid': 14454, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:20:47,740 [salt.state       :1951][INFO    ][14401] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:20:47.740038 duration_in_ms=1674.965
2019-04-18 10:20:47,749 [salt.state       :1780][INFO    ][14401] Running state [maas_region_boot_source_resources_mirror] at time 10:20:47.749398
2019-04-18 10:20:47,750 [salt.state       :1813][INFO    ][14401] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-04-18 10:20:47,842 [salt.state       :300 ][INFO    ][14401] {'changes': {}}
2019-04-18 10:20:47,842 [salt.state       :1951][INFO    ][14401] Completed state [maas_region_boot_source_resources_mirror] at time 10:20:47.842361 duration_in_ms=92.964
2019-04-18 10:20:47,843 [salt.state       :1780][INFO    ][14401] Running state [maasng.boot_resources_import] at time 10:20:47.843733
2019-04-18 10:20:47,844 [salt.state       :1813][INFO    ][14401] Executing state module.run for [maasng.boot_resources_import]
2019-04-18 10:20:47,844 [salt.utils.decorators:613 ][WARNING ][14401] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:20:47,928 [salt.loaded.ext.module.maasng:1600][INFO    ][14401] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-04-18 10:20:52,977 [salt.loaded.ext.module.maasng:1600][INFO    ][14401] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-04-18 10:20:55,723 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102055713986
2019-04-18 10:20:55,747 [salt.minion      :1432][INFO    ][14639] Starting a new job with PID 14639
2019-04-18 10:20:55,771 [salt.minion      :1711][INFO    ][14639] Returning information for job: 20190418102055713986
2019-04-18 10:20:58,057 [salt.state       :300 ][INFO    ][14401] {'ret': True}
2019-04-18 10:20:58,058 [salt.state       :1951][INFO    ][14401] Completed state [maasng.boot_resources_import] at time 10:20:58.058017 duration_in_ms=10214.283
2019-04-18 10:20:58,060 [salt.state       :1780][INFO    ][14401] Running state [maas_region_boot_sources_selection_xenial] at time 10:20:58.060487
2019-04-18 10:20:58,060 [salt.state       :1813][INFO    ][14401] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-04-18 10:20:58,233 [salt.state       :300 ][INFO    ][14401] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-04-18 10:20:58,233 [salt.state       :1951][INFO    ][14401] Completed state [maas_region_boot_sources_selection_xenial] at time 10:20:58.233416 duration_in_ms=172.929
2019-04-18 10:20:58,234 [salt.state       :1780][INFO    ][14401] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 10:20:58.234237
2019-04-18 10:20:58,234 [salt.state       :1813][INFO    ][14401] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-04-18 10:20:58,235 [salt.utils.decorators:613 ][WARNING ][14401] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:20:58,235 [salt.loaded.ext.module.maasng:1771][INFO    ][14401] boot-sources sync initiated for ALL Rack's
2019-04-18 10:20:59,218 [salt.state       :300 ][INFO    ][14401] {'ret': True}
2019-04-18 10:20:59,218 [salt.state       :1951][INFO    ][14401] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 10:20:59.218391 duration_in_ms=984.153
2019-04-18 10:20:59,221 [salt.state       :1780][INFO    ][14401] Running state [maas.process_maas_config] at time 10:20:59.221203
2019-04-18 10:20:59,221 [salt.state       :1813][INFO    ][14401] Executing state module.run for [maas.process_maas_config]
2019-04-18 10:20:59,222 [salt.utils.decorators:613 ][WARNING ][14401] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:20:59,224 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=enable_http_proxy value=True
2019-04-18 10:20:59,281 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=upstream_dns value=8.8.8.8
2019-04-18 10:20:59,326 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=commissioning_distro_series value=xenial
2019-04-18 10:20:59,383 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=default_osystem value=ubuntu
2019-04-18 10:21:00,513 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=active_discovery_interval value=600
2019-04-18 10:21:00,561 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=dnssec_validation value=no
2019-04-18 10:21:00,597 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=maas_name value=mas01
2019-04-18 10:21:00,635 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=network_discovery value=enabled
2019-04-18 10:21:00,728 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=enable_third_party_drivers value=True
2019-04-18 10:21:00,788 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=default_storage_layout value=lvm
2019-04-18 10:21:00,834 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=ntp_external_only value=True
2019-04-18 10:21:00,895 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=disk_erase_with_secure_erase value=False
2019-04-18 10:21:00,952 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=default_distro_series value=xenial
2019-04-18 10:21:01,020 [salt.loaded.ext.module.maas:92  ][INFO    ][14401] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-04-18 10:21:01,127 [salt.state       :300 ][INFO    ][14401] {'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-04-18 10:21:01,127 [salt.state       :1951][INFO    ][14401] Completed state [maas.process_maas_config] at time 10:21:01.127731 duration_in_ms=1906.527
2019-04-18 10:21:01,128 [salt.state       :1780][INFO    ][14401] Running state [pxe_admin] at time 10:21:01.128306
2019-04-18 10:21:01,128 [salt.state       :1813][INFO    ][14401] Executing state maasng.fabric_present for [pxe_admin]
2019-04-18 10:21:01,180 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'id': 0}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'id': 1}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'id': 2}]
2019-04-18 10:21:01,251 [salt.loaded.ext.module.maasng:1008][WARNING ][14401] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-04-18 10:21:01,252 [salt.loaded.ext.module.maasng:1011][WARNING ][14401] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-04-18 10:21:01,309 [salt.state       :300 ][INFO    ][14401] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-04-18 10:21:01,310 [salt.state       :1951][INFO    ][14401] Completed state [pxe_admin] at time 10:21:01.310223 duration_in_ms=181.916
2019-04-18 10:21:01,310 [salt.state       :1780][INFO    ][14401] Running state [vlan 0] at time 10:21:01.310526
2019-04-18 10:21:01,313 [salt.state       :1813][INFO    ][14401] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-18 10:21:01,364 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-18 10:21:01,450 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{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'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-18 10:21:01,711 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'id': 0}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'id': 1}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'id': 2}]
2019-04-18 10:21:01,787 [salt.state       :300 ][INFO    ][14401] {'new': 'Vlan untagged was updated'}
2019-04-18 10:21:01,787 [salt.state       :1951][INFO    ][14401] Completed state [vlan 0] at time 10:21:01.787403 duration_in_ms=476.876
2019-04-18 10:21:01,788 [salt.state       :1780][INFO    ][14401] Running state [192.168.11.0/24] at time 10:21:01.788475
2019-04-18 10:21:01,788 [salt.state       :1813][INFO    ][14401] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-04-18 10:21:01,969 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{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'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-18 10:21:01,970 [salt.loaded.ext.module.maasng:1235][WARNING ][14401] Ignoring parameter vlan:0
2019-04-18 10:21:02,030 [salt.state       :300 ][INFO    ][14401] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-04-18 10:21:02,032 [salt.state       :1951][INFO    ][14401] Completed state [192.168.11.0/24] at time 10:21:02.032057 duration_in_ms=243.581
2019-04-18 10:21:02,032 [salt.state       :1780][INFO    ][14401] Running state [maas_create_iprange_1] at time 10:21:02.032830
2019-04-18 10:21:02,033 [salt.state       :1813][INFO    ][14401] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-04-18 10:21:02,087 [salt.state       :300 ][INFO    ][14401] Iprange maas_create_iprange_1 already exist.
2019-04-18 10:21:02,088 [salt.state       :1951][INFO    ][14401] Completed state [maas_create_iprange_1] at time 10:21:02.088133 duration_in_ms=55.302
2019-04-18 10:21:02,088 [salt.state       :1780][INFO    ][14401] Running state [vlan 0] at time 10:21:02.088395
2019-04-18 10:21:02,088 [salt.state       :1813][INFO    ][14401] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-04-18 10:21:02,133 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'id': 0}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'id': 1}, {u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'8ksyym', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'id': 2}]
2019-04-18 10:21:02,222 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'8ksyym', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-04-18 10:21:02,421 [salt.loaded.ext.module.maasng:945 ][INFO    ][14401] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'8ksyym', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-04-18 10:21:02,515 [salt.state       :300 ][INFO    ][14401] {'new': 'Vlan untagged was updated'}
2019-04-18 10:21:02,515 [salt.state       :1951][INFO    ][14401] Completed state [vlan 0] at time 10:21:02.515764 duration_in_ms=427.369
2019-04-18 10:21:02,516 [salt.state       :1780][INFO    ][14401] Running state [opnfv] at time 10:21:02.516467
2019-04-18 10:21:02,516 [salt.state       :1813][INFO    ][14401] Executing state maasng.sshkey_present for [opnfv]
2019-04-18 10:21:02,564 [salt.loaded.ext.module.maasng:1903][INFO    ][14401] [{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-04-18 10:21:02,565 [salt.state       :300 ][INFO    ][14401] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-04-18 10:21:02,565 [salt.state       :1951][INFO    ][14401] Completed state [opnfv] at time 10:21:02.565406 duration_in_ms=48.938
2019-04-18 10:21:02,567 [salt.minion      :1711][INFO    ][14401] Returning information for job: 20190418102040622543
2019-04-18 10:21:03,180 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102103167881
2019-04-18 10:21:03,201 [salt.minion      :1432][INFO    ][14870] Starting a new job with PID 14870
2019-04-18 10:21:11,428 [salt.state       :915 ][INFO    ][14870] Loading fresh modules for state activity
2019-04-18 10:21:11,520 [salt.state       :1780][INFO    ][14870] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:21:11.520688
2019-04-18 10:21:11,521 [salt.state       :1813][INFO    ][14870] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:21:11,522 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14870] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:21:13,238 [salt.state       :300 ][INFO    ][14870] {'pid': 14916, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:21:13,240 [salt.state       :1951][INFO    ][14870] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:21:13.240206 duration_in_ms=1719.518
2019-04-18 10:21:13,243 [salt.state       :1780][INFO    ][14870] Running state [maas.process_machines] at time 10:21:13.243715
2019-04-18 10:21:13,244 [salt.state       :1813][INFO    ][14870] Executing state module.run for [maas.process_machines]
2019-04-18 10:21:13,244 [salt.utils.decorators:613 ][WARNING ][14870] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:21:13,795 [salt.loaded.ext.module.maas:412 ][WARNING ][14870] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 10:21:13,796 [salt.loaded.ext.module.maas:92  ][INFO    ][14870] 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=b7kawf architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 10:21:14,904 [salt.loaded.ext.module.maas:412 ][WARNING ][14870] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 10:21:14,905 [salt.loaded.ext.module.maas:92  ][INFO    ][14870] 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=hqd87d architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 10:21:15,997 [salt.loaded.ext.module.maas:412 ][WARNING ][14870] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 10:21:15,998 [salt.loaded.ext.module.maas:92  ][INFO    ][14870] machine hostname=kvm01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=rmt3p3 architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 10:21:17,048 [salt.loaded.ext.module.maas:412 ][WARNING ][14870] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 10:21:17,048 [salt.loaded.ext.module.maas:92  ][INFO    ][14870] machine hostname=kvm03 power_type=ipmi mac_addresses=['14:58:d0:54:7a:28'] power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 system_id=66wwpb architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 10:21:17,927 [salt.loaded.ext.module.maas:412 ][WARNING ][14870] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-04-18 10:21:17,928 [salt.loaded.ext.module.maas:92  ][INFO    ][14870] machine hostname=kvm02 power_type=ipmi mac_addresses=['14:58:d0:54:6a:60'] power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 system_id=e3h8xt architecture=amd64/generic power_parameters_power_user=opnfv
2019-04-18 10:21:18,277 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102118270324
2019-04-18 10:21:18,297 [salt.minion      :1432][INFO    ][15122] Starting a new job with PID 15122
2019-04-18 10:21:18,321 [salt.minion      :1711][INFO    ][15122] Returning information for job: 20190418102118270324
2019-04-18 10:21:18,817 [salt.state       :300 ][INFO    ][14870] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-04-18 10:21:18,817 [salt.state       :1951][INFO    ][14870] Completed state [maas.process_machines] at time 10:21:18.817649 duration_in_ms=5573.933
2019-04-18 10:21:18,821 [salt.minion      :1711][INFO    ][14870] Returning information for job: 20190418102103167881
2019-04-18 10:21:51,692 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102151680376
2019-04-18 10:21:51,710 [salt.minion      :1432][INFO    ][15162] Starting a new job with PID 15162
2019-04-18 10:21:59,933 [salt.state       :915 ][INFO    ][15162] Loading fresh modules for state activity
2019-04-18 10:22:00,031 [salt.state       :1780][INFO    ][15162] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:00.030966
2019-04-18 10:22:00,031 [salt.state       :1813][INFO    ][15162] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:22:00,032 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15162] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:22:01,693 [salt.state       :300 ][INFO    ][15162] {'pid': 15205, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:22:01,695 [salt.state       :1951][INFO    ][15162] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:01.694772 duration_in_ms=1663.806
2019-04-18 10:22:01,698 [salt.state       :1780][INFO    ][15162] Running state [maas.wait_for_machine_status] at time 10:22:01.698076
2019-04-18 10:22:01,698 [salt.state       :1813][INFO    ][15162] Executing state module.run for [maas.wait_for_machine_status]
2019-04-18 10:22:01,699 [salt.utils.decorators:613 ][WARNING ][15162] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:22:04,501 [salt.state       :300 ][INFO    ][15162] {'ret': True}
2019-04-18 10:22:04,501 [salt.state       :1951][INFO    ][15162] Completed state [maas.wait_for_machine_status] at time 10:22:04.501448 duration_in_ms=2803.371
2019-04-18 10:22:04,505 [salt.minion      :1711][INFO    ][15162] Returning information for job: 20190418102151680376
2019-04-18 10:22:05,051 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102205039453
2019-04-18 10:22:05,074 [salt.minion      :1432][INFO    ][15244] Starting a new job with PID 15244
2019-04-18 10:22:06,238 [salt.state       :915 ][INFO    ][15244] Loading fresh modules for state activity
2019-04-18 10:22:06,384 [salt.state       :1780][INFO    ][15244] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:06.384575
2019-04-18 10:22:06,384 [salt.state       :1813][INFO    ][15244] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:22:06,386 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15244] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:22:08,069 [salt.state       :300 ][INFO    ][15244] {'pid': 15256, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:22:08,071 [salt.state       :1951][INFO    ][15244] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:08.070695 duration_in_ms=1686.119
2019-04-18 10:22:08,074 [salt.state       :1780][INFO    ][15244] Running state [maas_machines_storage_cmp002_lvm] at time 10:22:08.074711
2019-04-18 10:22:08,075 [salt.state       :1813][INFO    ][15244] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-04-18 10:22:08,642 [salt.state       :300 ][INFO    ][15244] Machine cmp002 is not in Ready state.
2019-04-18 10:22:08,642 [salt.state       :1951][INFO    ][15244] Completed state [maas_machines_storage_cmp002_lvm] at time 10:22:08.642697 duration_in_ms=567.985
2019-04-18 10:22:08,645 [salt.state       :1780][INFO    ][15244] Running state [maas_machines_storage_cmp001_lvm] at time 10:22:08.645371
2019-04-18 10:22:08,645 [salt.state       :1813][INFO    ][15244] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-04-18 10:22:09,301 [salt.state       :300 ][INFO    ][15244] Machine cmp001 is not in Ready state.
2019-04-18 10:22:09,302 [salt.state       :1951][INFO    ][15244] Completed state [maas_machines_storage_cmp001_lvm] at time 10:22:09.302358 duration_in_ms=656.985
2019-04-18 10:22:09,306 [salt.minion      :1711][INFO    ][15244] Returning information for job: 20190418102205039453
2019-04-18 10:22:09,839 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102209826738
2019-04-18 10:22:09,859 [salt.minion      :1432][INFO    ][15269] Starting a new job with PID 15269
2019-04-18 10:22:10,992 [salt.state       :915 ][INFO    ][15269] Loading fresh modules for state activity
2019-04-18 10:22:11,084 [salt.state       :1780][INFO    ][15269] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:11.084539
2019-04-18 10:22:11,084 [salt.state       :1813][INFO    ][15269] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:22:11,086 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15269] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:22:12,792 [salt.state       :300 ][INFO    ][15269] {'pid': 15276, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:22:12,794 [salt.state       :1951][INFO    ][15269] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:12.793901 duration_in_ms=1709.362
2019-04-18 10:22:12,797 [salt.state       :1780][INFO    ][15269] Running state [maas.deploy_machines] at time 10:22:12.797810
2019-04-18 10:22:12,798 [salt.state       :1813][INFO    ][15269] Executing state module.run for [maas.deploy_machines]
2019-04-18 10:22:12,799 [salt.utils.decorators:613 ][WARNING ][15269] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:22:13,372 [salt.loaded.ext.module.maas:684 ][INFO    ][15269] deploymachines hwe_kernel=ga-16.04 system_id=e3h8xt distro_series=xenial
2019-04-18 10:22:15,696 [salt.state       :300 ][INFO    ][15269] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {}, 'success': ['kvm02']}}
2019-04-18 10:22:15,696 [salt.state       :1951][INFO    ][15269] Completed state [maas.deploy_machines] at time 10:22:15.696881 duration_in_ms=2899.071
2019-04-18 10:22:15,702 [salt.minion      :1711][INFO    ][15269] Returning information for job: 20190418102209826738
2019-04-18 10:22:16,224 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command state.apply with jid 20190418102216216638
2019-04-18 10:22:16,245 [salt.minion      :1432][INFO    ][15343] Starting a new job with PID 15343
2019-04-18 10:22:24,312 [salt.state       :915 ][INFO    ][15343] Loading fresh modules for state activity
2019-04-18 10:22:24,397 [salt.state       :1780][INFO    ][15343] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:24.397053
2019-04-18 10:22:24,397 [salt.state       :1813][INFO    ][15343] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-04-18 10:22:24,399 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15343] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-04-18 10:22:26,075 [salt.state       :300 ][INFO    ][15343] {'pid': 15364, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-04-18 10:22:26,076 [salt.state       :1951][INFO    ][15343] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:22:26.075952 duration_in_ms=1678.899
2019-04-18 10:22:26,082 [salt.state       :1780][INFO    ][15343] Running state [maas.wait_for_machine_status] at time 10:22:26.082033
2019-04-18 10:22:26,082 [salt.state       :1813][INFO    ][15343] Executing state module.run for [maas.wait_for_machine_status]
2019-04-18 10:22:26,082 [salt.utils.decorators:613 ][WARNING ][15343] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-04-18 10:22:28,555 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2247.53430414s left)
2019-04-18 10:22:31,387 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102231313915
2019-04-18 10:22:31,411 [salt.minion      :1432][INFO    ][15378] Starting a new job with PID 15378
2019-04-18 10:22:31,435 [salt.minion      :1711][INFO    ][15378] Returning information for job: 20190418102231313915
2019-04-18 10:23:01,205 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2214.88376999s left)
2019-04-18 10:23:01,411 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102301395640
2019-04-18 10:23:01,434 [salt.minion      :1432][INFO    ][15434] Starting a new job with PID 15434
2019-04-18 10:23:01,457 [salt.minion      :1711][INFO    ][15434] Returning information for job: 20190418102301395640
2019-04-18 10:23:31,488 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102331480637
2019-04-18 10:23:31,502 [salt.minion      :1432][INFO    ][15483] Starting a new job with PID 15483
2019-04-18 10:23:31,526 [salt.minion      :1711][INFO    ][15483] Returning information for job: 20190418102331480637
2019-04-18 10:23:33,733 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2182.35648108s left)
2019-04-18 10:24:01,689 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102401669977
2019-04-18 10:24:01,717 [salt.minion      :1432][INFO    ][15535] Starting a new job with PID 15535
2019-04-18 10:24:01,745 [salt.minion      :1711][INFO    ][15535] Returning information for job: 20190418102401669977
2019-04-18 10:24:06,598 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2149.49115705s left)
2019-04-18 10:24:31,896 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102431880990
2019-04-18 10:24:31,916 [salt.minion      :1432][INFO    ][15584] Starting a new job with PID 15584
2019-04-18 10:24:31,939 [salt.minion      :1711][INFO    ][15584] Returning information for job: 20190418102431880990
2019-04-18 10:24:39,030 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2117.05918503s left)
2019-04-18 10:25:01,958 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102501943257
2019-04-18 10:25:01,981 [salt.minion      :1432][INFO    ][15641] Starting a new job with PID 15641
2019-04-18 10:25:02,006 [salt.minion      :1711][INFO    ][15641] Returning information for job: 20190418102501943257
2019-04-18 10:25:11,738 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2084.35166097s left)
2019-04-18 10:25:32,169 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102532150805
2019-04-18 10:25:32,192 [salt.minion      :1432][INFO    ][15690] Starting a new job with PID 15690
2019-04-18 10:25:32,216 [salt.minion      :1711][INFO    ][15690] Returning information for job: 20190418102532150805
2019-04-18 10:25:44,162 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2051.92688394s left)
2019-04-18 10:26:02,369 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102602361145
2019-04-18 10:26:02,393 [salt.minion      :1432][INFO    ][15744] Starting a new job with PID 15744
2019-04-18 10:26:02,419 [salt.minion      :1711][INFO    ][15744] Returning information for job: 20190418102602361145
2019-04-18 10:26:16,986 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2019.10281706s left)
2019-04-18 10:26:32,441 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102632432659
2019-04-18 10:26:32,456 [salt.minion      :1432][INFO    ][15817] Starting a new job with PID 15817
2019-04-18 10:26:32,479 [salt.minion      :1711][INFO    ][15817] Returning information for job: 20190418102632432659
2019-04-18 10:26:49,384 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1986.7050221s left)
2019-04-18 10:27:02,504 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102702489361
2019-04-18 10:27:02,526 [salt.minion      :1432][INFO    ][15902] Starting a new job with PID 15902
2019-04-18 10:27:02,551 [salt.minion      :1711][INFO    ][15902] Returning information for job: 20190418102702489361
2019-04-18 10:27:22,235 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1953.85399199s left)
2019-04-18 10:27:32,605 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102732595829
2019-04-18 10:27:32,626 [salt.minion      :1432][INFO    ][16019] Starting a new job with PID 16019
2019-04-18 10:27:32,653 [salt.minion      :1711][INFO    ][16019] Returning information for job: 20190418102732595829
2019-04-18 10:27:54,958 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1921.13152599s left)
2019-04-18 10:28:02,707 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102802691900
2019-04-18 10:28:02,731 [salt.minion      :1432][INFO    ][16074] Starting a new job with PID 16074
2019-04-18 10:28:02,754 [salt.minion      :1711][INFO    ][16074] Returning information for job: 20190418102802691900
2019-04-18 10:28:27,823 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1888.26634312s left)
2019-04-18 10:28:32,810 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102832797803
2019-04-18 10:28:32,831 [salt.minion      :1432][INFO    ][16223] Starting a new job with PID 16223
2019-04-18 10:28:32,853 [salt.minion      :1711][INFO    ][16223] Returning information for job: 20190418102832797803
2019-04-18 10:29:00,270 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1855.81906199s left)
2019-04-18 10:29:02,837 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102902824123
2019-04-18 10:29:02,861 [salt.minion      :1432][INFO    ][16278] Starting a new job with PID 16278
2019-04-18 10:29:02,883 [salt.minion      :1711][INFO    ][16278] Returning information for job: 20190418102902824123
2019-04-18 10:29:32,946 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418102932938025
2019-04-18 10:29:32,962 [salt.minion      :1432][INFO    ][16410] Starting a new job with PID 16410
2019-04-18 10:29:32,985 [salt.minion      :1711][INFO    ][16410] Returning information for job: 20190418102932938025
2019-04-18 10:29:33,083 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1823.00598502s left)
2019-04-18 10:30:03,058 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103003049994
2019-04-18 10:30:03,072 [salt.minion      :1432][INFO    ][16460] Starting a new job with PID 16460
2019-04-18 10:30:03,095 [salt.minion      :1711][INFO    ][16460] Returning information for job: 20190418103003049994
2019-04-18 10:30:05,887 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1790.20180511s left)
2019-04-18 10:30:33,173 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103033161827
2019-04-18 10:30:33,194 [salt.minion      :1432][INFO    ][16592] Starting a new job with PID 16592
2019-04-18 10:30:33,220 [salt.minion      :1711][INFO    ][16592] Returning information for job: 20190418103033161827
2019-04-18 10:30:38,861 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1757.227916s left)
2019-04-18 10:31:03,187 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103103176607
2019-04-18 10:31:03,206 [salt.minion      :1432][INFO    ][16653] Starting a new job with PID 16653
2019-04-18 10:31:03,235 [salt.minion      :1711][INFO    ][16653] Returning information for job: 20190418103103176607
2019-04-18 10:31:11,278 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1724.81115699s left)
2019-04-18 10:31:33,326 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103133311731
2019-04-18 10:31:33,347 [salt.minion      :1432][INFO    ][16727] Starting a new job with PID 16727
2019-04-18 10:31:33,372 [salt.minion      :1711][INFO    ][16727] Returning information for job: 20190418103133311731
2019-04-18 10:31:44,077 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1692.01187515s left)
2019-04-18 10:32:02,647 [salt.utils.schedule:1377][INFO    ][3506] Running scheduled job: __mine_interval
2019-04-18 10:32:03,481 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103203474302
2019-04-18 10:32:03,501 [salt.minion      :1432][INFO    ][16802] Starting a new job with PID 16802
2019-04-18 10:32:03,528 [salt.minion      :1711][INFO    ][16802] Returning information for job: 20190418103203474302
2019-04-18 10:32:16,588 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1659.50123715s left)
2019-04-18 10:32:33,629 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103233617580
2019-04-18 10:32:33,643 [salt.minion      :1432][INFO    ][17009] Starting a new job with PID 17009
2019-04-18 10:32:33,665 [salt.minion      :1711][INFO    ][17009] Returning information for job: 20190418103233617580
2019-04-18 10:32:49,379 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1626.71055102s left)
2019-04-18 10:33:03,743 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103303734805
2019-04-18 10:33:03,763 [salt.minion      :1432][INFO    ][17075] Starting a new job with PID 17075
2019-04-18 10:33:03,787 [salt.minion      :1711][INFO    ][17075] Returning information for job: 20190418103303734805
2019-04-18 10:33:21,793 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1594.29610896s left)
2019-04-18 10:33:33,863 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103333855648
2019-04-18 10:33:33,878 [salt.minion      :1432][INFO    ][17115] Starting a new job with PID 17115
2019-04-18 10:33:33,900 [salt.minion      :1711][INFO    ][17115] Returning information for job: 20190418103333855648
2019-04-18 10:33:54,774 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1561.31543803s left)
2019-04-18 10:34:03,955 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103403942533
2019-04-18 10:34:03,974 [salt.minion      :1432][INFO    ][17176] Starting a new job with PID 17176
2019-04-18 10:34:03,997 [salt.minion      :1711][INFO    ][17176] Returning information for job: 20190418103403942533
2019-04-18 10:34:27,270 [salt.loaded.ext.module.maas:1023][INFO    ][15343] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1528.81957793s left)
2019-04-18 10:34:34,110 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command saltutil.find_job with jid 20190418103434101874
2019-04-18 10:34:34,122 [salt.minion      :1432][INFO    ][17243] Starting a new job with PID 17243
2019-04-18 10:34:34,142 [salt.minion      :1711][INFO    ][17243] Returning information for job: 20190418103434101874
2019-04-18 10:35:00,106 [salt.state       :300 ][INFO    ][15343] {'ret': True}
2019-04-18 10:35:00,109 [salt.state       :1951][INFO    ][15343] Completed state [maas.wait_for_machine_status] at time 10:35:00.106746 duration_in_ms=754024.711
2019-04-18 10:35:00,116 [salt.minion      :1711][INFO    ][15343] Returning information for job: 20190418102216216638
2019-04-18 11:32:02,647 [salt.utils.schedule:1377][INFO    ][3506] Running scheduled job: __mine_interval
2019-04-18 12:16:24,236 [salt.minion      :1308][INFO    ][3506] User sudo_ubuntu Executing command cp.push_dir with jid 20190418121624225568
2019-04-18 12:16:24,254 [salt.minion      :1432][INFO    ][27729] Starting a new job with PID 27729
