2019-08-27 20:07:25,942 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-08-27 20:08:15,992 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-08-27 20:09:06,040 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-08-27 20:09:56,087 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-08-27 20:10:46,133 [salt.minion      :870 ][ERROR   ][359] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-08-27 20:12:56,896 [salt.utils.decorators:613 ][WARNING ][2725] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 20:12:57,573 [salt.utils.decorators:613 ][WARNING ][2725] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 20:12:59,737 [salt.loaded.int.states.file:2298][WARNING ][2868] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-08-27 20:13:05,330 [salt.state       :2022][WARNING ][2974] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-27 20:13:07,994 [salt.utils.decorators:613 ][WARNING ][2974] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 20:28:15,626 [salt.utils.decorators:613 ][WARNING ][2974] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 20:55:12,481 [salt.utils.decorators:613 ][WARNING ][2974] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:10:15,224 [salt.utils.decorators:613 ][WARNING ][2974] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:10:19,122 [salt.loaded.ext.module.maasng:1008][WARNING ][2974] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-08-27 21:10:19,123 [salt.loaded.ext.module.maasng:1011][WARNING ][2974] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-08-27 21:10:19,947 [salt.loaded.ext.module.maasng:1235][WARNING ][2974] Ignoring parameter vlan:0
2019-08-27 21:10:20,788 [salt.utils.decorators:613 ][WARNING ][2974] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:10:26,611 [salt.utils.decorators:613 ][WARNING ][12192] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:10:26,653 [salt.loaded.ext.module.maas:412 ][WARNING ][12192] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:10:29,721 [salt.loaded.ext.module.maas:412 ][WARNING ][12192] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:10:33,967 [salt.loaded.ext.module.maas:412 ][WARNING ][12192] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:10:38,177 [salt.loaded.ext.module.maas:412 ][WARNING ][12192] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:10:42,602 [salt.loaded.ext.module.maas:412 ][WARNING ][12192] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:10:49,475 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13131] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-08-27 21:10:49,507 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13131] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-08-27 21:10:49,532 [salt.utils.parsers:1051][WARNING ][359] Minion received a SIGTERM. Exiting.
2019-08-27 21:10:50,603 [salt.cli.daemons :293 ][INFO    ][13177] Setting up the Salt Minion "mas01.mcp-odl-noha.local"
2019-08-27 21:10:50,702 [salt.cli.daemons :82  ][INFO    ][13177] Starting up the Salt Minion
2019-08-27 21:10:50,702 [salt.utils.event :1017][INFO    ][13177] Starting pull socket on /var/run/salt/minion/minion_event_0f3e0c7467_pull.ipc
2019-08-27 21:10:51,620 [salt.minion      :976 ][INFO    ][13177] Creating minion process manager
2019-08-27 21:10:53,045 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13177] Executing command ['date', '+%z'] in directory '/root'
2019-08-27 21:10:53,065 [salt.utils.schedule:568 ][INFO    ][13177] Updating job settings for scheduled job: __mine_interval
2019-08-27 21:10:53,066 [salt.minion      :1108][INFO    ][13177] Added mine.update to scheduler
2019-08-27 21:10:53,070 [salt.minion      :1975][INFO    ][13177] Minion is starting as user 'root'
2019-08-27 21:10:53,080 [salt.minion      :2336][INFO    ][13177] Minion is ready to receive requests!
2019-08-27 21:11:18,102 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827211118089433
2019-08-27 21:11:18,123 [salt.minion      :1432][INFO    ][13305] Starting a new job with PID 13305
2019-08-27 21:11:21,606 [salt.state       :915 ][INFO    ][13305] Loading fresh modules for state activity
2019-08-27 21:11:21,649 [salt.fileclient  :1219][INFO    ][13305] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-08-27 21:11:21,681 [salt.state       :1780][INFO    ][13305] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:11:21.681891
2019-08-27 21:11:21,682 [salt.state       :1813][INFO    ][13305] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:11:21,683 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13305] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:11:23,150 [salt.state       :300 ][INFO    ][13305] {'pid': 13312, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:11:23,151 [salt.state       :1951][INFO    ][13305] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:11:23.151323 duration_in_ms=1469.433
2019-08-27 21:11:23,152 [salt.state       :1780][INFO    ][13305] Running state [maas.wait_for_machine_status] at time 21:11:23.152412
2019-08-27 21:11:23,152 [salt.state       :1813][INFO    ][13305] Executing state module.run for [maas.wait_for_machine_status]
2019-08-27 21:11:23,152 [salt.utils.decorators:613 ][WARNING ][13305] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:11:24,142 [salt.loaded.ext.module.maas:1023][INFO    ][13305] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.01443887s left)
2019-08-27 21:11:33,223 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211133210984
2019-08-27 21:11:33,242 [salt.minion      :1432][INFO    ][13330] Starting a new job with PID 13330
2019-08-27 21:11:33,263 [salt.minion      :1711][INFO    ][13330] Returning information for job: 20190827211133210984
2019-08-27 21:11:55,220 [salt.loaded.ext.module.maas:1023][INFO    ][13305] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1467.93692183s left)
2019-08-27 21:12:03,259 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211203247869
2019-08-27 21:12:03,282 [salt.minion      :1432][INFO    ][13361] Starting a new job with PID 13361
2019-08-27 21:12:03,305 [salt.minion      :1711][INFO    ][13361] Returning information for job: 20190827211203247869
2019-08-27 21:12:26,042 [salt.loaded.ext.module.maas:1023][INFO    ][13305] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1437.11501884s left)
2019-08-27 21:12:33,324 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211233318093
2019-08-27 21:12:33,341 [salt.minion      :1432][INFO    ][13574] Starting a new job with PID 13574
2019-08-27 21:12:33,352 [salt.minion      :1711][INFO    ][13574] Returning information for job: 20190827211233318093
2019-08-27 21:12:57,547 [salt.loaded.ext.module.maas:1023][INFO    ][13305] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1405.60985184s left)
2019-08-27 21:13:03,356 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211303344124
2019-08-27 21:13:03,375 [salt.minion      :1432][INFO    ][13715] Starting a new job with PID 13715
2019-08-27 21:13:03,393 [salt.minion      :1711][INFO    ][13715] Returning information for job: 20190827211303344124
2019-08-27 21:13:33,423 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211333410657
2019-08-27 21:13:33,446 [salt.minion      :1432][INFO    ][14637] Starting a new job with PID 14637
2019-08-27 21:13:33,471 [salt.minion      :1711][INFO    ][14637] Returning information for job: 20190827211333410657
2019-08-27 21:14:03,456 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211403443773
2019-08-27 21:14:03,479 [salt.minion      :1432][INFO    ][14711] Starting a new job with PID 14711
2019-08-27 21:14:03,504 [salt.minion      :1711][INFO    ][14711] Returning information for job: 20190827211403443773
2019-08-27 21:14:33,552 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211433542062
2019-08-27 21:14:33,574 [salt.minion      :1432][INFO    ][14780] Starting a new job with PID 14780
2019-08-27 21:14:33,592 [salt.minion      :1711][INFO    ][14780] Returning information for job: 20190827211433542062
2019-08-27 21:15:03,622 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211503609071
2019-08-27 21:15:03,643 [salt.minion      :1432][INFO    ][14818] Starting a new job with PID 14818
2019-08-27 21:15:03,667 [salt.minion      :1711][INFO    ][14818] Returning information for job: 20190827211503609071
2019-08-27 21:15:33,710 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211533698624
2019-08-27 21:15:33,733 [salt.minion      :1432][INFO    ][14874] Starting a new job with PID 14874
2019-08-27 21:15:33,757 [salt.minion      :1711][INFO    ][14874] Returning information for job: 20190827211533698624
2019-08-27 21:16:03,810 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211603797873
2019-08-27 21:16:03,833 [salt.minion      :1432][INFO    ][14921] Starting a new job with PID 14921
2019-08-27 21:16:03,856 [salt.minion      :1711][INFO    ][14921] Returning information for job: 20190827211603797873
2019-08-27 21:16:33,926 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211633911242
2019-08-27 21:16:33,946 [salt.minion      :1432][INFO    ][14972] Starting a new job with PID 14972
2019-08-27 21:16:33,968 [salt.minion      :1711][INFO    ][14972] Returning information for job: 20190827211633911242
2019-08-27 21:17:04,023 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211704016969
2019-08-27 21:17:04,043 [salt.minion      :1432][INFO    ][15019] Starting a new job with PID 15019
2019-08-27 21:17:04,068 [salt.minion      :1711][INFO    ][15019] Returning information for job: 20190827211704016969
2019-08-27 21:17:34,133 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211734120131
2019-08-27 21:17:34,158 [salt.minion      :1432][INFO    ][15069] Starting a new job with PID 15069
2019-08-27 21:17:34,182 [salt.minion      :1711][INFO    ][15069] Returning information for job: 20190827211734120131
2019-08-27 21:18:04,251 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211804242152
2019-08-27 21:18:04,272 [salt.minion      :1432][INFO    ][15099] Starting a new job with PID 15099
2019-08-27 21:18:04,291 [salt.minion      :1711][INFO    ][15099] Returning information for job: 20190827211804242152
2019-08-27 21:18:34,373 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211834357674
2019-08-27 21:18:34,393 [salt.minion      :1432][INFO    ][15142] Starting a new job with PID 15142
2019-08-27 21:18:34,418 [salt.minion      :1711][INFO    ][15142] Returning information for job: 20190827211834357674
2019-08-27 21:19:04,497 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827211904485133
2019-08-27 21:19:04,520 [salt.minion      :1432][INFO    ][15169] Starting a new job with PID 15169
2019-08-27 21:19:04,542 [salt.minion      :1711][INFO    ][15169] Returning information for job: 20190827211904485133
2019-08-27 21:19:29,586 [salt.state       :302 ][ERROR   ][13305] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-08-27 21:19:29,587 [salt.state       :1951][INFO    ][13305] Completed state [maas.wait_for_machine_status] at time 21:19:29.587565 duration_in_ms=486435.15
2019-08-27 21:19:29,591 [salt.minion      :1711][INFO    ][13305] Returning information for job: 20190827211118089433
2019-08-27 21:19:40,388 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command pillar.get with jid 20190827211940375129
2019-08-27 21:19:40,408 [salt.minion      :1432][INFO    ][15511] Starting a new job with PID 15511
2019-08-27 21:19:40,415 [salt.minion      :1711][INFO    ][15511] Returning information for job: 20190827211940375129
2019-08-27 21:19:40,943 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command service.status with jid 20190827211940930370
2019-08-27 21:19:40,964 [salt.minion      :1432][INFO    ][15517] Starting a new job with PID 15517
2019-08-27 21:19:41,453 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15517] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:41,483 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15517] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-08-27 21:19:41,496 [salt.minion      :1711][INFO    ][15517] Returning information for job: 20190827211940930370
2019-08-27 21:19:41,992 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827211941985452
2019-08-27 21:19:42,010 [salt.minion      :1432][INFO    ][15543] Starting a new job with PID 15543
2019-08-27 21:19:45,652 [salt.state       :915 ][INFO    ][15543] Loading fresh modules for state activity
2019-08-27 21:19:45,980 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'salt-minion --version' in directory '/root'
2019-08-27 21:19:46,313 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'salt-minion --version' in directory '/root'
2019-08-27 21:19:47,147 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'salt-minion --version' in directory '/root'
2019-08-27 21:19:47,500 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'salt-minion --version' in directory '/root'
2019-08-27 21:19:48,849 [salt.state       :1780][INFO    ][15543] Running state [salt-minion] at time 21:19:48.849137
2019-08-27 21:19:48,849 [salt.state       :1813][INFO    ][15543] Executing state pkg.installed for [salt-minion]
2019-08-27 21:19:48,849 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-27 21:19:48,922 [salt.state       :300 ][INFO    ][15543] All specified packages are already installed
2019-08-27 21:19:48,923 [salt.state       :1951][INFO    ][15543] Completed state [salt-minion] at time 21:19:48.923118 duration_in_ms=73.982
2019-08-27 21:19:48,923 [salt.state       :1780][INFO    ][15543] Running state [salt_minion_dependency_packages] at time 21:19:48.923355
2019-08-27 21:19:48,923 [salt.state       :1813][INFO    ][15543] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-08-27 21:19:48,928 [salt.state       :300 ][INFO    ][15543] All specified packages are already installed
2019-08-27 21:19:48,928 [salt.state       :1951][INFO    ][15543] Completed state [salt_minion_dependency_packages] at time 21:19:48.928203 duration_in_ms=4.848
2019-08-27 21:19:48,930 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/minion.d/minion.conf] at time 21:19:48.930519
2019-08-27 21:19:48,930 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-08-27 21:19:49,101 [salt.state       :300 ][INFO    ][15543] File /etc/salt/minion.d/minion.conf is in the correct state
2019-08-27 21:19:49,101 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/minion.d/minion.conf] at time 21:19:49.101329 duration_in_ms=170.81
2019-08-27 21:19:49,103 [salt.state       :1780][INFO    ][15543] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:49.103435
2019-08-27 21:19:49,103 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-08-27 21:19:49,112 [salt.state       :300 ][INFO    ][15543] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-08-27 21:19:49,112 [salt.state       :1951][INFO    ][15543] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:19:49.112777 duration_in_ms=9.342
2019-08-27 21:19:49,113 [salt.state       :1780][INFO    ][15543] Running state [salt-minion] at time 21:19:49.113421
2019-08-27 21:19:49,113 [salt.state       :1813][INFO    ][15543] Executing state service.running for [salt-minion]
2019-08-27 21:19:49,114 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:49,150 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-08-27 21:19:49,167 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-08-27 21:19:49,184 [salt.state       :300 ][INFO    ][15543] The service salt-minion is already running
2019-08-27 21:19:49,184 [salt.state       :1951][INFO    ][15543] Completed state [salt-minion] at time 21:19:49.184894 duration_in_ms=71.471
2019-08-27 21:19:49,186 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains.d] at time 21:19:49.186522
2019-08-27 21:19:49,186 [salt.state       :1813][INFO    ][15543] Executing state file.directory for [/etc/salt/grains.d]
2019-08-27 21:19:49,187 [salt.state       :300 ][INFO    ][15543] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-08-27 21:19:49,188 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains.d] at time 21:19:49.188113 duration_in_ms=1.59
2019-08-27 21:19:49,188 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains] at time 21:19:49.188838
2019-08-27 21:19:49,189 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/grains]
2019-08-27 21:19:49,189 [salt.state       :300 ][INFO    ][15543] File /etc/salt/grains exists with proper permissions. No changes made.
2019-08-27 21:19:49,190 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains] at time 21:19:49.189993 duration_in_ms=1.154
2019-08-27 21:19:49,190 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains.d/placeholder] at time 21:19:49.190476
2019-08-27 21:19:49,190 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-08-27 21:19:49,191 [salt.state       :300 ][INFO    ][15543] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-08-27 21:19:49,191 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains.d/placeholder] at time 21:19:49.191621 duration_in_ms=1.145
2019-08-27 21:19:49,192 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains.d/sphinx] at time 21:19:49.192106
2019-08-27 21:19:49,192 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-08-27 21:19:49,209 [salt.state       :300 ][INFO    ][15543] File /etc/salt/grains.d/sphinx is in the correct state
2019-08-27 21:19:49,209 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains.d/sphinx] at time 21:19:49.209240 duration_in_ms=17.135
2019-08-27 21:19:49,211 [salt.state       :1780][INFO    ][15543] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.211637
2019-08-27 21:19:49,212 [salt.state       :1813][INFO    ][15543] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-08-27 21:19:49,212 [salt.state       :300 ][INFO    ][15543] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-08-27 21:19:49,212 [salt.state       :1951][INFO    ][15543] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.212620 duration_in_ms=0.983
2019-08-27 21:19:49,213 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains.d/dns_records] at time 21:19:49.213126
2019-08-27 21:19:49,213 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-08-27 21:19:49,226 [salt.state       :300 ][INFO    ][15543] File /etc/salt/grains.d/dns_records is in the correct state
2019-08-27 21:19:49,227 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains.d/dns_records] at time 21:19:49.227165 duration_in_ms=14.039
2019-08-27 21:19:49,228 [salt.state       :1780][INFO    ][15543] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.228152
2019-08-27 21:19:49,228 [salt.state       :1813][INFO    ][15543] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-08-27 21:19:49,228 [salt.state       :300 ][INFO    ][15543] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-08-27 21:19:49,229 [salt.state       :1951][INFO    ][15543] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.229106 duration_in_ms=0.953
2019-08-27 21:19:49,229 [salt.state       :1780][INFO    ][15543] Running state [/etc/salt/grains.d/salt] at time 21:19:49.229615
2019-08-27 21:19:49,229 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-08-27 21:19:49,244 [salt.state       :300 ][INFO    ][15543] File /etc/salt/grains.d/salt is in the correct state
2019-08-27 21:19:49,245 [salt.state       :1951][INFO    ][15543] Completed state [/etc/salt/grains.d/salt] at time 21:19:49.245212 duration_in_ms=15.597
2019-08-27 21:19:49,246 [salt.state       :1780][INFO    ][15543] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.246153
2019-08-27 21:19:49,246 [salt.state       :1813][INFO    ][15543] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-08-27 21:19:49,246 [salt.state       :300 ][INFO    ][15543] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-08-27 21:19:49,247 [salt.state       :1951][INFO    ][15543] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:19:49.247095 duration_in_ms=0.943
2019-08-27 21:19:49,249 [salt.state       :1780][INFO    ][15543] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:49.249112
2019-08-27 21:19:49,249 [salt.state       :1813][INFO    ][15543] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-08-27 21:19:49,249 [salt.state       :300 ][INFO    ][15543] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-08-27 21:19:49,250 [salt.state       :1951][INFO    ][15543] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:19:49.250061 duration_in_ms=0.949
2019-08-27 21:19:49,250 [salt.state       :1780][INFO    ][15543] Running state [mine.update] at time 21:19:49.250793
2019-08-27 21:19:49,251 [salt.state       :1813][INFO    ][15543] Executing state module.wait for [mine.update]
2019-08-27 21:19:49,251 [salt.state       :300 ][INFO    ][15543] No changes made for mine.update
2019-08-27 21:19:49,251 [salt.state       :1951][INFO    ][15543] Completed state [mine.update] at time 21:19:49.251666 duration_in_ms=0.872
2019-08-27 21:19:49,251 [salt.state       :1780][INFO    ][15543] Running state [ca-certificates] at time 21:19:49.251934
2019-08-27 21:19:49,252 [salt.state       :1813][INFO    ][15543] Executing state pkg.installed for [ca-certificates]
2019-08-27 21:19:49,260 [salt.state       :300 ][INFO    ][15543] All specified packages are already installed
2019-08-27 21:19:49,260 [salt.state       :1951][INFO    ][15543] Completed state [ca-certificates] at time 21:19:49.260591 duration_in_ms=8.656
2019-08-27 21:19:49,261 [salt.state       :1780][INFO    ][15543] Running state [update-ca-certificates] at time 21:19:49.261668
2019-08-27 21:19:49,262 [salt.state       :1813][INFO    ][15543] Executing state cmd.wait for [update-ca-certificates]
2019-08-27 21:19:49,262 [salt.state       :300 ][INFO    ][15543] No changes made for update-ca-certificates
2019-08-27 21:19:49,262 [salt.state       :1951][INFO    ][15543] Completed state [update-ca-certificates] at time 21:19:49.262555 duration_in_ms=0.887
2019-08-27 21:19:49,262 [salt.state       :1780][INFO    ][15543] Running state [iptables] at time 21:19:49.262822
2019-08-27 21:19:49,263 [salt.state       :1813][INFO    ][15543] Executing state pkg.installed for [iptables]
2019-08-27 21:19:49,270 [salt.state       :300 ][INFO    ][15543] All specified packages are already installed
2019-08-27 21:19:49,270 [salt.state       :1951][INFO    ][15543] Completed state [iptables] at time 21:19:49.270474 duration_in_ms=7.652
2019-08-27 21:19:49,270 [salt.state       :1780][INFO    ][15543] Running state [iptables-persistent] at time 21:19:49.270752
2019-08-27 21:19:49,271 [salt.state       :1813][INFO    ][15543] Executing state pkg.installed for [iptables-persistent]
2019-08-27 21:19:49,278 [salt.state       :300 ][INFO    ][15543] All specified packages are already installed
2019-08-27 21:19:49,278 [salt.state       :1951][INFO    ][15543] Completed state [iptables-persistent] at time 21:19:49.278381 duration_in_ms=7.629
2019-08-27 21:19:49,279 [salt.state       :1780][INFO    ][15543] Running state [iptables_modules_v4_load] at time 21:19:49.279406
2019-08-27 21:19:49,279 [salt.state       :1813][INFO    ][15543] Executing state kmod.present for [iptables_modules_v4_load]
2019-08-27 21:19:49,280 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'lsmod' in directory '/root'
2019-08-27 21:19:49,303 [salt.state       :300 ][INFO    ][15543] Kernel modules iptable_filter, ip_tables are already present
2019-08-27 21:19:49,303 [salt.state       :1951][INFO    ][15543] Completed state [iptables_modules_v4_load] at time 21:19:49.303355 duration_in_ms=23.948
2019-08-27 21:19:49,304 [salt.state       :1780][INFO    ][15543] Running state [/etc/iptables/rules.v4] at time 21:19:49.304063
2019-08-27 21:19:49,304 [salt.state       :1813][INFO    ][15543] Executing state file.managed for [/etc/iptables/rules.v4]
2019-08-27 21:19:49,394 [salt.state       :300 ][INFO    ][15543] File /etc/iptables/rules.v4 is in the correct state
2019-08-27 21:19:49,395 [salt.state       :1951][INFO    ][15543] Completed state [/etc/iptables/rules.v4] at time 21:19:49.395108 duration_in_ms=91.044
2019-08-27 21:19:49,396 [salt.state       :1780][INFO    ][15543] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:49.396059
2019-08-27 21:19:49,396 [salt.state       :1813][INFO    ][15543] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-08-27 21:19:49,396 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-08-27 21:19:49,415 [salt.state       :300 ][INFO    ][15543] onlyif execution failed
2019-08-27 21:19:49,416 [salt.state       :1951][INFO    ][15543] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:19:49.416183 duration_in_ms=20.123
2019-08-27 21:19:49,417 [salt.state       :1780][INFO    ][15543] Running state [netfilter-persistent] at time 21:19:49.417920
2019-08-27 21:19:49,418 [salt.state       :1813][INFO    ][15543] Executing state service.running for [netfilter-persistent]
2019-08-27 21:19:49,419 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:49,441 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-08-27 21:19:49,460 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-08-27 21:19:49,479 [salt.state       :300 ][INFO    ][15543] The service netfilter-persistent is already running
2019-08-27 21:19:49,479 [salt.state       :1951][INFO    ][15543] Completed state [netfilter-persistent] at time 21:19:49.479722 duration_in_ms=61.802
2019-08-27 21:19:49,481 [salt.state       :1780][INFO    ][15543] Running state [iptables_extra.remove_stale_tables] at time 21:19:49.481071
2019-08-27 21:19:49,481 [salt.state       :1813][INFO    ][15543] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-08-27 21:19:49,482 [salt.state       :300 ][INFO    ][15543] No changes made for iptables_extra.remove_stale_tables
2019-08-27 21:19:49,482 [salt.state       :1951][INFO    ][15543] Completed state [iptables_extra.remove_stale_tables] at time 21:19:49.482471 duration_in_ms=1.4
2019-08-27 21:19:49,482 [salt.state       :1780][INFO    ][15543] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:49.482884
2019-08-27 21:19:49,483 [salt.state       :1813][INFO    ][15543] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-08-27 21:19:49,484 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15543] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-08-27 21:19:49,500 [salt.state       :300 ][INFO    ][15543] onlyif execution failed
2019-08-27 21:19:49,501 [salt.state       :1951][INFO    ][15543] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:19:49.500968 duration_in_ms=18.085
2019-08-27 21:19:49,502 [salt.state       :1780][INFO    ][15543] Running state [/etc/iptables/rules.v6] at time 21:19:49.502414
2019-08-27 21:19:49,502 [salt.state       :1813][INFO    ][15543] Executing state file.absent for [/etc/iptables/rules.v6]
2019-08-27 21:19:49,503 [salt.state       :300 ][INFO    ][15543] File /etc/iptables/rules.v6 is not present
2019-08-27 21:19:49,504 [salt.state       :1951][INFO    ][15543] Completed state [/etc/iptables/rules.v6] at time 21:19:49.503926 duration_in_ms=1.512
2019-08-27 21:19:49,505 [salt.state       :1780][INFO    ][15543] Running state [iptables_extra.flush_all] at time 21:19:49.504951
2019-08-27 21:19:49,505 [salt.state       :1813][INFO    ][15543] Executing state module.wait for [iptables_extra.flush_all]
2019-08-27 21:19:49,505 [salt.state       :300 ][INFO    ][15543] No changes made for iptables_extra.flush_all
2019-08-27 21:19:49,506 [salt.state       :1951][INFO    ][15543] Completed state [iptables_extra.flush_all] at time 21:19:49.506136 duration_in_ms=1.184
2019-08-27 21:19:49,510 [salt.minion      :1711][INFO    ][15543] Returning information for job: 20190827211941985452
2019-08-27 21:19:50,133 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827211950120741
2019-08-27 21:19:50,155 [salt.minion      :1432][INFO    ][15624] Starting a new job with PID 15624
2019-08-27 21:19:50,853 [salt.state       :915 ][INFO    ][15624] Loading fresh modules for state activity
2019-08-27 21:19:51,482 [salt.state       :1780][INFO    ][15624] Running state [maas-rack-controller] at time 21:19:51.482080
2019-08-27 21:19:51,482 [salt.state       :1813][INFO    ][15624] Executing state pkg.installed for [maas-rack-controller]
2019-08-27 21:19:51,482 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15624] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-27 21:19:51,614 [salt.state       :300 ][INFO    ][15624] All specified packages are already installed
2019-08-27 21:19:51,614 [salt.state       :1951][INFO    ][15624] Completed state [maas-rack-controller] at time 21:19:51.614783 duration_in_ms=132.702
2019-08-27 21:19:51,615 [salt.state       :1780][INFO    ][15624] Running state [ipmitool] at time 21:19:51.615057
2019-08-27 21:19:51,615 [salt.state       :1813][INFO    ][15624] Executing state pkg.installed for [ipmitool]
2019-08-27 21:19:51,620 [salt.state       :300 ][INFO    ][15624] All specified packages are already installed
2019-08-27 21:19:51,620 [salt.state       :1951][INFO    ][15624] Completed state [ipmitool] at time 21:19:51.620637 duration_in_ms=5.58
2019-08-27 21:19:51,623 [salt.state       :1780][INFO    ][15624] Running state [/etc/maas/rackd.conf] at time 21:19:51.623190
2019-08-27 21:19:51,623 [salt.state       :1813][INFO    ][15624] Executing state file.line for [/etc/maas/rackd.conf]
2019-08-27 21:19:51,624 [salt.state       :300 ][INFO    ][15624] No changes needed to be made
2019-08-27 21:19:51,624 [salt.state       :1951][INFO    ][15624] Completed state [/etc/maas/rackd.conf] at time 21:19:51.624503 duration_in_ms=1.313
2019-08-27 21:19:51,624 [salt.state       :1780][INFO    ][15624] Running state [/etc/maas/rackd.conf] at time 21:19:51.624693
2019-08-27 21:19:51,624 [salt.state       :1813][INFO    ][15624] Executing state file.managed for [/etc/maas/rackd.conf]
2019-08-27 21:19:51,625 [salt.loaded.int.states.file:2298][WARNING ][15624] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-08-27 21:19:51,625 [salt.state       :300 ][INFO    ][15624] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-08-27 21:19:51,625 [salt.state       :1951][INFO    ][15624] Completed state [/etc/maas/rackd.conf] at time 21:19:51.625691 duration_in_ms=0.997
2019-08-27 21:19:51,626 [salt.state       :1780][INFO    ][15624] Running state [maas-rackd] at time 21:19:51.626450
2019-08-27 21:19:51,626 [salt.state       :1813][INFO    ][15624] Executing state service.running for [maas-rackd]
2019-08-27 21:19:51,627 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15624] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:51,658 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15624] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-08-27 21:19:51,673 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15624] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-08-27 21:19:51,688 [salt.state       :300 ][INFO    ][15624] The service maas-rackd is already running
2019-08-27 21:19:51,688 [salt.state       :1951][INFO    ][15624] Completed state [maas-rackd] at time 21:19:51.688636 duration_in_ms=62.186
2019-08-27 21:19:51,689 [salt.minion      :1711][INFO    ][15624] Returning information for job: 20190827211950120741
2019-08-27 21:19:52,282 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827211952269975
2019-08-27 21:19:52,303 [salt.minion      :1432][INFO    ][15655] Starting a new job with PID 15655
2019-08-27 21:19:52,988 [salt.state       :915 ][INFO    ][15655] Loading fresh modules for state activity
2019-08-27 21:19:53,682 [salt.state       :1780][INFO    ][15655] Running state [maas-region-controller] at time 21:19:53.682217
2019-08-27 21:19:53,682 [salt.state       :1813][INFO    ][15655] Executing state pkg.installed for [maas-region-controller]
2019-08-27 21:19:53,683 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-27 21:19:53,780 [salt.state       :300 ][INFO    ][15655] All specified packages are already installed
2019-08-27 21:19:53,780 [salt.state       :1951][INFO    ][15655] Completed state [maas-region-controller] at time 21:19:53.780746 duration_in_ms=98.529
2019-08-27 21:19:53,781 [salt.state       :1780][INFO    ][15655] Running state [python-oauth] at time 21:19:53.781117
2019-08-27 21:19:53,781 [salt.state       :1813][INFO    ][15655] Executing state pkg.installed for [python-oauth]
2019-08-27 21:19:53,788 [salt.state       :300 ][INFO    ][15655] All specified packages are already installed
2019-08-27 21:19:53,789 [salt.state       :1951][INFO    ][15655] Completed state [python-oauth] at time 21:19:53.789000 duration_in_ms=7.883
2019-08-27 21:19:53,792 [salt.state       :1780][INFO    ][15655] Running state [/etc/maas/regiond.conf] at time 21:19:53.792420
2019-08-27 21:19:53,792 [salt.state       :1813][INFO    ][15655] Executing state file.replace for [/etc/maas/regiond.conf]
2019-08-27 21:19:53,827 [salt.state       :300 ][INFO    ][15655] No changes needed to be made
2019-08-27 21:19:53,827 [salt.state       :1951][INFO    ][15655] Completed state [/etc/maas/regiond.conf] at time 21:19:53.827780 duration_in_ms=35.359
2019-08-27 21:19:53,828 [salt.state       :1780][INFO    ][15655] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:53.828585
2019-08-27 21:19:53,829 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-08-27 21:19:53,910 [salt.state       :300 ][INFO    ][15655] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-08-27 21:19:53,910 [salt.state       :1951][INFO    ][15655] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:53.910531 duration_in_ms=81.947
2019-08-27 21:19:53,911 [salt.state       :1780][INFO    ][15655] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:53.911188
2019-08-27 21:19:53,911 [salt.state       :1813][INFO    ][15655] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-27 21:19:53,930 [salt.state       :300 ][INFO    ][15655] No changes needed to be made
2019-08-27 21:19:53,930 [salt.state       :1951][INFO    ][15655] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:53.930316 duration_in_ms=19.129
2019-08-27 21:19:53,931 [salt.state       :1780][INFO    ][15655] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:53.930970
2019-08-27 21:19:53,931 [salt.state       :1813][INFO    ][15655] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-27 21:19:53,953 [salt.state       :300 ][INFO    ][15655] No changes needed to be made
2019-08-27 21:19:53,954 [salt.state       :1951][INFO    ][15655] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:53.954173 duration_in_ms=23.202
2019-08-27 21:19:53,954 [salt.state       :1780][INFO    ][15655] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:53.954810
2019-08-27 21:19:53,955 [salt.state       :1813][INFO    ][15655] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-08-27 21:19:53,985 [salt.state       :300 ][INFO    ][15655] No changes needed to be made
2019-08-27 21:19:53,985 [salt.state       :1951][INFO    ][15655] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:53.985289 duration_in_ms=30.48
2019-08-27 21:19:53,985 [salt.state       :1780][INFO    ][15655] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:53.985851
2019-08-27 21:19:53,986 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-08-27 21:19:53,998 [salt.state       :300 ][INFO    ][15655] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-08-27 21:19:53,998 [salt.state       :1951][INFO    ][15655] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:53.998769 duration_in_ms=12.919
2019-08-27 21:19:54,000 [salt.state       :1780][INFO    ][15655] Running state [a2enmod headers] at time 21:19:54.000164
2019-08-27 21:19:54,000 [salt.state       :1813][INFO    ][15655] Executing state cmd.run for [a2enmod headers]
2019-08-27 21:19:54,001 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command 'a2enmod headers' in directory '/root'
2019-08-27 21:19:54,076 [salt.state       :300 ][INFO    ][15655] {'pid': 15682, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-08-27 21:19:54,076 [salt.state       :1951][INFO    ][15655] Completed state [a2enmod headers] at time 21:19:54.076857 duration_in_ms=76.691
2019-08-27 21:19:54,077 [salt.state       :1780][INFO    ][15655] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:54.077442
2019-08-27 21:19:54,078 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-08-27 21:19:54,100 [salt.state       :300 ][INFO    ][15655] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-08-27 21:19:54,101 [salt.state       :1951][INFO    ][15655] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:54.101600 duration_in_ms=24.144
2019-08-27 21:19:54,102 [salt.state       :1780][INFO    ][15655] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:54.102815
2019-08-27 21:19:54,103 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-08-27 21:19:54,179 [salt.state       :300 ][INFO    ][15655] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-08-27 21:19:54,180 [salt.state       :1951][INFO    ][15655] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:54.180200 duration_in_ms=77.384
2019-08-27 21:19:54,180 [salt.state       :1780][INFO    ][15655] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:54.180828
2019-08-27 21:19:54,181 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-08-27 21:19:54,239 [salt.state       :300 ][INFO    ][15655] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-08-27 21:19:54,239 [salt.state       :1951][INFO    ][15655] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:54.239879 duration_in_ms=59.05
2019-08-27 21:19:54,240 [salt.state       :1780][INFO    ][15655] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:54.240412
2019-08-27 21:19:54,240 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-08-27 21:19:54,299 [salt.state       :300 ][INFO    ][15655] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-08-27 21:19:54,299 [salt.state       :1951][INFO    ][15655] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:54.299776 duration_in_ms=59.365
2019-08-27 21:19:54,300 [salt.state       :1780][INFO    ][15655] Running state [/root/.pgpass] at time 21:19:54.300072
2019-08-27 21:19:54,300 [salt.state       :1813][INFO    ][15655] Executing state file.managed for [/root/.pgpass]
2019-08-27 21:19:54,341 [salt.state       :300 ][INFO    ][15655] File /root/.pgpass is in the correct state
2019-08-27 21:19:54,341 [salt.state       :1951][INFO    ][15655] Completed state [/root/.pgpass] at time 21:19:54.341659 duration_in_ms=41.587
2019-08-27 21:19:54,346 [salt.state       :1780][INFO    ][15655] Running state [maas-region syncdb --noinput] at time 21:19:54.346943
2019-08-27 21:19:54,347 [salt.state       :1813][INFO    ][15655] Executing state cmd.run for [maas-region syncdb --noinput]
2019-08-27 21:19:54,348 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-08-27 21:19:56,274 [salt.state       :300 ][INFO    ][15655] {'pid': 15695, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: auth, maasserver, piston3, metadataserver, sessions, sites, contenttypes\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-08-27 21:19:56,275 [salt.state       :1951][INFO    ][15655] Completed state [maas-region syncdb --noinput] at time 21:19:56.275042 duration_in_ms=1928.099
2019-08-27 21:19:56,275 [salt.state       :2022][WARNING ][15655] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-27 21:19:56,276 [salt.state       :1780][INFO    ][15655] Running state [maas-regiond] at time 21:19:56.276246
2019-08-27 21:19:56,276 [salt.state       :1813][INFO    ][15655] Executing state service.running for [maas-regiond]
2019-08-27 21:19:56,277 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:56,310 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-08-27 21:19:56,326 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-08-27 21:19:56,341 [salt.state       :300 ][INFO    ][15655] The service maas-regiond is already running
2019-08-27 21:19:56,342 [salt.state       :1951][INFO    ][15655] Completed state [maas-regiond] at time 21:19:56.342033 duration_in_ms=65.787
2019-08-27 21:19:56,343 [salt.state       :1780][INFO    ][15655] Running state [bind9] at time 21:19:56.343136
2019-08-27 21:19:56,343 [salt.state       :1813][INFO    ][15655] Executing state service.running for [bind9]
2019-08-27 21:19:56,343 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:56,361 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-08-27 21:19:56,376 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-08-27 21:19:56,392 [salt.state       :300 ][INFO    ][15655] The service bind9 is already running
2019-08-27 21:19:56,392 [salt.state       :1951][INFO    ][15655] Completed state [bind9] at time 21:19:56.392303 duration_in_ms=49.168
2019-08-27 21:19:56,393 [salt.state       :1780][INFO    ][15655] Running state [apache2] at time 21:19:56.393499
2019-08-27 21:19:56,393 [salt.state       :1813][INFO    ][15655] Executing state service.running for [apache2]
2019-08-27 21:19:56,394 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-08-27 21:19:56,410 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-08-27 21:19:56,425 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-08-27 21:19:56,444 [salt.state       :300 ][INFO    ][15655] The service apache2 is already running
2019-08-27 21:19:56,444 [salt.state       :1951][INFO    ][15655] Completed state [apache2] at time 21:19:56.444689 duration_in_ms=51.19
2019-08-27 21:19:56,445 [salt.state       :1780][INFO    ][15655] Running state [maasng.wait_for_http_code] at time 21:19:56.445769
2019-08-27 21:19:56,446 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maasng.wait_for_http_code]
2019-08-27 21:19:56,446 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:19:56,451 [salt.state       :300 ][INFO    ][15655] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-08-27 21:19:56,452 [salt.state       :1951][INFO    ][15655] Completed state [maasng.wait_for_http_code] at time 21:19:56.452106 duration_in_ms=6.337
2019-08-27 21:19:56,452 [salt.state       :1780][INFO    ][15655] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:56.452711
2019-08-27 21:19:56,452 [salt.state       :1813][INFO    ][15655] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-08-27 21:19:56,453 [salt.state       :300 ][INFO    ][15655] /var/lib/maas/.setup_admin exists
2019-08-27 21:19:56,453 [salt.state       :1951][INFO    ][15655] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:56.453456 duration_in_ms=0.745
2019-08-27 21:19:56,454 [salt.state       :1780][INFO    ][15655] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:56.454012
2019-08-27 21:19:56,454 [salt.state       :1813][INFO    ][15655] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:19:56,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15655] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:19:57,867 [salt.state       :300 ][INFO    ][15655] {'pid': 15714, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:19:57,867 [salt.state       :1951][INFO    ][15655] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:57.867527 duration_in_ms=1413.515
2019-08-27 21:19:57,870 [salt.state       :1780][INFO    ][15655] Running state [maas_region_boot_source_resources_mirror] at time 21:19:57.870807
2019-08-27 21:19:57,871 [salt.state       :1813][INFO    ][15655] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-08-27 21:19:57,976 [salt.state       :300 ][INFO    ][15655] {'changes': {}}
2019-08-27 21:19:57,976 [salt.state       :1951][INFO    ][15655] Completed state [maas_region_boot_source_resources_mirror] at time 21:19:57.976773 duration_in_ms=105.965
2019-08-27 21:19:57,977 [salt.state       :1780][INFO    ][15655] Running state [maasng.boot_resources_import] at time 21:19:57.977823
2019-08-27 21:19:57,978 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maasng.boot_resources_import]
2019-08-27 21:19:57,978 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:19:58,090 [salt.loaded.ext.module.maasng:1600][INFO    ][15655] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-08-27 21:20:03,149 [salt.loaded.ext.module.maasng:1600][INFO    ][15655] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-08-27 21:20:07,368 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212007356392
2019-08-27 21:20:07,386 [salt.minion      :1432][INFO    ][15780] Starting a new job with PID 15780
2019-08-27 21:20:07,407 [salt.minion      :1711][INFO    ][15780] Returning information for job: 20190827212007356392
2019-08-27 21:20:08,207 [salt.loaded.ext.module.maasng:1600][INFO    ][15655] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-08-27 21:20:13,319 [salt.state       :300 ][INFO    ][15655] {'ret': True}
2019-08-27 21:20:13,320 [salt.state       :1951][INFO    ][15655] Completed state [maasng.boot_resources_import] at time 21:20:13.320106 duration_in_ms=15342.282
2019-08-27 21:20:13,321 [salt.state       :1780][INFO    ][15655] Running state [maas_region_boot_sources_selection_xenial] at time 21:20:13.321351
2019-08-27 21:20:13,321 [salt.state       :1813][INFO    ][15655] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-08-27 21:20:13,534 [salt.state       :300 ][INFO    ][15655] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-08-27 21:20:13,535 [salt.state       :1951][INFO    ][15655] Completed state [maas_region_boot_sources_selection_xenial] at time 21:20:13.535172 duration_in_ms=213.82
2019-08-27 21:20:13,536 [salt.state       :1780][INFO    ][15655] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:13.536481
2019-08-27 21:20:13,537 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-08-27 21:20:13,537 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:20:13,538 [salt.loaded.ext.module.maasng:1771][INFO    ][15655] boot-sources sync initiated for ALL Rack's
2019-08-27 21:20:14,565 [salt.state       :300 ][INFO    ][15655] {'ret': True}
2019-08-27 21:20:14,566 [salt.state       :1951][INFO    ][15655] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:14.566201 duration_in_ms=1029.72
2019-08-27 21:20:14,568 [salt.state       :1780][INFO    ][15655] Running state [maas.process_maas_config] at time 21:20:14.568377
2019-08-27 21:20:14,568 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maas.process_maas_config]
2019-08-27 21:20:14,569 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:20:14,570 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=enable_http_proxy value=True
2019-08-27 21:20:14,632 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=upstream_dns value=8.8.8.8
2019-08-27 21:20:14,696 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=commissioning_distro_series value=xenial
2019-08-27 21:20:14,771 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=default_osystem value=ubuntu
2019-08-27 21:20:17,741 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=active_discovery_interval value=600
2019-08-27 21:20:17,808 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=dnssec_validation value=no
2019-08-27 21:20:17,868 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=maas_name value=mas01
2019-08-27 21:20:17,921 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=network_discovery value=enabled
2019-08-27 21:20:18,029 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=enable_third_party_drivers value=True
2019-08-27 21:20:18,091 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=default_storage_layout value=lvm
2019-08-27 21:20:18,146 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=ntp_external_only value=True
2019-08-27 21:20:18,194 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=disk_erase_with_secure_erase value=False
2019-08-27 21:20:18,242 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=default_distro_series value=xenial
2019-08-27 21:20:18,296 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-08-27 21:20:18,410 [salt.state       :300 ][INFO    ][15655] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-08-27 21:20:18,410 [salt.state       :1951][INFO    ][15655] Completed state [maas.process_maas_config] at time 21:20:18.410782 duration_in_ms=3842.405
2019-08-27 21:20:18,411 [salt.state       :1780][INFO    ][15655] Running state [pxe_admin] at time 21:20:18.411380
2019-08-27 21:20:18,411 [salt.state       :1813][INFO    ][15655] Executing state maasng.fabric_present for [pxe_admin]
2019-08-27 21:20:18,472 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-08-27 21:20:18,569 [salt.loaded.ext.module.maasng:1008][WARNING ][15655] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-08-27 21:20:18,569 [salt.loaded.ext.module.maasng:1011][WARNING ][15655] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-08-27 21:20:18,640 [salt.state       :300 ][INFO    ][15655] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-08-27 21:20:18,641 [salt.state       :1951][INFO    ][15655] Completed state [pxe_admin] at time 21:20:18.641276 duration_in_ms=229.895
2019-08-27 21:20:18,641 [salt.state       :1780][INFO    ][15655] Running state [vlan 0] at time 21:20:18.641782
2019-08-27 21:20:18,642 [salt.state       :1813][INFO    ][15655] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-27 21:20:18,713 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/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'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'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'primary_rack': u'7bmbbp', 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'}]
2019-08-27 21:20:18,838 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/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'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'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'primary_rack': u'7bmbbp', 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'}]
2019-08-27 21:20:19,086 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-08-27 21:20:19,170 [salt.state       :300 ][INFO    ][15655] {'new': 'Vlan untagged was updated'}
2019-08-27 21:20:19,171 [salt.state       :1951][INFO    ][15655] Completed state [vlan 0] at time 21:20:19.171214 duration_in_ms=529.431
2019-08-27 21:20:19,172 [salt.state       :1780][INFO    ][15655] Running state [192.168.11.0/24] at time 21:20:19.172348
2019-08-27 21:20:19,172 [salt.state       :1813][INFO    ][15655] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-08-27 21:20:19,431 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0'}, {u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/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'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'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'primary_rack': u'7bmbbp', 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'}]
2019-08-27 21:20:19,432 [salt.loaded.ext.module.maasng:1235][WARNING ][15655] Ignoring parameter vlan:0
2019-08-27 21:20:19,515 [salt.state       :300 ][INFO    ][15655] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-08-27 21:20:19,516 [salt.state       :1951][INFO    ][15655] Completed state [192.168.11.0/24] at time 21:20:19.516137 duration_in_ms=343.788
2019-08-27 21:20:19,517 [salt.state       :1780][INFO    ][15655] Running state [maas_create_iprange_1] at time 21:20:19.517554
2019-08-27 21:20:19,518 [salt.state       :1813][INFO    ][15655] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-08-27 21:20:19,593 [salt.state       :300 ][INFO    ][15655] Iprange maas_create_iprange_1 already exist.
2019-08-27 21:20:19,594 [salt.state       :1951][INFO    ][15655] Completed state [maas_create_iprange_1] at time 21:20:19.594002 duration_in_ms=76.448
2019-08-27 21:20:19,594 [salt.state       :1780][INFO    ][15655] Running state [vlan 0] at time 21:20:19.594398
2019-08-27 21:20:19,594 [salt.state       :1813][INFO    ][15655] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-27 21:20:19,646 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, 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'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'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'7bmbbp', 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'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-08-27 21:20:19,778 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-08-27 21:20:19,997 [salt.loaded.ext.module.maasng:945 ][INFO    ][15655] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-08-27 21:20:20,085 [salt.state       :300 ][INFO    ][15655] {'new': 'Vlan untagged was updated'}
2019-08-27 21:20:20,085 [salt.state       :1951][INFO    ][15655] Completed state [vlan 0] at time 21:20:20.085821 duration_in_ms=491.421
2019-08-27 21:20:20,086 [salt.state       :1780][INFO    ][15655] Running state [opnfv] at time 21:20:20.086805
2019-08-27 21:20:20,087 [salt.state       :1813][INFO    ][15655] Executing state maasng.sshkey_present for [opnfv]
2019-08-27 21:20:20,140 [salt.loaded.ext.module.maasng:1903][INFO    ][15655] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-08-27 21:20:20,141 [salt.state       :300 ][INFO    ][15655] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-08-27 21:20:20,141 [salt.state       :1951][INFO    ][15655] Completed state [opnfv] at time 21:20:20.141457 duration_in_ms=54.651
2019-08-27 21:20:20,142 [salt.state       :1780][INFO    ][15655] Running state [maas.process_tags] at time 21:20:20.142363
2019-08-27 21:20:20,142 [salt.state       :1813][INFO    ][15655] Executing state module.run for [maas.process_tags]
2019-08-27 21:20:20,143 [salt.utils.decorators:613 ][WARNING ][15655] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:20:20,200 [salt.loaded.ext.module.maas:92  ][INFO    ][15655] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-08-27 21:20:20,276 [salt.state       :300 ][INFO    ][15655] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-08-27 21:20:20,277 [salt.state       :1951][INFO    ][15655] Completed state [maas.process_tags] at time 21:20:20.277227 duration_in_ms=134.864
2019-08-27 21:20:20,281 [salt.minion      :1711][INFO    ][15655] Returning information for job: 20190827211952269975
2019-08-27 21:20:20,890 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827212020876751
2019-08-27 21:20:20,912 [salt.minion      :1432][INFO    ][16164] Starting a new job with PID 16164
2019-08-27 21:20:24,477 [salt.state       :915 ][INFO    ][16164] Loading fresh modules for state activity
2019-08-27 21:20:24,527 [salt.state       :1780][INFO    ][16164] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:24.527574
2019-08-27 21:20:24,527 [salt.state       :1813][INFO    ][16164] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:20:24,529 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16164] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:20:25,863 [salt.state       :300 ][INFO    ][16164] {'pid': 16187, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:20:25,864 [salt.state       :1951][INFO    ][16164] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:25.864306 duration_in_ms=1336.732
2019-08-27 21:20:25,865 [salt.state       :1780][INFO    ][16164] Running state [maas.process_machines] at time 21:20:25.865424
2019-08-27 21:20:25,865 [salt.state       :1813][INFO    ][16164] Executing state module.run for [maas.process_machines]
2019-08-27 21:20:25,866 [salt.utils.decorators:613 ][WARNING ][16164] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:20:26,419 [salt.loaded.ext.module.maas:412 ][WARNING ][16164] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:20:26,420 [salt.loaded.ext.module.maas:92  ][INFO    ][16164] machine hostname=gtw01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=gbrham architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:20:27,732 [salt.loaded.ext.module.maas:412 ][WARNING ][16164] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:20:27,733 [salt.loaded.ext.module.maas:92  ][INFO    ][16164] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=cm3e6x architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:20:28,966 [salt.loaded.ext.module.maas:412 ][WARNING ][16164] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:20:28,967 [salt.loaded.ext.module.maas:92  ][INFO    ][16164] machine hostname=odl01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=xrbdga architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:20:29,951 [salt.loaded.ext.module.maas:412 ][WARNING ][16164] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:20:29,952 [salt.loaded.ext.module.maas:92  ][INFO    ][16164] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=7qknxq architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:20:31,256 [salt.loaded.ext.module.maas:412 ][WARNING ][16164] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:20:31,257 [salt.loaded.ext.module.maas:92  ][INFO    ][16164] machine hostname=ctl01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=nw43wx architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:20:32,272 [salt.state       :300 ][INFO    ][16164] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-08-27 21:20:32,272 [salt.state       :1951][INFO    ][16164] Completed state [maas.process_machines] at time 21:20:32.272761 duration_in_ms=6407.335
2019-08-27 21:20:32,276 [salt.minion      :1711][INFO    ][16164] Returning information for job: 20190827212020876751
2019-08-27 21:21:03,315 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827212103303119
2019-08-27 21:21:03,337 [salt.minion      :1432][INFO    ][16428] Starting a new job with PID 16428
2019-08-27 21:21:07,077 [salt.state       :915 ][INFO    ][16428] Loading fresh modules for state activity
2019-08-27 21:21:07,160 [salt.state       :1780][INFO    ][16428] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:07.160755
2019-08-27 21:21:07,161 [salt.state       :1813][INFO    ][16428] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:21:07,163 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16428] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:21:08,753 [salt.state       :300 ][INFO    ][16428] {'pid': 16435, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:21:08,753 [salt.state       :1951][INFO    ][16428] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:08.753765 duration_in_ms=1593.01
2019-08-27 21:21:08,756 [salt.state       :1780][INFO    ][16428] Running state [maas.wait_for_machine_status] at time 21:21:08.756872
2019-08-27 21:21:08,757 [salt.state       :1813][INFO    ][16428] Executing state module.run for [maas.wait_for_machine_status]
2019-08-27 21:21:08,758 [salt.utils.decorators:613 ][WARNING ][16428] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:21:10,271 [salt.loaded.ext.module.maas:981 ][INFO    ][16428] Machine xrbdga deleted
2019-08-27 21:21:11,059 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:11,060 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=gtw01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=gbrham architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:11,904 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:11,905 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=cm3e6x architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:13,056 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:13,056 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=odl01 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:14,408 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:14,409 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=7qknxq architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:15,687 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:15,687 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=ctl01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=nw43wx architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:17,660 [salt.loaded.ext.module.maas:981 ][INFO    ][16428] Machine nw43wx deleted
2019-08-27 21:21:18,359 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:18,359 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=gtw01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=gbrham architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:18,368 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212118358332
2019-08-27 21:21:18,382 [salt.minion      :1432][INFO    ][16738] Starting a new job with PID 16738
2019-08-27 21:21:18,400 [salt.minion      :1711][INFO    ][16738] Returning information for job: 20190827212118358332
2019-08-27 21:21:19,277 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:19,278 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=cm3e6x architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:20,534 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:20,535 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=odl01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=prfkwe architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:21,377 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:21,378 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=7qknxq architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:22,685 [salt.loaded.ext.module.maas:412 ][WARNING ][16428] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-27 21:21:22,686 [salt.loaded.ext.module.maas:92  ][INFO    ][16428] machine hostname=ctl01 power_type=ipmi mac_addresses=00:25:b5:a0:00:2a power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-08-27 21:21:24,123 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1484.64478803s left)
2019-08-27 21:21:48,406 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212148394030
2019-08-27 21:21:48,426 [salt.minion      :1432][INFO    ][16995] Starting a new job with PID 16995
2019-08-27 21:21:48,447 [salt.minion      :1711][INFO    ][16995] Returning information for job: 20190827212148394030
2019-08-27 21:21:56,863 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1451.90488315s left)
2019-08-27 21:22:18,478 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212218466339
2019-08-27 21:22:18,500 [salt.minion      :1432][INFO    ][17062] Starting a new job with PID 17062
2019-08-27 21:22:18,524 [salt.minion      :1711][INFO    ][17062] Returning information for job: 20190827212218466339
2019-08-27 21:22:29,528 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1419.23958898s left)
2019-08-27 21:22:48,527 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212248514182
2019-08-27 21:22:48,550 [salt.minion      :1432][INFO    ][17095] Starting a new job with PID 17095
2019-08-27 21:22:48,575 [salt.minion      :1711][INFO    ][17095] Returning information for job: 20190827212248514182
2019-08-27 21:23:01,577 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1387.19049811s left)
2019-08-27 21:23:18,579 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212318567047
2019-08-27 21:23:18,598 [salt.minion      :1432][INFO    ][17287] Starting a new job with PID 17287
2019-08-27 21:23:18,621 [salt.minion      :1711][INFO    ][17287] Returning information for job: 20190827212318567047
2019-08-27 21:23:34,101 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1354.66704702s left)
2019-08-27 21:23:48,624 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212348611221
2019-08-27 21:23:48,647 [salt.minion      :1432][INFO    ][17367] Starting a new job with PID 17367
2019-08-27 21:23:48,670 [salt.minion      :1711][INFO    ][17367] Returning information for job: 20190827212348611221
2019-08-27 21:24:06,666 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['odl01', 'ctl01']
sleep for:30s Timeout:1500s (1322.10168505s left)
2019-08-27 21:24:18,680 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212418667384
2019-08-27 21:24:18,703 [salt.minion      :1432][INFO    ][17609] Starting a new job with PID 17609
2019-08-27 21:24:18,726 [salt.minion      :1711][INFO    ][17609] Returning information for job: 20190827212418667384
2019-08-27 21:24:39,825 [salt.loaded.ext.module.maas:1023][INFO    ][16428] Waiting status:Ready|Deployed for machines:['ctl01']
sleep for:30s Timeout:1500s (1288.94309711s left)
2019-08-27 21:24:48,742 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212448730440
2019-08-27 21:24:48,765 [salt.minion      :1432][INFO    ][17711] Starting a new job with PID 17711
2019-08-27 21:24:48,790 [salt.minion      :1711][INFO    ][17711] Returning information for job: 20190827212448730440
2019-08-27 21:25:12,967 [salt.state       :300 ][INFO    ][16428] {'ret': True}
2019-08-27 21:25:12,968 [salt.state       :1951][INFO    ][16428] Completed state [maas.wait_for_machine_status] at time 21:25:12.968303 duration_in_ms=244211.43
2019-08-27 21:25:12,972 [salt.minion      :1711][INFO    ][16428] Returning information for job: 20190827212103303119
2019-08-27 21:25:13,611 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827212513598170
2019-08-27 21:25:13,633 [salt.minion      :1432][INFO    ][17793] Starting a new job with PID 17793
2019-08-27 21:25:17,276 [salt.state       :915 ][INFO    ][17793] Loading fresh modules for state activity
2019-08-27 21:25:17,329 [salt.fileclient  :1219][INFO    ][17793] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-08-27 21:25:17,415 [salt.state       :1780][INFO    ][17793] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:17.415094
2019-08-27 21:25:17,415 [salt.state       :1813][INFO    ][17793] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:25:17,416 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17793] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:25:18,909 [salt.state       :300 ][INFO    ][17793] {'pid': 17801, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:25:18,910 [salt.state       :1951][INFO    ][17793] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:18.910099 duration_in_ms=1495.004
2019-08-27 21:25:18,913 [salt.state       :1780][INFO    ][17793] Running state [maas_machines_storage_cmp002_lvm] at time 21:25:18.913338
2019-08-27 21:25:18,913 [salt.state       :1813][INFO    ][17793] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-08-27 21:25:20,194 [salt.loaded.ext.module.maasng:610 ][INFO    ][17793] cm3e6x
2019-08-27 21:25:20,195 [salt.loaded.ext.module.maasng:626 ][INFO    ][17793] sda
2019-08-27 21:25:20,854 [salt.loaded.ext.module.maasng:361 ][INFO    ][17793] cm3e6x
2019-08-27 21:25:20,987 [salt.loaded.ext.module.maasng:367 ][INFO    ][17793] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cm3e6x', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'uuid': u'e0592759-8b56-4f6f-b973-00738a951a25', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm3e6x', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'd99da1b2-f3db-44ee-80bb-799964039c76', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/partition/2', u'type': u'partition', u'id': 2, u'size': 2397992648704}]}, {u'size': 2397988454400, u'model': None, u'block_size': 4096, u'uuid': u'4405ac83-ff3c-4f30-9659-602daa2403fa', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'df54e296-78b1-4b88-984e-5c338bc7b21d', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cm3e6x', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/6/', u'used_size': 2397988454400, u'id': 6, u'partitions': []}]
2019-08-27 21:25:20,988 [salt.loaded.ext.module.maasng:632 ][INFO    ][17793] vgroot
2019-08-27 21:25:20,988 [salt.loaded.ext.module.maasng:635 ][INFO    ][17793] lvroot
2019-08-27 21:25:20,988 [salt.loaded.ext.module.maasng:639 ][INFO    ][17793] 107374182400
2019-08-27 21:25:21,546 [salt.loaded.ext.module.maasng:645 ][INFO    ][17793] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'ip_addresses': [], u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'fqdn': u'cmp002.maas', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'address_ttl': None, u'system_id': u'cm3e6x', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'physicalblockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/', u'type': u'physical', u'id': 4, u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cm3e6x', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'12b1d8f9-2964-4471-9a94-73dc2554eac2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm3e6x', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9035fe5e-294a-4c5b-ab1a-79734d9f0956', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}]}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cm3e6x', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'uuid': u'12b1d8f9-2964-4471-9a94-73dc2554eac2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm3e6x', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9035fe5e-294a-4c5b-ab1a-79734d9f0956', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}]}, {u'size': 107374182400, u'model': None, u'block_size': 4096, u'uuid': u'afed1df3-d46e-489f-9d94-e046e0f7ee8a', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'62ab1e28-310b-4fac-b8be-f2f67a5f79cf', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cm3e6x', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/12/', u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cm3e6x', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/', u'type': u'physical', u'id': 4, u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cm3e6x', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'12b1d8f9-2964-4471-9a94-73dc2554eac2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cm3e6x', u'device_id': 4, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9035fe5e-294a-4c5b-ab1a-79734d9f0956', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/4/partition/6', u'type': u'partition', u'id': 6, u'size': 2397992648704}]}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'disable_ipv4': False, u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'afed1df3-d46e-489f-9d94-e046e0f7ee8a', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/blockdevices/12/', u'type': u'virtual', u'id': 12, u'tags': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'62ab1e28-310b-4fac-b8be-f2f67a5f79cf', u'fstype': u'ext4'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cm3e6x', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'7bmbbp', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 21}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'7bmbbp', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [], u'system_id': u'cm3e6x', u'mac_address': u'00:25:b5:a0:00:6a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/interfaces/5/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'7bmbbp', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 21}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'7bmbbp', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': [], u'system_id': u'cm3e6x', u'mac_address': u'00:25:b5:a0:00:6a', u'id': 5, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 22}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cm3e6x', u'mac_address': u'00:25:b5:a0:00:6c', u'id': 12, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/interfaces/12/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 23}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cm3e6x', u'mac_address': u'00:25:b5:a0:00:6d', u'id': 13, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/interfaces/13/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 24}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'parents': [], u'discovered': None, u'system_id': u'cm3e6x', u'mac_address': u'00:25:b5:a0:00:6b', u'id': 14, u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cm3e6x/interfaces/14/'}], u'commissioning_status_name': u'Passed', u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/cm3e6x/'}
2019-08-27 21:25:21,548 [salt.state       :300 ][INFO    ][17793] {'new': {'storage_layout': 'lvm'}}
2019-08-27 21:25:21,549 [salt.state       :1951][INFO    ][17793] Completed state [maas_machines_storage_cmp002_lvm] at time 21:25:21.548935 duration_in_ms=2635.595
2019-08-27 21:25:21,549 [salt.state       :1780][INFO    ][17793] Running state [maas_machines_storage_cmp001_lvm] at time 21:25:21.549522
2019-08-27 21:25:21,550 [salt.state       :1813][INFO    ][17793] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-08-27 21:25:22,855 [salt.loaded.ext.module.maasng:610 ][INFO    ][17793] 7qknxq
2019-08-27 21:25:22,856 [salt.loaded.ext.module.maasng:626 ][INFO    ][17793] sda
2019-08-27 21:25:23,520 [salt.loaded.ext.module.maasng:361 ][INFO    ][17793] 7qknxq
2019-08-27 21:25:23,659 [salt.loaded.ext.module.maasng:367 ][INFO    ][17793] [{u'size': 2397998940160, u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'7qknxq', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/', u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'abcf403f-505c-4299-853b-8bfd0e4d253f', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/partition/1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7qknxq', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'474ddc75-b596-4adb-9b60-fc6bed14973c', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 1, u'size': 2397992648704}]}, {u'size': 2397988454400, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 5, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c8e93350-d80b-4c48-80cc-fdedb5d7c1ea', u'fstype': u'ext4'}, u'uuid': u'030062a4-1328-4c4d-b29b-cfa07d26f622', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'7qknxq', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/5/', u'used_size': 2397988454400, u'serial': None, u'partitions': []}]
2019-08-27 21:25:23,660 [salt.loaded.ext.module.maasng:632 ][INFO    ][17793] vgroot
2019-08-27 21:25:23,660 [salt.loaded.ext.module.maasng:635 ][INFO    ][17793] lvroot
2019-08-27 21:25:23,660 [salt.loaded.ext.module.maasng:639 ][INFO    ][17793] 107374182400
2019-08-27 21:25:24,390 [salt.loaded.ext.module.maasng:645 ][INFO    ][17793] {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'cpu_count': 16, 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'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default', u'id': 1}, u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'7qknxq', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'block_size': 4096, u'uuid': u'9a509bcb-b7f6-4267-9647-1ae6c719d482', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'7f8800ba-214e-466e-98a2-b0f6ea4a0d38'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'7qknxq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'size': 107374182400, u'type': u'virtual', u'id': 13, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/13/'}], u'blockdevice_set': [{u'size': 2397998940160, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'6f26d173-812f-44f0-8879-7d62fc39211d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7qknxq', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'57fdfe84-62df-4fe3-a988-928911940ce4'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'device_id': 3}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'7qknxq', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 3, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/'}, {u'size': 107374182400, u'uuid': u'9a509bcb-b7f6-4267-9647-1ae6c719d482', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'uuid': u'7f8800ba-214e-466e-98a2-b0f6ea4a0d38'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'7qknxq', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 13, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/13/'}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'6f26d173-812f-44f0-8879-7d62fc39211d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7qknxq', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'57fdfe84-62df-4fe3-a988-928911940ce4'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'device_id': 3}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'7qknxq', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 3, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'7qknxq', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 8, u'boot_disk': {u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'6f26d173-812f-44f0-8879-7d62fc39211d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7qknxq', u'filesystem': {u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'uuid': u'57fdfe84-62df-4fe3-a988-928911940ce4'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'device_id': 3}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'7qknxq', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 3, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/blockdevices/3/'}, u'current_testing_result_id': 9, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', 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': 16, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'children': [], u'discovered': [], u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'7qknxq', u'type': u'physical', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/interfaces/7/'}, u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'7bmbbp', 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': 16, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', u'enabled': True, u'children': [], u'discovered': [], u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'7qknxq', u'type': u'physical', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/interfaces/7/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'id': 20, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'7qknxq', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/interfaces/11/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'id': 17, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'7qknxq', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/interfaces/9/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'7qknxq', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/7qknxq/interfaces/10/'}], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/7qknxq/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-08-27 21:25:24,392 [salt.state       :300 ][INFO    ][17793] {'new': {'storage_layout': 'lvm'}}
2019-08-27 21:25:24,392 [salt.state       :1951][INFO    ][17793] Completed state [maas_machines_storage_cmp001_lvm] at time 21:25:24.392622 duration_in_ms=2843.099
2019-08-27 21:25:24,396 [salt.minion      :1711][INFO    ][17793] Returning information for job: 20190827212513598170
2019-08-27 21:25:24,940 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827212524929322
2019-08-27 21:25:24,956 [salt.minion      :1432][INFO    ][17819] Starting a new job with PID 17819
2019-08-27 21:25:25,562 [salt.state       :915 ][INFO    ][17819] Loading fresh modules for state activity
2019-08-27 21:25:25,613 [salt.fileclient  :1219][INFO    ][17819] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-08-27 21:25:25,649 [salt.state       :1780][INFO    ][17819] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:25.649897
2019-08-27 21:25:25,650 [salt.state       :1813][INFO    ][17819] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:25:25,651 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17819] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:25:26,931 [salt.state       :300 ][INFO    ][17819] {'pid': 17826, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:25:26,931 [salt.state       :1951][INFO    ][17819] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:26.931696 duration_in_ms=1281.799
2019-08-27 21:25:26,933 [salt.state       :1780][INFO    ][17819] Running state [maas.deploy_machines] at time 21:25:26.933380
2019-08-27 21:25:26,933 [salt.state       :1813][INFO    ][17819] Executing state module.run for [maas.deploy_machines]
2019-08-27 21:25:26,934 [salt.utils.decorators:613 ][WARNING ][17819] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:25:27,407 [salt.loaded.ext.module.maas:684 ][INFO    ][17819] deploymachines hwe_kernel=hwe-16.04 system_id=gbrham distro_series=xenial
2019-08-27 21:25:29,232 [salt.loaded.ext.module.maas:684 ][INFO    ][17819] deploymachines hwe_kernel=hwe-16.04 system_id=cm3e6x distro_series=xenial
2019-08-27 21:25:31,345 [salt.loaded.ext.module.maas:684 ][INFO    ][17819] deploymachines hwe_kernel=hwe-16.04 system_id=prfkwe distro_series=xenial
2019-08-27 21:25:34,110 [salt.loaded.ext.module.maas:684 ][INFO    ][17819] deploymachines hwe_kernel=hwe-16.04 system_id=7qknxq distro_series=xenial
2019-08-27 21:25:36,643 [salt.loaded.ext.module.maas:684 ][INFO    ][17819] deploymachines hwe_kernel=hwe-16.04 system_id=h84e6r distro_series=xenial
2019-08-27 21:25:39,353 [salt.state       :300 ][INFO    ][17819] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']}}
2019-08-27 21:25:39,354 [salt.state       :1951][INFO    ][17819] Completed state [maas.deploy_machines] at time 21:25:39.354085 duration_in_ms=12420.705
2019-08-27 21:25:39,357 [salt.minion      :1711][INFO    ][17819] Returning information for job: 20190827212524929322
2019-08-27 21:25:39,984 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command state.apply with jid 20190827212539971398
2019-08-27 21:25:40,007 [salt.minion      :1432][INFO    ][18102] Starting a new job with PID 18102
2019-08-27 21:25:43,734 [salt.state       :915 ][INFO    ][18102] Loading fresh modules for state activity
2019-08-27 21:25:43,789 [salt.fileclient  :1219][INFO    ][18102] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-08-27 21:25:43,837 [salt.state       :1780][INFO    ][18102] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:43.837820
2019-08-27 21:25:43,838 [salt.state       :1813][INFO    ][18102] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-27 21:25:43,840 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18102] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-27 21:25:45,255 [salt.state       :300 ][INFO    ][18102] {'pid': 18117, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-27 21:25:45,256 [salt.state       :1951][INFO    ][18102] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:25:45.256749 duration_in_ms=1418.93
2019-08-27 21:25:45,259 [salt.state       :1780][INFO    ][18102] Running state [maas.wait_for_machine_status] at time 21:25:45.259126
2019-08-27 21:25:45,259 [salt.state       :1813][INFO    ][18102] Executing state module.run for [maas.wait_for_machine_status]
2019-08-27 21:25:45,260 [salt.utils.decorators:613 ][WARNING ][18102] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-27 21:25:48,294 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2246.97542191s left)
2019-08-27 21:25:55,021 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212555007198
2019-08-27 21:25:55,044 [salt.minion      :1432][INFO    ][18130] Starting a new job with PID 18130
2019-08-27 21:25:55,068 [salt.minion      :1711][INFO    ][18130] Returning information for job: 20190827212555007198
2019-08-27 21:26:21,447 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2213.82252407s left)
2019-08-27 21:26:25,080 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212625067062
2019-08-27 21:26:25,103 [salt.minion      :1432][INFO    ][18184] Starting a new job with PID 18184
2019-08-27 21:26:25,126 [salt.minion      :1711][INFO    ][18184] Returning information for job: 20190827212625067062
2019-08-27 21:26:54,651 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2180.61845589s left)
2019-08-27 21:26:55,172 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212655160083
2019-08-27 21:26:55,195 [salt.minion      :1432][INFO    ][18205] Starting a new job with PID 18205
2019-08-27 21:26:55,220 [salt.minion      :1711][INFO    ][18205] Returning information for job: 20190827212655160083
2019-08-27 21:27:25,216 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212725204294
2019-08-27 21:27:25,235 [salt.minion      :1432][INFO    ][18391] Starting a new job with PID 18391
2019-08-27 21:27:25,256 [salt.minion      :1711][INFO    ][18391] Returning information for job: 20190827212725204294
2019-08-27 21:27:28,169 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2147.10086489s left)
2019-08-27 21:27:55,259 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212755247120
2019-08-27 21:27:55,281 [salt.minion      :1432][INFO    ][18528] Starting a new job with PID 18528
2019-08-27 21:27:55,306 [salt.minion      :1711][INFO    ][18528] Returning information for job: 20190827212755247120
2019-08-27 21:28:01,345 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2113.92452002s left)
2019-08-27 21:28:25,311 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212825298397
2019-08-27 21:28:25,334 [salt.minion      :1432][INFO    ][19247] Starting a new job with PID 19247
2019-08-27 21:28:25,358 [salt.minion      :1711][INFO    ][19247] Returning information for job: 20190827212825298397
2019-08-27 21:28:33,918 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2081.35141802s left)
2019-08-27 21:28:55,373 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212855360095
2019-08-27 21:28:55,395 [salt.minion      :1432][INFO    ][19268] Starting a new job with PID 19268
2019-08-27 21:28:55,417 [salt.minion      :1711][INFO    ][19268] Returning information for job: 20190827212855360095
2019-08-27 21:29:07,529 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2047.74095893s left)
2019-08-27 21:29:25,433 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212925421311
2019-08-27 21:29:25,457 [salt.minion      :1432][INFO    ][19493] Starting a new job with PID 19493
2019-08-27 21:29:25,480 [salt.minion      :1711][INFO    ][19493] Returning information for job: 20190827212925421311
2019-08-27 21:29:41,000 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2014.26951504s left)
2019-08-27 21:29:55,490 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827212955477586
2019-08-27 21:29:55,512 [salt.minion      :1432][INFO    ][19524] Starting a new job with PID 19524
2019-08-27 21:29:55,535 [salt.minion      :1711][INFO    ][19524] Returning information for job: 20190827212955477586
2019-08-27 21:30:13,954 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1981.31548691s left)
2019-08-27 21:30:25,557 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213025544536
2019-08-27 21:30:25,580 [salt.minion      :1432][INFO    ][19978] Starting a new job with PID 19978
2019-08-27 21:30:25,603 [salt.minion      :1711][INFO    ][19978] Returning information for job: 20190827213025544536
2019-08-27 21:30:47,196 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1948.07366705s left)
2019-08-27 21:30:55,628 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213055616469
2019-08-27 21:30:55,650 [salt.minion      :1432][INFO    ][20005] Starting a new job with PID 20005
2019-08-27 21:30:55,673 [salt.minion      :1711][INFO    ][20005] Returning information for job: 20190827213055616469
2019-08-27 21:31:20,672 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1914.59742284s left)
2019-08-27 21:31:25,711 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213125696780
2019-08-27 21:31:25,736 [salt.minion      :1432][INFO    ][20507] Starting a new job with PID 20507
2019-08-27 21:31:25,758 [salt.minion      :1711][INFO    ][20507] Returning information for job: 20190827213125696780
2019-08-27 21:31:54,071 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1881.19830203s left)
2019-08-27 21:31:55,795 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213155779958
2019-08-27 21:31:55,818 [salt.minion      :1432][INFO    ][20528] Starting a new job with PID 20528
2019-08-27 21:31:55,843 [salt.minion      :1711][INFO    ][20528] Returning information for job: 20190827213155779958
2019-08-27 21:32:25,889 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213225876408
2019-08-27 21:32:25,912 [salt.minion      :1432][INFO    ][20660] Starting a new job with PID 20660
2019-08-27 21:32:25,934 [salt.minion      :1711][INFO    ][20660] Returning information for job: 20190827213225876408
2019-08-27 21:32:27,141 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1848.12828898s left)
2019-08-27 21:32:55,982 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213255969645
2019-08-27 21:32:56,001 [salt.minion      :1432][INFO    ][20725] Starting a new job with PID 20725
2019-08-27 21:32:56,021 [salt.minion      :1711][INFO    ][20725] Returning information for job: 20190827213255969645
2019-08-27 21:33:00,035 [salt.loaded.ext.module.maas:1023][INFO    ][18102] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1815.23460293s left)
2019-08-27 21:33:26,141 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command saltutil.find_job with jid 20190827213326129546
2019-08-27 21:33:26,164 [salt.minion      :1432][INFO    ][21000] Starting a new job with PID 21000
2019-08-27 21:33:26,189 [salt.minion      :1711][INFO    ][21000] Returning information for job: 20190827213326129546
2019-08-27 21:33:33,275 [salt.state       :300 ][INFO    ][18102] {'ret': True}
2019-08-27 21:33:33,275 [salt.state       :1951][INFO    ][18102] Completed state [maas.wait_for_machine_status] at time 21:33:33.275824 duration_in_ms=468016.697
2019-08-27 21:33:33,279 [salt.minion      :1711][INFO    ][18102] Returning information for job: 20190827212539971398
2019-08-27 22:10:54,082 [salt.utils.schedule:1377][INFO    ][13177] Running scheduled job: __mine_interval
2019-08-27 22:26:28,056 [salt.minion      :1308][INFO    ][13177] User sudo_ubuntu Executing command cp.push_dir with jid 20190827222628044244
2019-08-27 22:26:28,078 [salt.minion      :1432][INFO    ][25268] Starting a new job with PID 25268
