2018-12-28 08:37:21,209 [salt.utils       :831 ][ERROR   ][1488] DNS lookup or connection check of 'salt' failed.
2018-12-28 08:37:21,210 [salt.minion      :152 ][ERROR   ][1488] Master hostname: 'salt' not found or not responsive. Retrying in 30 seconds
2018-12-28 08:37:23,570 [salt.utils.parsers:1051][WARNING ][1488] Minion received a SIGTERM. Exiting.
2018-12-28 08:38:05,998 [salt.minion      :870 ][ERROR   ][1703] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2018-12-28 08:39:01,142 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /boot/grub/grub.cfg - 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.
2018-12-28 08:39:12,125 [salt.utils.decorators:613 ][WARNING ][1846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:39:12,241 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/shadow - 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.
2018-12-28 08:39:12,243 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/gshadow - 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.
2018-12-28 08:39:12,244 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/group- - 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.
2018-12-28 08:39:12,246 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/group - 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.
2018-12-28 08:39:12,247 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/passwd- - 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.
2018-12-28 08:39:12,248 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/passwd - 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.
2018-12-28 08:39:12,250 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/gshadow- - 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.
2018-12-28 08:39:12,251 [salt.loaded.int.states.file:2298][WARNING ][1846] State for file: /etc/shadow- - 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.
2018-12-28 08:39:12,460 [salt.loaded.int.module.cmdmod:730 ][ERROR   ][1846] Command '['umount', '/dev/shm']' failed with return code: 32
2018-12-28 08:39:12,461 [salt.loaded.int.module.cmdmod:734 ][ERROR   ][1846] stderr: umount: /dev/shm: target is busy
        (In some cases useful info about processes that
         use the device is found by lsof(8) or fuser(1).)
2018-12-28 08:39:12,461 [salt.loaded.int.module.cmdmod:736 ][ERROR   ][1846] retcode: 32
2018-12-28 08:39:25,541 [salt.utils.parsers:1051][WARNING ][1703] Minion received a SIGTERM. Exiting.
2018-12-28 08:40:17,412 [salt.utils.decorators:613 ][WARNING ][1985] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:40:37,835 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4664] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2018-12-28 08:40:37,858 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4664] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2018-12-28 08:40:37,876 [salt.utils.parsers:1051][WARNING ][1721] Minion received a SIGTERM. Exiting.
2018-12-28 08:40:38,824 [salt.cli.daemons :293 ][INFO    ][4741] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2018-12-28 08:40:38,943 [salt.cli.daemons :82  ][INFO    ][4741] Starting up the Salt Minion
2018-12-28 08:40:38,944 [salt.utils.event :1017][INFO    ][4741] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2018-12-28 08:40:39,557 [salt.minion      :976 ][INFO    ][4741] Creating minion process manager
2018-12-28 08:40:40,899 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4741] Executing command ['date', '+%z'] in directory '/root'
2018-12-28 08:40:40,917 [salt.utils.schedule:568 ][INFO    ][4741] Updating job settings for scheduled job: __mine_interval
2018-12-28 08:40:40,919 [salt.minion      :1108][INFO    ][4741] Added mine.update to scheduler
2018-12-28 08:40:40,925 [salt.minion      :1975][INFO    ][4741] Minion is starting as user 'root'
2018-12-28 08:40:40,936 [salt.minion      :2336][INFO    ][4741] Minion is ready to receive requests!
2018-12-28 08:40:46,701 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084046687418
2018-12-28 08:40:46,732 [salt.minion      :1432][INFO    ][4931] Starting a new job with PID 4931
2018-12-28 08:40:46,773 [salt.minion      :1711][INFO    ][4931] Returning information for job: 20181228084046687418
2018-12-28 08:40:50,184 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /boot/grub/grub.cfg - 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.
2018-12-28 08:40:53,404 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/shadow - 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.
2018-12-28 08:40:53,406 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/gshadow - 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.
2018-12-28 08:40:53,407 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/group- - 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.
2018-12-28 08:40:53,408 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/group - 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.
2018-12-28 08:40:53,409 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/passwd- - 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.
2018-12-28 08:40:53,411 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/passwd - 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.
2018-12-28 08:40:53,412 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/gshadow- - 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.
2018-12-28 08:40:53,413 [salt.loaded.int.states.file:2298][WARNING ][4670] State for file: /etc/shadow- - 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.
2018-12-28 08:40:53,590 [salt.utils.decorators:613 ][WARNING ][4670] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:40:53,962 [salt.loaded.int.module.cmdmod:730 ][ERROR   ][4670] Command '['umount', '/dev/shm']' failed with return code: 32
2018-12-28 08:40:53,963 [salt.loaded.int.module.cmdmod:734 ][ERROR   ][4670] stderr: umount: /dev/shm: target is busy
        (In some cases useful info about processes that
         use the device is found by lsof(8) or fuser(1).)
2018-12-28 08:40:53,963 [salt.loaded.int.module.cmdmod:736 ][ERROR   ][4670] retcode: 32
2018-12-28 08:40:56,755 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084056740648
2018-12-28 08:40:56,794 [salt.minion      :1432][INFO    ][5729] Starting a new job with PID 5729
2018-12-28 08:40:56,847 [salt.minion      :1711][INFO    ][5729] Returning information for job: 20181228084056740648
2018-12-28 08:41:01,339 [salt.utils.decorators:613 ][WARNING ][4670] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:41:01,371 [salt.utils.decorators:613 ][WARNING ][4670] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:41:02,185 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228084102172503
2018-12-28 08:41:02,242 [salt.minion      :1432][INFO    ][6087] Starting a new job with PID 6087
2018-12-28 08:41:10,091 [salt.state       :915 ][INFO    ][6087] Loading fresh modules for state activity
2018-12-28 08:41:10,156 [salt.fileclient  :1219][INFO    ][6087] Fetching file from saltenv 'base', ** done ** 'maas/cluster.sls'
2018-12-28 08:41:11,027 [salt.state       :1780][INFO    ][6087] Running state [maas-rack-controller] at time 08:41:11.027803
2018-12-28 08:41:11,028 [salt.state       :1813][INFO    ][6087] Executing state pkg.installed for [maas-rack-controller]
2018-12-28 08:41:11,028 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-28 08:41:11,428 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['apt-cache', '-q', 'policy', 'maas-rack-controller'] in directory '/root'
2018-12-28 08:41:11,509 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['apt-get', '-q', 'update'] in directory '/root'
2018-12-28 08:41:12,298 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084112281724
2018-12-28 08:41:12,344 [salt.minion      :1432][INFO    ][6350] Starting a new job with PID 6350
2018-12-28 08:41:12,383 [salt.minion      :1711][INFO    ][6350] Returning information for job: 20181228084112281724
2018-12-28 08:41:13,741 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-28 08:41:13,766 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['systemd-run', '--scope', 'apt-get', '-q', '-y', '-o', 'DPkg::Options::=--force-confold', '-o', 'DPkg::Options::=--force-confdef', 'install', 'maas-rack-controller'] in directory '/root'
2018-12-28 08:41:22,340 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084122330134
2018-12-28 08:41:22,389 [salt.minion      :1432][INFO    ][6973] Starting a new job with PID 6973
2018-12-28 08:41:22,431 [salt.minion      :1711][INFO    ][6973] Returning information for job: 20181228084122330134
2018-12-28 08:41:32,393 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084132379301
2018-12-28 08:41:32,437 [salt.minion      :1432][INFO    ][8949] Starting a new job with PID 8949
2018-12-28 08:41:32,485 [salt.minion      :1711][INFO    ][8949] Returning information for job: 20181228084132379301
2018-12-28 08:41:42,440 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084142424472
2018-12-28 08:41:42,492 [salt.minion      :1432][INFO    ][9586] Starting a new job with PID 9586
2018-12-28 08:41:42,531 [salt.minion      :1711][INFO    ][9586] Returning information for job: 20181228084142424472
2018-12-28 08:41:52,469 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084152458267
2018-12-28 08:41:52,513 [salt.minion      :1432][INFO    ][9754] Starting a new job with PID 9754
2018-12-28 08:41:52,542 [salt.minion      :1711][INFO    ][9754] Returning information for job: 20181228084152458267
2018-12-28 08:41:54,359 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-28 08:41:54,405 [salt.state       :300 ][INFO    ][6087] Made the following changes:
'python3-pyvmomi' changed from 'absent' to '6.5.0.2017.5-0ubuntu1~16.04.1'
'libdaemon0' changed from 'absent' to '0.14-6'
'tgt' changed from 'absent' to '1:1.0.63-1ubuntu1.1'
'authbind' changed from 'absent' to '2.1.1+nmu1'
'libavahi-common3' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'python3-twisted' changed from 'absent' to '16.0.0-1ubuntu0.2'
'libfreeipmi16' changed from 'absent' to '1.4.11-1.1ubuntu4~0.16.04'
'python3-bson' changed from 'absent' to '3.2-1build1'
'python3-zope' changed from 'absent' to '1'
'python3-service-identity' changed from 'absent' to '16.0.0-2'
'python3.5-crypto' changed from 'absent' to '1'
'python3-html5lib' changed from 'absent' to '0.999-4'
'python3-simplestreams' changed from 'absent' to '0.1.0~bzr426-0ubuntu1.2'
'freeipmi-tools' changed from 'absent' to '1.4.11-1.1ubuntu4~0.16.04'
'python3-netaddr' changed from 'absent' to '0.7.18-1'
'python3-pyasn1-modules' changed from 'absent' to '0.0.7-0.1'
'libavahi-core7' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'avahi-daemon' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'python3-iso8601' changed from 'absent' to '0.1.11-1'
'python3.5-lxml' changed from 'absent' to '1'
'sg3-utils' changed from 'absent' to '1.40-0ubuntu1'
'archdetect-deb' changed from 'absent' to '1.117ubuntu2.3'
'python3-lxml' changed from 'absent' to '3.5.0-1ubuntu0.1'
'maas-dhcp' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-httplib2' changed from 'absent' to '0.9.1+dfsg-1'
'python3-pexpect' changed from 'absent' to '4.0.1-1'
'python3-bson-ext' changed from 'absent' to '3.2-1build1'
'avahi-utils' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'distro-info' changed from 'absent' to '0.14build1'
'libipmidetect0' changed from 'absent' to '1.4.11-1.1ubuntu4~0.16.04'
'python3-maas-provisioningserver' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-jsonschema' changed from 'absent' to '2.5.1-4'
'maas-cli' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-seamicroclient' changed from 'absent' to '0.4.0-1ubuntu1'
'python3-tempita' changed from 'absent' to '0.5.2-1build1'
'python3-ptyprocess' changed from 'absent' to '0.5-1'
'python3-netifaces' changed from 'absent' to '0.10.4-0.1build2'
'syslinux-common' changed from 'absent' to '3:6.03+dfsg-11ubuntu1'
'libnss-mdns' changed from 'absent' to '0.10-7'
'libipmiconsole2' changed from 'absent' to '1.4.11-1.1ubuntu4~0.16.04'
'libavahi-client3' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'python3-pyparsing' changed from 'absent' to '2.0.3+dfsg1-1ubuntu0.1'
'python3-pbr' changed from 'absent' to '1.8.0-4ubuntu1'
'python3-dnspython' changed from 'absent' to '1.12.0-0ubuntu3'
'python3-paramiko' changed from 'absent' to '1.16.0-1ubuntu0.2'
'python3-tz' changed from 'absent' to '2014.10~dfsg1-0ubuntu2'
'python3-babel' changed from 'absent' to '1.3+dfsg.1-6'
'formencode-i18n' changed from 'absent' to '1.3.0-0ubuntu5'
'python3-zope.interface' changed from 'absent' to '4.1.3-1build1'
'python3.5-zope.interface' changed from 'absent' to '1'
'python3-txtftp' changed from 'absent' to '0.1~bzr42-0ubuntu2'
'maas-common' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'freeipmi-common' changed from 'absent' to '1.4.11-1.1ubuntu4~0.16.04'
'curtin-common' changed from 'absent' to '18.1-17-gae48e86f-0ubuntu1~16.04.1'
'librdmacm1' changed from 'absent' to '1.0.21-1'
'python3-oauth' changed from 'absent' to '1.0.1-5'
'python3-maas-client' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'libisccfg-export140' changed from 'absent' to '1:9.10.3.dfsg.P4-8ubuntu1.11'
'python3-openssl' changed from 'absent' to '0.15.1-2ubuntu0.2'
'python3-ecdsa' changed from 'absent' to '0.13-2'
'python3-distro-info' changed from 'absent' to '0.14build1'
'python3-attr' changed from 'absent' to '15.2.0-1'
'libibverbs1' changed from 'absent' to '1.1.8-1.1ubuntu2'
'libdebian-installer4' changed from 'absent' to '0.102ubuntu1.1'
'isc-dhcp-server' changed from 'absent' to '4.3.3-5ubuntu12.10'
'maas-rack-controller' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python-babel-localedata' changed from 'absent' to '1.3+dfsg.1-6'
'python3-curtin' changed from 'absent' to '18.1-17-gae48e86f-0ubuntu1~16.04.1'
'python3-simplejson' changed from 'absent' to '3.8.1-1ubuntu2'
'pxelinux' changed from 'absent' to '3:6.03+dfsg-11ubuntu1'
'bind9utils' changed from 'absent' to '1:9.10.3.dfsg.P4-8ubuntu1.11'
'python3-crypto' changed from 'absent' to '2.6.1-6ubuntu0.16.04.3'
'python3-crochet' changed from 'absent' to '1.4.0-0ubuntu2'
'libavahi-common-data' changed from 'absent' to '0.6.32~rc+dfsg-1ubuntu2.2'
'python3-formencode' changed from 'absent' to '1.3.0-0ubuntu5'
'python3-pam' changed from 'absent' to '0.4.2-13.2ubuntu2'
'libconfig-general-perl' changed from 'absent' to '2.60-1'
'python3-bs4' changed from 'absent' to '4.4.1-1'
'libsgutils2-2' changed from 'absent' to '1.40-0ubuntu1'
'libirs-export141' changed from 'absent' to '1:9.10.3.dfsg.P4-8ubuntu1.11'

2018-12-28 08:41:54,448 [salt.state       :915 ][INFO    ][6087] Loading fresh modules for state activity
2018-12-28 08:41:54,495 [salt.state       :1951][INFO    ][6087] Completed state [maas-rack-controller] at time 08:41:54.495186 duration_in_ms=43467.383
2018-12-28 08:41:54,503 [salt.state       :1780][INFO    ][6087] Running state [ipmitool] at time 08:41:54.503148
2018-12-28 08:41:54,503 [salt.state       :1813][INFO    ][6087] Executing state pkg.installed for [ipmitool]
2018-12-28 08:41:55,295 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-28 08:41:55,320 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['systemd-run', '--scope', 'apt-get', '-q', '-y', '-o', 'DPkg::Options::=--force-confold', '-o', 'DPkg::Options::=--force-confdef', 'install', 'ipmitool'] in directory '/root'
2018-12-28 08:41:59,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-28 08:41:59,990 [salt.state       :300 ][INFO    ][6087] Made the following changes:
'libsnmp30' changed from 'absent' to '5.7.3+dfsg-1ubuntu4.2'
'ipmitool' changed from 'absent' to '1.8.16-3ubuntu0.2'
'libsensors4' changed from 'absent' to '1:3.4.0-2'
'libopenipmi0' changed from 'absent' to '2.0.18-0ubuntu11.2'
'libsnmp-base' changed from 'absent' to '5.7.3+dfsg-1ubuntu4.2'
'openipmi' changed from 'absent' to '2.0.18-0ubuntu11.2'

2018-12-28 08:42:00,009 [salt.state       :915 ][INFO    ][6087] Loading fresh modules for state activity
2018-12-28 08:42:00,056 [salt.state       :1951][INFO    ][6087] Completed state [ipmitool] at time 08:42:00.055951 duration_in_ms=5552.802
2018-12-28 08:42:00,062 [salt.state       :1780][INFO    ][6087] Running state [/etc/maas/rackd.conf] at time 08:42:00.062498
2018-12-28 08:42:00,062 [salt.state       :1813][INFO    ][6087] Executing state file.line for [/etc/maas/rackd.conf]
2018-12-28 08:42:00,068 [salt.state       :300 ][INFO    ][6087] No changes needed to be made
2018-12-28 08:42:00,068 [salt.state       :1951][INFO    ][6087] Completed state [/etc/maas/rackd.conf] at time 08:42:00.068675 duration_in_ms=6.177
2018-12-28 08:42:00,068 [salt.state       :1780][INFO    ][6087] Running state [/etc/maas/rackd.conf] at time 08:42:00.068933
2018-12-28 08:42:00,069 [salt.state       :1813][INFO    ][6087] Executing state file.managed for [/etc/maas/rackd.conf]
2018-12-28 08:42:00,069 [salt.loaded.int.states.file:2298][WARNING ][6087] 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.
2018-12-28 08:42:00,070 [salt.state       :300 ][INFO    ][6087] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2018-12-28 08:42:00,070 [salt.state       :1951][INFO    ][6087] Completed state [/etc/maas/rackd.conf] at time 08:42:00.070432 duration_in_ms=1.499
2018-12-28 08:42:00,635 [salt.state       :1780][INFO    ][6087] Running state [maas-rackd] at time 08:42:00.634955
2018-12-28 08:42:00,635 [salt.state       :1813][INFO    ][6087] Executing state service.running for [maas-rackd]
2018-12-28 08:42:00,636 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2018-12-28 08:42:00,658 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2018-12-28 08:42:00,678 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6087] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2018-12-28 08:42:00,697 [salt.state       :300 ][INFO    ][6087] The service maas-rackd is already running
2018-12-28 08:42:00,697 [salt.state       :1951][INFO    ][6087] Completed state [maas-rackd] at time 08:42:00.697508 duration_in_ms=62.554
2018-12-28 08:42:00,700 [salt.minion      :1711][INFO    ][6087] Returning information for job: 20181228084102172503
2018-12-28 08:42:01,403 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228084201388387
2018-12-28 08:42:01,441 [salt.minion      :1432][INFO    ][10862] Starting a new job with PID 10862
2018-12-28 08:42:09,225 [salt.state       :915 ][INFO    ][10862] Loading fresh modules for state activity
2018-12-28 08:42:09,280 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/region.sls'
2018-12-28 08:42:10,252 [salt.state       :1780][INFO    ][10862] Running state [maas-region-controller] at time 08:42:10.252062
2018-12-28 08:42:10,252 [salt.state       :1813][INFO    ][10862] Executing state pkg.installed for [maas-region-controller]
2018-12-28 08:42:10,253 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-28 08:42:10,678 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['apt-cache', '-q', 'policy', 'maas-region-controller'] in directory '/root'
2018-12-28 08:42:10,774 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['apt-get', '-q', 'update'] in directory '/root'
2018-12-28 08:42:11,434 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084211421248
2018-12-28 08:42:11,475 [salt.minion      :1432][INFO    ][11125] Starting a new job with PID 11125
2018-12-28 08:42:11,522 [salt.minion      :1711][INFO    ][11125] Returning information for job: 20181228084211421248
2018-12-28 08:42:12,854 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-28 08:42:12,881 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemd-run', '--scope', 'apt-get', '-q', '-y', '-o', 'DPkg::Options::=--force-confold', '-o', 'DPkg::Options::=--force-confdef', 'install', 'maas-region-controller'] in directory '/root'
2018-12-28 08:42:21,479 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084221461148
2018-12-28 08:42:21,540 [salt.minion      :1432][INFO    ][11436] Starting a new job with PID 11436
2018-12-28 08:42:21,588 [salt.minion      :1711][INFO    ][11436] Returning information for job: 20181228084221461148
2018-12-28 08:42:31,536 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084231505691
2018-12-28 08:42:31,643 [salt.minion      :1432][INFO    ][12862] Starting a new job with PID 12862
2018-12-28 08:42:31,724 [salt.minion      :1711][INFO    ][12862] Returning information for job: 20181228084231505691
2018-12-28 08:42:41,665 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084241641939
2018-12-28 08:42:41,723 [salt.minion      :1432][INFO    ][14561] Starting a new job with PID 14561
2018-12-28 08:42:41,756 [salt.minion      :1711][INFO    ][14561] Returning information for job: 20181228084241641939
2018-12-28 08:42:51,711 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084251695242
2018-12-28 08:42:51,748 [salt.minion      :1432][INFO    ][14571] Starting a new job with PID 14571
2018-12-28 08:42:51,790 [salt.minion      :1711][INFO    ][14571] Returning information for job: 20181228084251695242
2018-12-28 08:43:01,758 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084301744744
2018-12-28 08:43:01,805 [salt.minion      :1432][INFO    ][14586] Starting a new job with PID 14586
2018-12-28 08:43:01,843 [salt.minion      :1711][INFO    ][14586] Returning information for job: 20181228084301744744
2018-12-28 08:43:11,801 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084311788873
2018-12-28 08:43:11,838 [salt.minion      :1432][INFO    ][14595] Starting a new job with PID 14595
2018-12-28 08:43:11,874 [salt.minion      :1711][INFO    ][14595] Returning information for job: 20181228084311788873
2018-12-28 08:43:21,984 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084321968167
2018-12-28 08:43:22,089 [salt.minion      :1432][INFO    ][15487] Starting a new job with PID 15487
2018-12-28 08:43:22,144 [salt.minion      :1711][INFO    ][15487] Returning information for job: 20181228084321968167
2018-12-28 08:43:32,077 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084332054797
2018-12-28 08:43:32,117 [salt.minion      :1432][INFO    ][15997] Starting a new job with PID 15997
2018-12-28 08:43:32,154 [salt.minion      :1711][INFO    ][15997] Returning information for job: 20181228084332054797
2018-12-28 08:43:42,102 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084342084009
2018-12-28 08:43:42,157 [salt.minion      :1432][INFO    ][16280] Starting a new job with PID 16280
2018-12-28 08:43:42,186 [salt.minion      :1711][INFO    ][16280] Returning information for job: 20181228084342084009
2018-12-28 08:43:52,155 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084352134801
2018-12-28 08:43:52,273 [salt.minion      :1432][INFO    ][16769] Starting a new job with PID 16769
2018-12-28 08:43:52,344 [salt.minion      :1711][INFO    ][16769] Returning information for job: 20181228084352134801
2018-12-28 08:44:02,273 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084402258247
2018-12-28 08:44:02,417 [salt.minion      :1432][INFO    ][16780] Starting a new job with PID 16780
2018-12-28 08:44:02,449 [salt.minion      :1711][INFO    ][16780] Returning information for job: 20181228084402258247
2018-12-28 08:44:12,382 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084412363689
2018-12-28 08:44:12,511 [salt.minion      :1432][INFO    ][16785] Starting a new job with PID 16785
2018-12-28 08:44:12,575 [salt.minion      :1711][INFO    ][16785] Returning information for job: 20181228084412363689
2018-12-28 08:44:22,513 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084422496331
2018-12-28 08:44:22,643 [salt.minion      :1432][INFO    ][16790] Starting a new job with PID 16790
2018-12-28 08:44:22,690 [salt.minion      :1711][INFO    ][16790] Returning information for job: 20181228084422496331
2018-12-28 08:44:32,639 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084432622045
2018-12-28 08:44:32,829 [salt.minion      :1432][INFO    ][16796] Starting a new job with PID 16796
2018-12-28 08:44:32,870 [salt.minion      :1711][INFO    ][16796] Returning information for job: 20181228084432622045
2018-12-28 08:44:42,815 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084442797170
2018-12-28 08:44:42,918 [salt.minion      :1432][INFO    ][16802] Starting a new job with PID 16802
2018-12-28 08:44:43,050 [salt.minion      :1711][INFO    ][16802] Returning information for job: 20181228084442797170
2018-12-28 08:44:52,926 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084452912513
2018-12-28 08:44:52,973 [salt.minion      :1432][INFO    ][16813] Starting a new job with PID 16813
2018-12-28 08:44:53,064 [salt.minion      :1711][INFO    ][16813] Returning information for job: 20181228084452912513
2018-12-28 08:45:03,148 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084503131642
2018-12-28 08:45:03,206 [salt.minion      :1432][INFO    ][16828] Starting a new job with PID 16828
2018-12-28 08:45:03,251 [salt.minion      :1711][INFO    ][16828] Returning information for job: 20181228084503131642
2018-12-28 08:45:13,193 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084513179415
2018-12-28 08:45:13,241 [salt.minion      :1432][INFO    ][16833] Starting a new job with PID 16833
2018-12-28 08:45:13,278 [salt.minion      :1711][INFO    ][16833] Returning information for job: 20181228084513179415
2018-12-28 08:45:23,248 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084523229028
2018-12-28 08:45:23,318 [salt.minion      :1432][INFO    ][17411] Starting a new job with PID 17411
2018-12-28 08:45:23,351 [salt.minion      :1711][INFO    ][17411] Returning information for job: 20181228084523229028
2018-12-28 08:45:24,828 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-28 08:45:24,897 [salt.state       :300 ][INFO    ][10862] Made the following changes:
'python3.5-psycopg2' changed from 'absent' to '1'
'maas-region-controller' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'libapr1' changed from 'absent' to '1.5.2-3'
'sphinx-common' changed from 'absent' to '1.3.6-2ubuntu1.2'
'bind9' changed from 'absent' to '1:9.10.3.dfsg.P4-8ubuntu1.11'
'libecap3' changed from 'absent' to '1.0.1-3ubuntu3'
'python3-docutils' changed from 'absent' to '0.12+dfsg-1'
'libtiff5' changed from 'absent' to '4.0.6-1ubuntu0.4'
'maas-region-api' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-roman' changed from 'absent' to '2.0.0-2'
'libaprutil1-ldap' changed from 'absent' to '1.5.4-1build1'
'libpaper1' changed from 'absent' to '1.1.24+nmu4ubuntu1'
'docutils' changed from 'absent' to '1'
'postgresql-contrib-9.5' changed from 'absent' to '9.5.14-0ubuntu0.16.04'
'apache2' changed from 'absent' to '2.4.18-2ubuntu3.9'
'maas-region-controller-min' changed from 'absent' to '1'
'python3-mimeparse' changed from 'absent' to '0.1.4-1build1'
'libpq5' changed from 'absent' to '9.5.14-0ubuntu0.16.04'
'fonts-font-awesome' changed from 'absent' to '4.5.0~dfsg-1'
'python3-django' changed from 'absent' to '1.8.7-1ubuntu5.6'
'libpaper-utils' changed from 'absent' to '1.1.24+nmu4ubuntu1'
'postgresql-common' changed from 'absent' to '173ubuntu0.2'
'apache2-data' changed from 'absent' to '2.4.18-2ubuntu3.9'
'python3-convoy' changed from 'absent' to '0.2.1+bzr39-1'
'python3-psycopg2' changed from 'absent' to '2.6.1-1build2'
'libjs-yui3-min' changed from 'absent' to '3.5.1-1ubuntu3'
'python3-djorm-ext-pgarray' changed from 'absent' to '1.2-0ubuntu2'
'apache2-bin' changed from 'absent' to '2.4.18-2ubuntu3.9'
'libjbig0' changed from 'absent' to '2.1-3.1'
'fonts-lato' changed from 'absent' to '2.0-1'
'postgresql-9.5' changed from 'absent' to '9.5.14-0ubuntu0.16.04'
'libjpeg8' changed from 'absent' to '8c-2ubuntu8'
'libpaperg' changed from 'absent' to '1'
'docutils-common' changed from 'absent' to '0.12+dfsg-1'
'libirs141' changed from 'absent' to '1:9.10.3.dfsg.P4-8ubuntu1.11'
'libltdl7' changed from 'absent' to '2.4.6-0.1'
'squid-common' changed from 'absent' to '3.5.12-1ubuntu7.6'
'apache2-utils' changed from 'absent' to '2.4.18-2ubuntu3.9'
'squid' changed from 'absent' to '3.5.12-1ubuntu7.6'
'squid-langpack' changed from 'absent' to '20150704-1'
'libjs-yui3-full' changed from 'absent' to '3.5.1-1ubuntu3'
'python3-pil' changed from 'absent' to '3.1.2-0ubuntu1.1'
'postgresql-client-common' changed from 'absent' to '173ubuntu0.2'
'libjpeg-turbo8' changed from 'absent' to '1.4.2-0ubuntu3.1'
'python3-sqlparse' changed from 'absent' to '0.1.18-1'
'libwebp5' changed from 'absent' to '0.4.4-1'
'python3-django-piston' changed from 'absent' to '1'
'libjs-angularjs' changed from 'absent' to '1.2.28-1ubuntu2'
'postgresql-client-9.5' changed from 'absent' to '9.5.14-0ubuntu0.16.04'
'libjs-yui3-common' changed from 'absent' to '3.5.1-1ubuntu3'
'maas-dns' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-django-maas' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'dbconfig-pgsql' changed from 'absent' to '2.0.4ubuntu1'
'sphinx-rtd-theme-common' changed from 'absent' to '0.1.9-1'
'postgresql-client' changed from 'absent' to '9.5+173ubuntu0.2'
'python3-pillow' changed from 'absent' to '1'
'python3-django-piston3' changed from 'absent' to '0.3~rc2-3ubuntu1'
'dbconfig-common' changed from 'absent' to '2.0.4ubuntu1'
'liblcms2-2' changed from 'absent' to '2.6-3ubuntu2.1'
'httpd' changed from 'absent' to '1'
'apache2-api-20120211' changed from 'absent' to '1'
'libaprutil1' changed from 'absent' to '1.5.4-1build1'
'liblua5.1-0' changed from 'absent' to '5.1.5-8ubuntu1'
'libaprutil1-dbd-sqlite3' changed from 'absent' to '1.5.4-1build1'
'squid3-common' changed from 'absent' to '1'
'python3-sphinx-rtd-theme' changed from 'absent' to '0.1.9-1'
'python3-pygments' changed from 'absent' to '2.1+dfsg-1'
'maas-proxy' changed from 'absent' to '2.3.5-6511-gf466fdb-0ubuntu1'
'python3-alabaster' changed from 'absent' to '0.7.7-1'
'postgresql' changed from 'absent' to '9.5+173ubuntu0.2'
'sysstat' changed from 'absent' to '11.2.0-1ubuntu0.2'
'python3-petname' changed from 'absent' to '2.0-0ubuntu1~16.04'
'httpd-cgi' changed from 'absent' to '1'
'python3-sphinx' changed from 'absent' to '1.3.6-2ubuntu1.2'
'python3-djorm-pgarray' changed from 'absent' to '1'
'libjs-modernizr' changed from 'absent' to '2.6.2+ds1-1ubuntu1'
'python-django-common' changed from 'absent' to '1.8.7-1ubuntu5.6'
'ssl-cert' changed from 'absent' to '1.0.37'
'libwebpmux1' changed from 'absent' to '0.4.4-1'

2018-12-28 08:45:24,959 [salt.state       :915 ][INFO    ][10862] Loading fresh modules for state activity
2018-12-28 08:45:25,019 [salt.state       :1951][INFO    ][10862] Completed state [maas-region-controller] at time 08:45:25.019344 duration_in_ms=194767.282
2018-12-28 08:45:25,027 [salt.state       :1780][INFO    ][10862] Running state [python-oauth] at time 08:45:25.026995
2018-12-28 08:45:25,027 [salt.state       :1813][INFO    ][10862] Executing state pkg.installed for [python-oauth]
2018-12-28 08:45:26,242 [salt.state       :300 ][INFO    ][10862] All specified packages are already installed
2018-12-28 08:45:26,243 [salt.state       :1951][INFO    ][10862] Completed state [python-oauth] at time 08:45:26.243311 duration_in_ms=1216.315
2018-12-28 08:45:26,247 [salt.state       :1780][INFO    ][10862] Running state [/etc/maas/regiond.conf] at time 08:45:26.247545
2018-12-28 08:45:26,247 [salt.state       :1813][INFO    ][10862] Executing state file.replace for [/etc/maas/regiond.conf]
2018-12-28 08:45:26,253 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -3,4 +3,4 @@
 database_pass: qk3buG2wBZmv
 database_port: 5432
 database_user: maas
-maas_url: http://10.20.0.3:5240/MAAS
+maas_url: http://192.168.11.3:5240/MAAS

2018-12-28 08:45:26,253 [salt.state       :1951][INFO    ][10862] Completed state [/etc/maas/regiond.conf] at time 08:45:26.253680 duration_in_ms=6.135
2018-12-28 08:45:26,254 [salt.state       :1780][INFO    ][10862] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:45:26.254239
2018-12-28 08:45:26,254 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2018-12-28 08:45:26,282 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/maas-proxy.conf.template'
2018-12-28 08:45:26,334 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -1,3 +1,5 @@
+
+
 # DO NOT EDIT.  This file is automatically created by MAAS.
 # Last updated at {{modified}}.
 
@@ -10,6 +12,7 @@
 acl localnet src {{cidr}}
 {{endfor}}
 acl SSL_ports port 443
+acl SSL_ports port 50000        # jenkins slave
 acl Safe_ports port 80          # http
 acl Safe_ports port 21          # ftp
 acl Safe_ports port 443         # https
@@ -23,11 +26,7 @@
 http_access allow localhost
 http_access deny all
 http_port 3128 transparent
-{{if not maas_proxy_port}}
 http_port 8000
-{{else}}
-http_port {{maas_proxy_port}}
-{{endif}}
 refresh_pattern ^ftp:           1440    20%     10080
 refresh_pattern -i (/cgi-bin/|\?) 0     0%      0
 refresh_pattern \/Release(|\.gpg)$                        0    0%    0 refresh-ims
@@ -61,7 +60,5 @@
 cache_log /var/log/maas/proxy/cache.log
 cache_store_log /var/log/maas/proxy/store.log
 {{endif}}
-{{if upstream_peer_proxy}}
-cache_peer {{upstream_proxy_address}} parent {{upstream_proxy_port}} 0 no-query default
-never_direct allow all
-{{endif}}
+
+

2018-12-28 08:45:26,335 [salt.state       :1951][INFO    ][10862] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:45:26.335000 duration_in_ms=80.761
2018-12-28 08:45:26,336 [salt.state       :1780][INFO    ][10862] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:45:26.336725
2018-12-28 08:45:26,337 [salt.state       :1813][INFO    ][10862] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2018-12-28 08:45:26,340 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -284,7 +284,7 @@
 }
 
 NODE_FAILURE_MONITORED_STATUS_TIMEOUTS = {
-    NODE_STATUS.COMMISSIONING: 20,
+    NODE_STATUS.COMMISSIONING: 10,
     NODE_STATUS.DEPLOYING: 40,
     NODE_STATUS.RELEASING: 5,
     NODE_STATUS.ENTERING_RESCUE_MODE: 20,

2018-12-28 08:45:26,341 [salt.state       :1951][INFO    ][10862] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:45:26.341107 duration_in_ms=4.382
2018-12-28 08:45:26,341 [salt.state       :1780][INFO    ][10862] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:45:26.341597
2018-12-28 08:45:26,341 [salt.state       :1813][INFO    ][10862] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2018-12-28 08:45:26,346 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -285,7 +285,7 @@
 
 NODE_FAILURE_MONITORED_STATUS_TIMEOUTS = {
     NODE_STATUS.COMMISSIONING: 10,
-    NODE_STATUS.DEPLOYING: 40,
+    NODE_STATUS.DEPLOYING: 15,
     NODE_STATUS.RELEASING: 5,
     NODE_STATUS.ENTERING_RESCUE_MODE: 20,
     NODE_STATUS.EXITING_RESCUE_MODE: 5,

2018-12-28 08:45:26,347 [salt.state       :1951][INFO    ][10862] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:45:26.346997 duration_in_ms=5.4
2018-12-28 08:45:26,348 [salt.state       :1780][INFO    ][10862] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:45:26.347531
2018-12-28 08:45:26,348 [salt.state       :1813][INFO    ][10862] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2018-12-28 08:45:26,384 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -3210,7 +3210,7 @@
             alloc_type=IPADDRESS_TYPE.DISCOVERED, subnet__isnull=False)
         for ip_address in discovered_addresses:
             boot_interface.link_subnet(
-                INTERFACE_LINK_TYPE.AUTO, ip_address.subnet)
+                INTERFACE_LINK_TYPE.DHCP, ip_address.subnet)
             auto_set = True
         if not auto_set:
             # Failed to set AUTO mode on the boot interface. Lets force an

2018-12-28 08:45:26,384 [salt.state       :1951][INFO    ][10862] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:45:26.384376 duration_in_ms=36.844
2018-12-28 08:45:26,384 [salt.state       :1780][INFO    ][10862] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:45:26.384930
2018-12-28 08:45:26,385 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2018-12-28 08:45:26,405 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/maas-http.conf'
2018-12-28 08:45:26,411 [salt.state       :300 ][INFO    ][10862] File changed:
--- 
+++ 
@@ -37,3 +37,5 @@
     # Redirect (permanently) requests for /MAAS to /MAAS/.
     RewriteRule ^/MAAS$ %{REQUEST_URI}/ [R=301,L]
 </IfModule>
+Header set Access-Control-Allow-Origin "*"
+Header set X-Frame-Options "ALLOWALL"

2018-12-28 08:45:26,412 [salt.state       :1951][INFO    ][10862] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:45:26.412531 duration_in_ms=27.601
2018-12-28 08:45:26,413 [salt.state       :1780][INFO    ][10862] Running state [a2enmod headers] at time 08:45:26.413903
2018-12-28 08:45:26,414 [salt.state       :1813][INFO    ][10862] Executing state cmd.run for [a2enmod headers]
2018-12-28 08:45:26,414 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command 'a2enmod headers' in directory '/root'
2018-12-28 08:45:26,491 [salt.state       :300 ][INFO    ][10862] {'pid': 17622, 'retcode': 0, 'stderr': '', 'stdout': 'Enabling module headers.\nTo activate the new configuration, you need to run:\n  service apache2 restart'}
2018-12-28 08:45:26,493 [salt.state       :1951][INFO    ][10862] Completed state [a2enmod headers] at time 08:45:26.491547 duration_in_ms=77.644
2018-12-28 08:45:26,493 [salt.state       :1780][INFO    ][10862] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:45:26.493385
2018-12-28 08:45:26,493 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2018-12-28 08:45:26,525 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/mirantis-styles.css'
2018-12-28 08:45:26,530 [salt.state       :300 ][INFO    ][10862] File changed:
New file
2018-12-28 08:45:26,530 [salt.state       :1951][INFO    ][10862] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:45:26.530907 duration_in_ms=37.522
2018-12-28 08:45:26,532 [salt.state       :1780][INFO    ][10862] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:45:26.532596
2018-12-28 08:45:26,533 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2018-12-28 08:45:26,555 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_amd64_generic_trusty'
2018-12-28 08:45:26,608 [salt.state       :300 ][INFO    ][10862] File changed:
New file
2018-12-28 08:45:26,609 [salt.state       :1951][INFO    ][10862] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:45:26.609211 duration_in_ms=76.614
2018-12-28 08:45:26,609 [salt.state       :1780][INFO    ][10862] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:45:26.609768
2018-12-28 08:45:26,610 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2018-12-28 08:45:26,628 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_amd64_generic_xenial'
2018-12-28 08:45:26,680 [salt.state       :300 ][INFO    ][10862] File changed:
New file
2018-12-28 08:45:26,680 [salt.state       :1951][INFO    ][10862] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:45:26.680563 duration_in_ms=70.794
2018-12-28 08:45:26,681 [salt.state       :1780][INFO    ][10862] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:45:26.681144
2018-12-28 08:45:26,681 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2018-12-28 08:45:26,699 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_arm64_generic_xenial'
2018-12-28 08:45:26,770 [salt.state       :300 ][INFO    ][10862] File changed:
New file
2018-12-28 08:45:26,771 [salt.state       :1951][INFO    ][10862] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:45:26.771584 duration_in_ms=90.439
2018-12-28 08:45:26,772 [salt.state       :1780][INFO    ][10862] Running state [/root/.pgpass] at time 08:45:26.772165
2018-12-28 08:45:26,772 [salt.state       :1813][INFO    ][10862] Executing state file.managed for [/root/.pgpass]
2018-12-28 08:45:26,795 [salt.fileclient  :1219][INFO    ][10862] Fetching file from saltenv 'base', ** done ** 'maas/files/pgpass'
2018-12-28 08:45:26,829 [salt.state       :300 ][INFO    ][10862] File changed:
New file
2018-12-28 08:45:26,830 [salt.state       :1951][INFO    ][10862] Completed state [/root/.pgpass] at time 08:45:26.830216 duration_in_ms=58.05
2018-12-28 08:45:26,836 [salt.state       :1780][INFO    ][10862] Running state [maas-region syncdb --noinput] at time 08:45:26.836135
2018-12-28 08:45:26,837 [salt.state       :1813][INFO    ][10862] Executing state cmd.run for [maas-region syncdb --noinput]
2018-12-28 08:45:26,838 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command 'maas-region syncdb --noinput' in directory '/root'
2018-12-28 08:45:29,929 [salt.state       :300 ][INFO    ][10862] {'pid': 17651, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, sessions, contenttypes, piston3, auth, sites, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2018-12-28 08:45:29,929 [salt.state       :1951][INFO    ][10862] Completed state [maas-region syncdb --noinput] at time 08:45:29.929830 duration_in_ms=3093.695
2018-12-28 08:45:29,930 [salt.state       :2022][WARNING ][10862] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2018-12-28 08:45:29,932 [salt.state       :1780][INFO    ][10862] Running state [maas-regiond] at time 08:45:29.932167
2018-12-28 08:45:29,932 [salt.state       :1813][INFO    ][10862] Executing state service.running for [maas-regiond]
2018-12-28 08:45:29,933 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2018-12-28 08:45:29,949 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2018-12-28 08:45:29,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2018-12-28 08:45:29,988 [salt.state       :300 ][INFO    ][10862] The service maas-regiond is already running
2018-12-28 08:45:29,989 [salt.state       :1951][INFO    ][10862] Completed state [maas-regiond] at time 08:45:29.988944 duration_in_ms=56.777
2018-12-28 08:45:29,989 [salt.state       :1780][INFO    ][10862] Running state [maas-regiond] at time 08:45:29.989295
2018-12-28 08:45:29,989 [salt.state       :1813][INFO    ][10862] Executing state service.mod_watch for [maas-regiond]
2018-12-28 08:45:29,990 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2018-12-28 08:45:30,003 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'maas-regiond.service'] in directory '/root'
2018-12-28 08:45:30,080 [salt.state       :300 ][INFO    ][10862] {'maas-regiond': True}
2018-12-28 08:45:30,081 [salt.state       :1951][INFO    ][10862] Completed state [maas-regiond] at time 08:45:30.081292 duration_in_ms=91.997
2018-12-28 08:45:30,083 [salt.state       :1780][INFO    ][10862] Running state [bind9] at time 08:45:30.083325
2018-12-28 08:45:30,083 [salt.state       :1813][INFO    ][10862] Executing state service.running for [bind9]
2018-12-28 08:45:30,084 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2018-12-28 08:45:30,105 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2018-12-28 08:45:30,122 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2018-12-28 08:45:30,138 [salt.state       :300 ][INFO    ][10862] The service bind9 is already running
2018-12-28 08:45:30,139 [salt.state       :1951][INFO    ][10862] Completed state [bind9] at time 08:45:30.139225 duration_in_ms=55.899
2018-12-28 08:45:30,139 [salt.state       :1780][INFO    ][10862] Running state [bind9] at time 08:45:30.139562
2018-12-28 08:45:30,141 [salt.state       :1813][INFO    ][10862] Executing state service.mod_watch for [bind9]
2018-12-28 08:45:30,142 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2018-12-28 08:45:30,159 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'bind9.service'] in directory '/root'
2018-12-28 08:45:30,219 [salt.state       :300 ][INFO    ][10862] {'bind9': True}
2018-12-28 08:45:30,219 [salt.state       :1951][INFO    ][10862] Completed state [bind9] at time 08:45:30.219545 duration_in_ms=79.982
2018-12-28 08:45:30,222 [salt.state       :1780][INFO    ][10862] Running state [apache2] at time 08:45:30.222907
2018-12-28 08:45:30,223 [salt.state       :1813][INFO    ][10862] Executing state service.running for [apache2]
2018-12-28 08:45:30,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2018-12-28 08:45:30,243 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2018-12-28 08:45:30,261 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2018-12-28 08:45:30,283 [salt.state       :300 ][INFO    ][10862] The service apache2 is already running
2018-12-28 08:45:30,284 [salt.state       :1951][INFO    ][10862] Completed state [apache2] at time 08:45:30.284227 duration_in_ms=61.32
2018-12-28 08:45:30,284 [salt.state       :1780][INFO    ][10862] Running state [apache2] at time 08:45:30.284540
2018-12-28 08:45:30,284 [salt.state       :1813][INFO    ][10862] Executing state service.mod_watch for [apache2]
2018-12-28 08:45:30,285 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2018-12-28 08:45:30,305 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'apache2.service'] in directory '/root'
2018-12-28 08:45:31,569 [salt.state       :300 ][INFO    ][10862] {'apache2': True}
2018-12-28 08:45:31,569 [salt.state       :1951][INFO    ][10862] Completed state [apache2] at time 08:45:31.569567 duration_in_ms=1285.027
2018-12-28 08:45:31,571 [salt.state       :1780][INFO    ][10862] Running state [maasng.wait_for_http_code] at time 08:45:31.571121
2018-12-28 08:45:31,571 [salt.state       :1813][INFO    ][10862] Executing state module.run for [maasng.wait_for_http_code]
2018-12-28 08:45:31,572 [salt.utils.decorators:613 ][WARNING ][10862] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:45:31,576 [salt.loaded.ext.module.maasng:1435][INFO    ][10862] Waiting for api:http://localhost:5240/MAAS
sleep for:5s Left:120.0/120s
2018-12-28 08:45:33,311 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084533290192
2018-12-28 08:45:33,351 [salt.minion      :1432][INFO    ][18004] Starting a new job with PID 18004
2018-12-28 08:45:33,389 [salt.minion      :1711][INFO    ][18004] Returning information for job: 20181228084533290192
2018-12-28 08:45:36,698 [salt.state       :300 ][INFO    ][10862] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2018-12-28 08:45:36,699 [salt.state       :1951][INFO    ][10862] Completed state [maasng.wait_for_http_code] at time 08:45:36.699507 duration_in_ms=5128.382
2018-12-28 08:45:36,701 [salt.state       :1780][INFO    ][10862] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:45:36.701164
2018-12-28 08:45:36,701 [salt.state       :1813][INFO    ][10862] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2018-12-28 08:45:36,703 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command 'maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin' in directory '/root'
2018-12-28 08:45:38,663 [salt.state       :300 ][INFO    ][10862] {'pid': 18126, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 08:45:38,663 [salt.state       :1951][INFO    ][10862] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:45:38.663881 duration_in_ms=1962.716
2018-12-28 08:45:38,665 [salt.state       :1780][INFO    ][10862] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:45:38.665055
2018-12-28 08:45:38,665 [salt.state       :1813][INFO    ][10862] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 08:45:38,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10862] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 08:45:41,245 [salt.state       :300 ][INFO    ][10862] {'pid': 18174, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 08:45:41,247 [salt.state       :1951][INFO    ][10862] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:45:41.247080 duration_in_ms=2582.024
2018-12-28 08:45:41,257 [salt.state       :1780][INFO    ][10862] Running state [maas_region_boot_source_resources_mirror] at time 08:45:41.257026
2018-12-28 08:45:41,257 [salt.state       :1813][INFO    ][10862] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2018-12-28 08:45:41,447 [salt.loaded.ext.module.maasng:1508][INFO    ][10862] Removing boot-source:http://images.maas.io/ephemeral-v3/daily/
2018-12-28 08:45:43,383 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084543365589
2018-12-28 08:45:43,423 [salt.minion      :1432][INFO    ][18216] Starting a new job with PID 18216
2018-12-28 08:45:43,473 [salt.minion      :1711][INFO    ][18216] Returning information for job: 20181228084543365589
2018-12-28 08:45:43,885 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2018-12-28 08:45:48,931 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2018-12-28 08:45:53,463 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084553440921
2018-12-28 08:45:53,525 [salt.minion      :1432][INFO    ][18278] Starting a new job with PID 18278
2018-12-28 08:45:53,551 [salt.minion      :1711][INFO    ][18278] Returning information for job: 20181228084553440921
2018-12-28 08:45:53,976 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2018-12-28 08:45:59,033 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2018-12-28 08:46:03,540 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084603517853
2018-12-28 08:46:03,619 [salt.minion      :1432][INFO    ][18338] Starting a new job with PID 18338
2018-12-28 08:46:03,649 [salt.minion      :1711][INFO    ][18338] Returning information for job: 20181228084603517853
2018-12-28 08:46:04,077 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2018-12-28 08:46:09,119 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2018-12-28 08:46:13,615 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084613598558
2018-12-28 08:46:13,647 [salt.minion      :1432][INFO    ][18382] Starting a new job with PID 18382
2018-12-28 08:46:13,687 [salt.minion      :1711][INFO    ][18382] Returning information for job: 20181228084613598558
2018-12-28 08:46:14,170 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2018-12-28 08:46:19,218 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:865.0/900s
2018-12-28 08:46:23,678 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084623662248
2018-12-28 08:46:23,705 [salt.minion      :1432][INFO    ][18438] Starting a new job with PID 18438
2018-12-28 08:46:23,741 [salt.minion      :1711][INFO    ][18438] Returning information for job: 20181228084623662248
2018-12-28 08:46:24,264 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:860.0/900s
2018-12-28 08:46:29,322 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:855.0/900s
2018-12-28 08:46:33,744 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084633728697
2018-12-28 08:46:33,785 [salt.minion      :1432][INFO    ][18521] Starting a new job with PID 18521
2018-12-28 08:46:33,845 [salt.minion      :1711][INFO    ][18521] Returning information for job: 20181228084633728697
2018-12-28 08:46:34,369 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2018-12-28 08:46:39,421 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2018-12-28 08:46:43,816 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084643798423
2018-12-28 08:46:44,046 [salt.minion      :1432][INFO    ][18578] Starting a new job with PID 18578
2018-12-28 08:46:44,190 [salt.minion      :1711][INFO    ][18578] Returning information for job: 20181228084643798423
2018-12-28 08:46:44,478 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2018-12-28 08:46:49,526 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2018-12-28 08:46:53,999 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084653976182
2018-12-28 08:46:54,043 [salt.minion      :1432][INFO    ][18633] Starting a new job with PID 18633
2018-12-28 08:46:54,078 [salt.minion      :1711][INFO    ][18633] Returning information for job: 20181228084653976182
2018-12-28 08:46:54,586 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2018-12-28 08:46:59,631 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:824.0/900s
2018-12-28 08:47:04,084 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084704064383
2018-12-28 08:47:04,157 [salt.minion      :1432][INFO    ][18776] Starting a new job with PID 18776
2018-12-28 08:47:04,188 [salt.minion      :1711][INFO    ][18776] Returning information for job: 20181228084704064383
2018-12-28 08:47:04,995 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:819.0/900s
2018-12-28 08:47:10,046 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:814.0/900s
2018-12-28 08:47:14,168 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084714146569
2018-12-28 08:47:14,214 [salt.minion      :1432][INFO    ][18902] Starting a new job with PID 18902
2018-12-28 08:47:14,256 [salt.minion      :1711][INFO    ][18902] Returning information for job: 20181228084714146569
2018-12-28 08:47:15,108 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:809.0/900s
2018-12-28 08:47:20,314 [salt.state       :300 ][INFO    ][10862] {'new': 'boot resource http://images.maas.io/ephemeral-v3/daily was created', 'changes': {'new': 'Boot-resource http://images.maas.io/ephemeral-v3/daily/ deleted'}}
2018-12-28 08:47:20,316 [salt.state       :1951][INFO    ][10862] Completed state [maas_region_boot_source_resources_mirror] at time 08:47:20.316112 duration_in_ms=99059.084
2018-12-28 08:47:20,318 [salt.state       :1780][INFO    ][10862] Running state [maasng.boot_resources_import] at time 08:47:20.318837
2018-12-28 08:47:20,320 [salt.state       :1813][INFO    ][10862] Executing state module.run for [maasng.boot_resources_import]
2018-12-28 08:47:20,321 [salt.utils.decorators:613 ][WARNING ][10862] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:47:21,766 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2018-12-28 08:47:24,253 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084724233974
2018-12-28 08:47:24,307 [salt.minion      :1432][INFO    ][18947] Starting a new job with PID 18947
2018-12-28 08:47:24,341 [salt.minion      :1711][INFO    ][18947] Returning information for job: 20181228084724233974
2018-12-28 08:47:26,823 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2018-12-28 08:47:31,925 [salt.state       :300 ][INFO    ][10862] {'ret': True}
2018-12-28 08:47:31,925 [salt.state       :1951][INFO    ][10862] Completed state [maasng.boot_resources_import] at time 08:47:31.925441 duration_in_ms=11606.605
2018-12-28 08:47:31,926 [salt.state       :1780][INFO    ][10862] Running state [maas_region_boot_sources_selection_xenial] at time 08:47:31.926818
2018-12-28 08:47:31,927 [salt.state       :1813][INFO    ][10862] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2018-12-28 08:47:34,392 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084734373340
2018-12-28 08:47:34,431 [salt.minion      :1432][INFO    ][19019] Starting a new job with PID 19019
2018-12-28 08:47:34,470 [salt.minion      :1711][INFO    ][19019] Returning information for job: 20181228084734373340
2018-12-28 08:47:37,228 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2018-12-28 08:47:42,300 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2018-12-28 08:47:44,488 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084744466473
2018-12-28 08:47:44,539 [salt.minion      :1432][INFO    ][19054] Starting a new job with PID 19054
2018-12-28 08:47:44,579 [salt.minion      :1711][INFO    ][19054] Returning information for job: 20181228084744466473
2018-12-28 08:47:47,374 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2018-12-28 08:47:52,435 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2018-12-28 08:47:54,575 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084754556811
2018-12-28 08:47:54,618 [salt.minion      :1432][INFO    ][19062] Starting a new job with PID 19062
2018-12-28 08:47:54,662 [salt.minion      :1711][INFO    ][19062] Returning information for job: 20181228084754556811
2018-12-28 08:47:57,487 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2018-12-28 08:48:02,604 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2018-12-28 08:48:04,676 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084804650503
2018-12-28 08:48:04,724 [salt.minion      :1432][INFO    ][19094] Starting a new job with PID 19094
2018-12-28 08:48:04,772 [salt.minion      :1711][INFO    ][19094] Returning information for job: 20181228084804650503
2018-12-28 08:48:07,658 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2018-12-28 08:48:12,713 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:864.0/900s
2018-12-28 08:48:14,764 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084814746555
2018-12-28 08:48:14,805 [salt.minion      :1432][INFO    ][19105] Starting a new job with PID 19105
2018-12-28 08:48:14,857 [salt.minion      :1711][INFO    ][19105] Returning information for job: 20181228084814746555
2018-12-28 08:48:17,764 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:859.0/900s
2018-12-28 08:48:22,827 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:854.0/900s
2018-12-28 08:48:24,859 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084824840167
2018-12-28 08:48:24,895 [salt.minion      :1432][INFO    ][19132] Starting a new job with PID 19132
2018-12-28 08:48:24,939 [salt.minion      :1711][INFO    ][19132] Returning information for job: 20181228084824840167
2018-12-28 08:48:27,898 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2018-12-28 08:48:32,947 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2018-12-28 08:48:34,963 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084834946858
2018-12-28 08:48:34,999 [salt.minion      :1432][INFO    ][19152] Starting a new job with PID 19152
2018-12-28 08:48:35,039 [salt.minion      :1711][INFO    ][19152] Returning information for job: 20181228084834946858
2018-12-28 08:48:38,004 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2018-12-28 08:48:43,055 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2018-12-28 08:48:45,116 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084845098388
2018-12-28 08:48:45,163 [salt.minion      :1432][INFO    ][19163] Starting a new job with PID 19163
2018-12-28 08:48:45,205 [salt.minion      :1711][INFO    ][19163] Returning information for job: 20181228084845098388
2018-12-28 08:48:48,117 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2018-12-28 08:48:53,164 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:824.0/900s
2018-12-28 08:48:55,266 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084855245264
2018-12-28 08:48:55,312 [salt.minion      :1432][INFO    ][19176] Starting a new job with PID 19176
2018-12-28 08:48:55,350 [salt.minion      :1711][INFO    ][19176] Returning information for job: 20181228084855245264
2018-12-28 08:48:58,218 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:819.0/900s
2018-12-28 08:49:03,270 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:814.0/900s
2018-12-28 08:49:05,378 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084905362060
2018-12-28 08:49:05,417 [salt.minion      :1432][INFO    ][19198] Starting a new job with PID 19198
2018-12-28 08:49:05,458 [salt.minion      :1711][INFO    ][19198] Returning information for job: 20181228084905362060
2018-12-28 08:49:08,339 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:809.0/900s
2018-12-28 08:49:13,418 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:804.0/900s
2018-12-28 08:49:15,492 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084915474551
2018-12-28 08:49:15,524 [salt.minion      :1432][INFO    ][19208] Starting a new job with PID 19208
2018-12-28 08:49:15,567 [salt.minion      :1711][INFO    ][19208] Returning information for job: 20181228084915474551
2018-12-28 08:49:18,499 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:799.0/900s
2018-12-28 08:49:23,569 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:794.0/900s
2018-12-28 08:49:25,672 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084925654517
2018-12-28 08:49:25,723 [salt.minion      :1432][INFO    ][19232] Starting a new job with PID 19232
2018-12-28 08:49:25,760 [salt.minion      :1711][INFO    ][19232] Returning information for job: 20181228084925654517
2018-12-28 08:49:28,631 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:789.0/900s
2018-12-28 08:49:33,700 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:783.0/900s
2018-12-28 08:49:35,803 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084935780198
2018-12-28 08:49:35,839 [salt.minion      :1432][INFO    ][19255] Starting a new job with PID 19255
2018-12-28 08:49:35,893 [salt.minion      :1711][INFO    ][19255] Returning information for job: 20181228084935780198
2018-12-28 08:49:38,756 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:778.0/900s
2018-12-28 08:49:43,809 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:773.0/900s
2018-12-28 08:49:45,929 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084945907484
2018-12-28 08:49:45,977 [salt.minion      :1432][INFO    ][19265] Starting a new job with PID 19265
2018-12-28 08:49:46,015 [salt.minion      :1711][INFO    ][19265] Returning information for job: 20181228084945907484
2018-12-28 08:49:48,866 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:768.0/900s
2018-12-28 08:49:53,952 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:763.0/900s
2018-12-28 08:49:56,054 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228084956036807
2018-12-28 08:49:56,092 [salt.minion      :1432][INFO    ][19287] Starting a new job with PID 19287
2018-12-28 08:49:56,138 [salt.minion      :1711][INFO    ][19287] Returning information for job: 20181228084956036807
2018-12-28 08:49:59,013 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:758.0/900s
2018-12-28 08:50:04,086 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:753.0/900s
2018-12-28 08:50:06,183 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085006160300
2018-12-28 08:50:06,311 [salt.minion      :1432][INFO    ][19312] Starting a new job with PID 19312
2018-12-28 08:50:06,358 [salt.minion      :1711][INFO    ][19312] Returning information for job: 20181228085006160300
2018-12-28 08:50:09,158 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:748.0/900s
2018-12-28 08:50:14,211 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:743.0/900s
2018-12-28 08:50:16,361 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085016345202
2018-12-28 08:50:16,399 [salt.minion      :1432][INFO    ][19321] Starting a new job with PID 19321
2018-12-28 08:50:16,440 [salt.minion      :1711][INFO    ][19321] Returning information for job: 20181228085016345202
2018-12-28 08:50:19,265 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:738.0/900s
2018-12-28 08:50:24,318 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:733.0/900s
2018-12-28 08:50:26,508 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085026483813
2018-12-28 08:50:26,548 [salt.minion      :1432][INFO    ][19345] Starting a new job with PID 19345
2018-12-28 08:50:26,582 [salt.minion      :1711][INFO    ][19345] Returning information for job: 20181228085026483813
2018-12-28 08:50:29,375 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:728.0/900s
2018-12-28 08:50:34,438 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:723.0/900s
2018-12-28 08:50:36,714 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085036697416
2018-12-28 08:50:36,750 [salt.minion      :1432][INFO    ][19366] Starting a new job with PID 19366
2018-12-28 08:50:36,792 [salt.minion      :1711][INFO    ][19366] Returning information for job: 20181228085036697416
2018-12-28 08:50:39,507 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:718.0/900s
2018-12-28 08:50:44,572 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:713.0/900s
2018-12-28 08:50:46,739 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085046716311
2018-12-28 08:50:46,782 [salt.minion      :1432][INFO    ][19376] Starting a new job with PID 19376
2018-12-28 08:50:46,829 [salt.minion      :1711][INFO    ][19376] Returning information for job: 20181228085046716311
2018-12-28 08:50:49,622 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:708.0/900s
2018-12-28 08:50:54,669 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:703.0/900s
2018-12-28 08:50:56,897 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085056879619
2018-12-28 08:50:56,956 [salt.minion      :1432][INFO    ][19393] Starting a new job with PID 19393
2018-12-28 08:50:56,992 [salt.minion      :1711][INFO    ][19393] Returning information for job: 20181228085056879619
2018-12-28 08:50:59,724 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:697.0/900s
2018-12-28 08:51:04,789 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:692.0/900s
2018-12-28 08:51:07,042 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085107026756
2018-12-28 08:51:07,084 [salt.minion      :1432][INFO    ][19422] Starting a new job with PID 19422
2018-12-28 08:51:07,128 [salt.minion      :1711][INFO    ][19422] Returning information for job: 20181228085107026756
2018-12-28 08:51:09,836 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:687.0/900s
2018-12-28 08:51:14,890 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:682.0/900s
2018-12-28 08:51:17,210 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085117191542
2018-12-28 08:51:17,240 [salt.minion      :1432][INFO    ][19433] Starting a new job with PID 19433
2018-12-28 08:51:17,287 [salt.minion      :1711][INFO    ][19433] Returning information for job: 20181228085117191542
2018-12-28 08:51:19,962 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:677.0/900s
2018-12-28 08:51:25,013 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:672.0/900s
2018-12-28 08:51:27,230 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085127212290
2018-12-28 08:51:27,269 [salt.minion      :1432][INFO    ][19457] Starting a new job with PID 19457
2018-12-28 08:51:27,305 [salt.minion      :1711][INFO    ][19457] Returning information for job: 20181228085127212290
2018-12-28 08:51:30,081 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:667.0/900s
2018-12-28 08:51:35,151 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:662.0/900s
2018-12-28 08:51:37,290 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085137270213
2018-12-28 08:51:37,338 [salt.minion      :1432][INFO    ][19478] Starting a new job with PID 19478
2018-12-28 08:51:37,381 [salt.minion      :1711][INFO    ][19478] Returning information for job: 20181228085137270213
2018-12-28 08:51:40,213 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:657.0/900s
2018-12-28 08:51:45,271 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:652.0/900s
2018-12-28 08:51:47,464 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085147441705
2018-12-28 08:51:47,520 [salt.minion      :1432][INFO    ][19488] Starting a new job with PID 19488
2018-12-28 08:51:47,546 [salt.minion      :1711][INFO    ][19488] Returning information for job: 20181228085147441705
2018-12-28 08:51:50,335 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:647.0/900s
2018-12-28 08:51:55,391 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:642.0/900s
2018-12-28 08:51:57,634 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085157617860
2018-12-28 08:51:57,666 [salt.minion      :1432][INFO    ][19503] Starting a new job with PID 19503
2018-12-28 08:51:57,714 [salt.minion      :1711][INFO    ][19503] Returning information for job: 20181228085157617860
2018-12-28 08:52:00,429 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:637.0/900s
2018-12-28 08:52:05,497 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:632.0/900s
2018-12-28 08:52:07,840 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085207819702
2018-12-28 08:52:07,892 [salt.minion      :1432][INFO    ][19530] Starting a new job with PID 19530
2018-12-28 08:52:07,931 [salt.minion      :1711][INFO    ][19530] Returning information for job: 20181228085207819702
2018-12-28 08:52:10,564 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:627.0/900s
2018-12-28 08:52:15,636 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:622.0/900s
2018-12-28 08:52:18,051 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085218027678
2018-12-28 08:52:18,089 [salt.minion      :1432][INFO    ][19540] Starting a new job with PID 19540
2018-12-28 08:52:18,141 [salt.minion      :1711][INFO    ][19540] Returning information for job: 20181228085218027678
2018-12-28 08:52:20,703 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:616.0/900s
2018-12-28 08:52:25,759 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:611.0/900s
2018-12-28 08:52:28,255 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085228232961
2018-12-28 08:52:28,302 [salt.minion      :1432][INFO    ][19564] Starting a new job with PID 19564
2018-12-28 08:52:28,343 [salt.minion      :1711][INFO    ][19564] Returning information for job: 20181228085228232961
2018-12-28 08:52:30,820 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:606.0/900s
2018-12-28 08:52:35,887 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:601.0/900s
2018-12-28 08:52:38,456 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085238433885
2018-12-28 08:52:38,500 [salt.minion      :1432][INFO    ][19585] Starting a new job with PID 19585
2018-12-28 08:52:38,538 [salt.minion      :1711][INFO    ][19585] Returning information for job: 20181228085238433885
2018-12-28 08:52:40,940 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:596.0/900s
2018-12-28 08:52:45,997 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:591.0/900s
2018-12-28 08:52:48,660 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085248643309
2018-12-28 08:52:48,703 [salt.minion      :1432][INFO    ][19595] Starting a new job with PID 19595
2018-12-28 08:52:48,738 [salt.minion      :1711][INFO    ][19595] Returning information for job: 20181228085248643309
2018-12-28 08:52:51,050 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:586.0/900s
2018-12-28 08:52:56,105 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:581.0/900s
2018-12-28 08:52:58,880 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085258865247
2018-12-28 08:52:58,913 [salt.minion      :1432][INFO    ][19609] Starting a new job with PID 19609
2018-12-28 08:52:58,959 [salt.minion      :1711][INFO    ][19609] Returning information for job: 20181228085258865247
2018-12-28 08:53:01,158 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:576.0/900s
2018-12-28 08:53:06,209 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:571.0/900s
2018-12-28 08:53:09,098 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085309081825
2018-12-28 08:53:09,129 [salt.minion      :1432][INFO    ][19637] Starting a new job with PID 19637
2018-12-28 08:53:09,169 [salt.minion      :1711][INFO    ][19637] Returning information for job: 20181228085309081825
2018-12-28 08:53:11,264 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:566.0/900s
2018-12-28 08:53:16,327 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:561.0/900s
2018-12-28 08:53:19,321 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085319301444
2018-12-28 08:53:19,353 [salt.minion      :1432][INFO    ][19649] Starting a new job with PID 19649
2018-12-28 08:53:19,400 [salt.minion      :1711][INFO    ][19649] Returning information for job: 20181228085319301444
2018-12-28 08:53:21,403 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:556.0/900s
2018-12-28 08:53:26,452 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:551.0/900s
2018-12-28 08:53:29,551 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085329526491
2018-12-28 08:53:29,599 [salt.minion      :1432][INFO    ][19674] Starting a new job with PID 19674
2018-12-28 08:53:29,644 [salt.minion      :1711][INFO    ][19674] Returning information for job: 20181228085329526491
2018-12-28 08:53:31,522 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:546.0/900s
2018-12-28 08:53:36,591 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:541.0/900s
2018-12-28 08:53:39,609 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085339590055
2018-12-28 08:53:39,675 [salt.minion      :1432][INFO    ][19697] Starting a new job with PID 19697
2018-12-28 08:53:39,705 [salt.minion      :1711][INFO    ][19697] Returning information for job: 20181228085339590055
2018-12-28 08:53:41,649 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:536.0/900s
2018-12-28 08:53:46,712 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:530.0/900s
2018-12-28 08:53:49,641 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085349624896
2018-12-28 08:53:49,686 [salt.minion      :1432][INFO    ][19706] Starting a new job with PID 19706
2018-12-28 08:53:49,725 [salt.minion      :1711][INFO    ][19706] Returning information for job: 20181228085349624896
2018-12-28 08:53:51,762 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:525.0/900s
2018-12-28 08:53:56,821 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:520.0/900s
2018-12-28 08:53:59,672 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085359654196
2018-12-28 08:53:59,709 [salt.minion      :1432][INFO    ][19721] Starting a new job with PID 19721
2018-12-28 08:53:59,756 [salt.minion      :1711][INFO    ][19721] Returning information for job: 20181228085359654196
2018-12-28 08:54:01,881 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:515.0/900s
2018-12-28 08:54:06,949 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:510.0/900s
2018-12-28 08:54:09,724 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085409696813
2018-12-28 08:54:09,775 [salt.minion      :1432][INFO    ][19747] Starting a new job with PID 19747
2018-12-28 08:54:09,820 [salt.minion      :1711][INFO    ][19747] Returning information for job: 20181228085409696813
2018-12-28 08:54:12,007 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:505.0/900s
2018-12-28 08:54:17,081 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:500.0/900s
2018-12-28 08:54:19,818 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085419792967
2018-12-28 08:54:19,869 [salt.minion      :1432][INFO    ][19754] Starting a new job with PID 19754
2018-12-28 08:54:19,916 [salt.minion      :1711][INFO    ][19754] Returning information for job: 20181228085419792967
2018-12-28 08:54:22,134 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:495.0/900s
2018-12-28 08:54:27,191 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:490.0/900s
2018-12-28 08:54:29,884 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085429857379
2018-12-28 08:54:29,935 [salt.minion      :1432][INFO    ][19780] Starting a new job with PID 19780
2018-12-28 08:54:29,973 [salt.minion      :1711][INFO    ][19780] Returning information for job: 20181228085429857379
2018-12-28 08:54:32,236 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:485.0/900s
2018-12-28 08:54:37,315 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:480.0/900s
2018-12-28 08:54:40,025 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085440003576
2018-12-28 08:54:40,077 [salt.minion      :1432][INFO    ][19801] Starting a new job with PID 19801
2018-12-28 08:54:40,124 [salt.minion      :1711][INFO    ][19801] Returning information for job: 20181228085440003576
2018-12-28 08:54:42,371 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:475.0/900s
2018-12-28 08:54:47,426 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:470.0/900s
2018-12-28 08:54:50,092 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085450071764
2018-12-28 08:54:50,131 [salt.minion      :1432][INFO    ][19833] Starting a new job with PID 19833
2018-12-28 08:54:50,175 [salt.minion      :1711][INFO    ][19833] Returning information for job: 20181228085450071764
2018-12-28 08:54:52,477 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:465.0/900s
2018-12-28 08:54:57,538 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:460.0/900s
2018-12-28 08:55:00,177 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085500153281
2018-12-28 08:55:00,237 [salt.minion      :1432][INFO    ][19847] Starting a new job with PID 19847
2018-12-28 08:55:00,285 [salt.minion      :1711][INFO    ][19847] Returning information for job: 20181228085500153281
2018-12-28 08:55:02,578 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:455.0/900s
2018-12-28 08:55:07,630 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:450.0/900s
2018-12-28 08:55:10,268 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085510249507
2018-12-28 08:55:10,327 [salt.minion      :1432][INFO    ][19876] Starting a new job with PID 19876
2018-12-28 08:55:10,354 [salt.minion      :1711][INFO    ][19876] Returning information for job: 20181228085510249507
2018-12-28 08:55:12,677 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:445.0/900s
2018-12-28 08:55:17,732 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:439.0/900s
2018-12-28 08:55:20,362 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085520341721
2018-12-28 08:55:20,410 [salt.minion      :1432][INFO    ][19883] Starting a new job with PID 19883
2018-12-28 08:55:20,444 [salt.minion      :1711][INFO    ][19883] Returning information for job: 20181228085520341721
2018-12-28 08:55:22,781 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:434.0/900s
2018-12-28 08:55:27,840 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:429.0/900s
2018-12-28 08:55:30,473 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085530434361
2018-12-28 08:55:30,525 [salt.minion      :1432][INFO    ][19915] Starting a new job with PID 19915
2018-12-28 08:55:30,559 [salt.minion      :1711][INFO    ][19915] Returning information for job: 20181228085530434361
2018-12-28 08:55:32,889 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:424.0/900s
2018-12-28 08:55:37,956 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:419.0/900s
2018-12-28 08:55:40,630 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085540613898
2018-12-28 08:55:40,662 [salt.minion      :1432][INFO    ][19956] Starting a new job with PID 19956
2018-12-28 08:55:40,701 [salt.minion      :1711][INFO    ][19956] Returning information for job: 20181228085540613898
2018-12-28 08:55:43,005 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:414.0/900s
2018-12-28 08:55:48,062 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:409.0/900s
2018-12-28 08:55:50,741 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085550715925
2018-12-28 08:55:50,779 [salt.minion      :1432][INFO    ][19971] Starting a new job with PID 19971
2018-12-28 08:55:50,815 [salt.minion      :1711][INFO    ][19971] Returning information for job: 20181228085550715925
2018-12-28 08:55:53,115 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:404.0/900s
2018-12-28 08:55:58,173 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:399.0/900s
2018-12-28 08:56:00,857 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085600830776
2018-12-28 08:56:00,899 [salt.minion      :1432][INFO    ][19987] Starting a new job with PID 19987
2018-12-28 08:56:00,940 [salt.minion      :1711][INFO    ][19987] Returning information for job: 20181228085600830776
2018-12-28 08:56:03,236 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:394.0/900s
2018-12-28 08:56:08,314 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:389.0/900s
2018-12-28 08:56:10,923 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085610896863
2018-12-28 08:56:10,987 [salt.minion      :1432][INFO    ][20012] Starting a new job with PID 20012
2018-12-28 08:56:11,018 [salt.minion      :1711][INFO    ][20012] Returning information for job: 20181228085610896863
2018-12-28 08:56:13,385 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:384.0/900s
2018-12-28 08:56:18,464 [salt.loaded.ext.module.maasng:1600][INFO    ][10862] Waiting boot-resources import done
sleep for:5s Left:379.0/900s
2018-12-28 08:56:20,957 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085620935860
2018-12-28 08:56:21,009 [salt.minion      :1432][INFO    ][20032] Starting a new job with PID 20032
2018-12-28 08:56:21,049 [salt.minion      :1711][INFO    ][20032] Returning information for job: 20181228085620935860
2018-12-28 08:56:23,581 [salt.state       :300 ][INFO    ][10862] boot-source selection for http://images.maas.io/ephemeral-v3/daily was created
2018-12-28 08:56:23,582 [salt.state       :1951][INFO    ][10862] Completed state [maas_region_boot_sources_selection_xenial] at time 08:56:23.582412 duration_in_ms=531655.587
2018-12-28 08:56:23,584 [salt.state       :1780][INFO    ][10862] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 08:56:23.584784
2018-12-28 08:56:23,585 [salt.state       :1813][INFO    ][10862] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2018-12-28 08:56:23,586 [salt.utils.decorators:613 ][WARNING ][10862] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:56:23,587 [salt.loaded.ext.module.maasng:1771][INFO    ][10862] boot-sources sync initiated for ALL Rack's
2018-12-28 08:56:24,223 [salt.loaded.ext.module.maasng:1878][INFO    ][10862] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2018-12-28 08:56:29,567 [salt.loaded.ext.module.maasng:1878][INFO    ][10862] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:894.0/900s
2018-12-28 08:56:31,103 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085631085156
2018-12-28 08:56:31,290 [salt.minion      :1432][INFO    ][20065] Starting a new job with PID 20065
2018-12-28 08:56:31,408 [salt.minion      :1711][INFO    ][20065] Returning information for job: 20181228085631085156
2018-12-28 08:56:34,939 [salt.loaded.ext.module.maasng:1878][INFO    ][10862] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2018-12-28 08:56:40,200 [salt.loaded.ext.module.maasng:1878][INFO    ][10862] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:884.0/900s
2018-12-28 08:56:41,265 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085641245645
2018-12-28 08:56:41,324 [salt.minion      :1432][INFO    ][20100] Starting a new job with PID 20100
2018-12-28 08:56:41,366 [salt.minion      :1711][INFO    ][20100] Returning information for job: 20181228085641245645
2018-12-28 08:56:46,033 [salt.state       :300 ][INFO    ][10862] {'ret': True}
2018-12-28 08:56:46,034 [salt.state       :1951][INFO    ][10862] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 08:56:46.033975 duration_in_ms=22449.191
2018-12-28 08:56:46,037 [salt.state       :1780][INFO    ][10862] Running state [maas.process_maas_config] at time 08:56:46.037079
2018-12-28 08:56:46,037 [salt.state       :1813][INFO    ][10862] Executing state module.run for [maas.process_maas_config]
2018-12-28 08:56:46,037 [salt.utils.decorators:613 ][WARNING ][10862] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:56:46,038 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=enable_http_proxy value=True
2018-12-28 08:56:46,086 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=upstream_dns value=8.8.8.8
2018-12-28 08:56:46,142 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=commissioning_distro_series value=xenial
2018-12-28 08:56:46,206 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=default_osystem value=ubuntu
2018-12-28 08:56:46,265 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=active_discovery_interval value=600
2018-12-28 08:56:48,717 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=dnssec_validation value=no
2018-12-28 08:56:48,853 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=maas_name value=mas01
2018-12-28 08:56:48,911 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=network_discovery value=enabled
2018-12-28 08:56:49,026 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=enable_third_party_drivers value=True
2018-12-28 08:56:49,072 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=default_storage_layout value=lvm
2018-12-28 08:56:49,113 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=ntp_external_only value=True
2018-12-28 08:56:49,157 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=disk_erase_with_secure_erase value=False
2018-12-28 08:56:49,214 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=default_distro_series value=xenial
2018-12-28 08:56:49,275 [salt.loaded.ext.module.maas:92  ][INFO    ][10862] maasconfig name=default_min_hwe_kernel value=ga-16.04
2018-12-28 08:56:49,373 [salt.state       :300 ][INFO    ][10862] {'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']}}
2018-12-28 08:56:49,374 [salt.state       :1951][INFO    ][10862] Completed state [maas.process_maas_config] at time 08:56:49.373979 duration_in_ms=3336.9
2018-12-28 08:56:49,374 [salt.state       :1780][INFO    ][10862] Running state [pxe_admin] at time 08:56:49.374626
2018-12-28 08:56:49,374 [salt.state       :1813][INFO    ][10862] Executing state maasng.fabric_present for [pxe_admin]
2018-12-28 08:56:49,437 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{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': u'10.20.0.1', u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2018-12-28 08:56:49,509 [salt.loaded.ext.module.maasng:1008][WARNING ][10862] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2018-12-28 08:56:49,510 [salt.loaded.ext.module.maasng:1011][WARNING ][10862] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2018-12-28 08:56:49,577 [salt.state       :300 ][INFO    ][10862] {'new': 'Fabric  pxe_admin created', 'result': True}
2018-12-28 08:56:49,578 [salt.state       :1951][INFO    ][10862] Completed state [pxe_admin] at time 08:56:49.578139 duration_in_ms=203.511
2018-12-28 08:56:49,578 [salt.state       :1780][INFO    ][10862] Running state [vlan 0] at time 08:56:49.578570
2018-12-28 08:56:49,579 [salt.state       :1813][INFO    ][10862] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2018-12-28 08:56:49,628 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-28 08:56:49,723 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{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': u'10.20.0.1', u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2018-12-28 08:56:49,977 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{u'id': 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'relay_vlan': None, u'external_dhcp': u'10.20.0.1', u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None}, {u'id': 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': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u''}]
2018-12-28 08:56:50,042 [salt.state       :300 ][INFO    ][10862] {'new': 'Vlan untagged was updated'}
2018-12-28 08:56:50,042 [salt.state       :1951][INFO    ][10862] Completed state [vlan 0] at time 08:56:50.042380 duration_in_ms=463.811
2018-12-28 08:56:50,043 [salt.state       :1780][INFO    ][10862] Running state [192.168.11.0/24] at time 08:56:50.043359
2018-12-28 08:56:50,044 [salt.state       :1813][INFO    ][10862] Executing state maasng.subnet_present for [192.168.11.0/24]
2018-12-28 08:56:50,317 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-28 08:56:50,317 [salt.loaded.ext.module.maasng:1235][WARNING ][10862] Ignoring parameter vlan:0
2018-12-28 08:56:50,373 [salt.state       :300 ][INFO    ][10862] Subnet 192.168.11.0/24 has been updated for pxe_admin
2018-12-28 08:56:50,373 [salt.state       :1951][INFO    ][10862] Completed state [192.168.11.0/24] at time 08:56:50.373444 duration_in_ms=330.085
2018-12-28 08:56:50,374 [salt.state       :1780][INFO    ][10862] Running state [maas_create_iprange_1] at time 08:56:50.374339
2018-12-28 08:56:50,374 [salt.state       :1813][INFO    ][10862] Executing state maasng.iprange_present for [maas_create_iprange_1]
2018-12-28 08:56:50,522 [salt.state       :300 ][INFO    ][10862] {'new': 'Iprange: Type:dynamic: 192.168.11.38-192.168.11.254 has been created'}
2018-12-28 08:56:50,523 [salt.state       :1951][INFO    ][10862] Completed state [maas_create_iprange_1] at time 08:56:50.523254 duration_in_ms=148.914
2018-12-28 08:56:50,523 [salt.state       :1780][INFO    ][10862] Running state [vlan 0] at time 08:56:50.523626
2018-12-28 08:56:50,524 [salt.state       :1813][INFO    ][10862] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2018-12-28 08:56:50,596 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{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': u'10.20.0.1', u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'bqycpd', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2018-12-28 08:56:50,831 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-28 08:56:51,109 [salt.loaded.ext.module.maasng:945 ][INFO    ][10862] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-28 08:56:51,199 [salt.state       :300 ][INFO    ][10862] {'new': 'Vlan untagged was updated'}
2018-12-28 08:56:51,200 [salt.state       :1951][INFO    ][10862] Completed state [vlan 0] at time 08:56:51.200107 duration_in_ms=676.48
2018-12-28 08:56:51,200 [salt.state       :1780][INFO    ][10862] Running state [opnfv] at time 08:56:51.200899
2018-12-28 08:56:51,201 [salt.state       :1813][INFO    ][10862] Executing state maasng.sshkey_present for [opnfv]
2018-12-28 08:56:51,247 [salt.loaded.ext.module.maasng:1903][INFO    ][10862] []
2018-12-28 08:56:51,360 [salt.state       :300 ][INFO    ][10862] {'new': 'SSH Key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCwbsLV1UY13y2+2b7H9h6zOFMrcnumZvKOz6oqAXgttZjoKci01cqGRU8OMjob/9xeAOP2Cmu7HOBpRxda00X57yYx4UidSgEtlbOi7LLj2DuvJScix+rgPAd19aukdCiTuMmyLZQPMzVrdBxqzupJ5zqS3djSCllnQ2myEwswcSBn0Dpusgt3bnwdsCgI6B6ZgL9aR9DLnyMPMVroI6ZZH7aP7syIy1sPEsiJd3smWEULgeRElsuK+4I3YKG1Z1J2n80lmtR2gVD5tuKLFRRxnbjAqzyCEXQBTUVRc13SAFrH0b5bzFaqfxY1wdQPzP+dBSA+t25KcjnpTAAtL86H was added.'}
2018-12-28 08:56:51,361 [salt.state       :1951][INFO    ][10862] Completed state [opnfv] at time 08:56:51.361414 duration_in_ms=160.514
2018-12-28 08:56:51,367 [salt.minion      :1711][INFO    ][10862] Returning information for job: 20181228084201388387
2018-12-28 08:56:52,074 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228085652054403
2018-12-28 08:56:52,112 [salt.minion      :1432][INFO    ][20314] Starting a new job with PID 20314
2018-12-28 08:57:00,014 [salt.state       :915 ][INFO    ][20314] Loading fresh modules for state activity
2018-12-28 08:57:00,081 [salt.fileclient  :1219][INFO    ][20314] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2018-12-28 08:57:00,145 [salt.state       :1780][INFO    ][20314] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:57:00.145164
2018-12-28 08:57:00,145 [salt.state       :1813][INFO    ][20314] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 08:57:00,149 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20314] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 08:57:02,109 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085702087516
2018-12-28 08:57:02,325 [salt.minion      :1432][INFO    ][20379] Starting a new job with PID 20379
2018-12-28 08:57:02,395 [salt.minion      :1711][INFO    ][20379] Returning information for job: 20181228085702087516
2018-12-28 08:57:02,862 [salt.state       :300 ][INFO    ][20314] {'pid': 20367, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 08:57:02,864 [salt.state       :1951][INFO    ][20314] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:57:02.864399 duration_in_ms=2719.234
2018-12-28 08:57:02,868 [salt.state       :1780][INFO    ][20314] Running state [maas.process_machines] at time 08:57:02.868891
2018-12-28 08:57:02,869 [salt.state       :1813][INFO    ][20314] Executing state module.run for [maas.process_machines]
2018-12-28 08:57:02,870 [salt.utils.decorators:613 ][WARNING ][20314] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:57:02,965 [salt.loaded.ext.module.maas:412 ][WARNING ][20314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-28 08:57:02,966 [salt.loaded.ext.module.maas:92  ][INFO    ][20314] machine hostname=cmp002 power_type=ipmi mac_addresses=9c:b6:54:8a:10:18 power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2018-12-28 08:57:04,438 [salt.loaded.ext.module.maas:412 ][WARNING ][20314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-28 08:57:04,439 [salt.loaded.ext.module.maas:92  ][INFO    ][20314] machine hostname=cmp001 power_type=ipmi mac_addresses=9c:b6:54:8a:95:a0 power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2018-12-28 08:57:05,884 [salt.loaded.ext.module.maas:412 ][WARNING ][20314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-28 08:57:05,885 [salt.loaded.ext.module.maas:92  ][INFO    ][20314] machine hostname=kvm01 power_type=ipmi mac_addresses=14:58:d0:54:e7:88 power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2018-12-28 08:57:07,201 [salt.loaded.ext.module.maas:412 ][WARNING ][20314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-28 08:57:07,201 [salt.loaded.ext.module.maas:92  ][INFO    ][20314] machine hostname=kvm03 power_type=ipmi mac_addresses=14:58:d0:54:7a:28 power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2018-12-28 08:57:08,570 [salt.loaded.ext.module.maas:412 ][WARNING ][20314] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-28 08:57:08,572 [salt.loaded.ext.module.maas:92  ][INFO    ][20314] machine hostname=kvm02 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2018-12-28 08:57:09,889 [salt.state       :300 ][INFO    ][20314] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2018-12-28 08:57:09,889 [salt.state       :1951][INFO    ][20314] Completed state [maas.process_machines] at time 08:57:09.889810 duration_in_ms=7020.913
2018-12-28 08:57:09,898 [salt.minion      :1711][INFO    ][20314] Returning information for job: 20181228085652054403
2018-12-28 08:57:50,215 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228085750187825
2018-12-28 08:57:50,247 [salt.minion      :1432][INFO    ][20712] Starting a new job with PID 20712
2018-12-28 08:57:58,006 [salt.state       :915 ][INFO    ][20712] Loading fresh modules for state activity
2018-12-28 08:57:58,064 [salt.fileclient  :1219][INFO    ][20712] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2018-12-28 08:57:58,120 [salt.state       :1780][INFO    ][20712] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:57:58.120235
2018-12-28 08:57:58,120 [salt.state       :1813][INFO    ][20712] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 08:57:58,123 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20712] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 08:58:00,044 [salt.state       :300 ][INFO    ][20712] {'pid': 20726, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 08:58:00,045 [salt.state       :1951][INFO    ][20712] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:58:00.045636 duration_in_ms=1925.401
2018-12-28 08:58:00,049 [salt.state       :1780][INFO    ][20712] Running state [maas.wait_for_machine_status] at time 08:58:00.049383
2018-12-28 08:58:00,050 [salt.state       :1813][INFO    ][20712] Executing state module.run for [maas.wait_for_machine_status]
2018-12-28 08:58:00,051 [salt.utils.decorators:613 ][WARNING ][20712] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 08:58:00,324 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085800306466
2018-12-28 08:58:00,342 [salt.minion      :1432][INFO    ][20734] Starting a new job with PID 20734
2018-12-28 08:58:00,364 [salt.minion      :1711][INFO    ][20734] Returning information for job: 20181228085800306466
2018-12-28 08:58:00,976 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.09243679s left)
2018-12-28 08:58:10,526 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085810504068
2018-12-28 08:58:10,552 [salt.minion      :1432][INFO    ][20762] Starting a new job with PID 20762
2018-12-28 08:58:10,576 [salt.minion      :1711][INFO    ][20762] Returning information for job: 20181228085810504068
2018-12-28 08:58:20,738 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085820719432
2018-12-28 08:58:20,762 [salt.minion      :1432][INFO    ][20767] Starting a new job with PID 20767
2018-12-28 08:58:20,785 [salt.minion      :1711][INFO    ][20767] Returning information for job: 20181228085820719432
2018-12-28 08:58:30,946 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085830924545
2018-12-28 08:58:30,970 [salt.minion      :1432][INFO    ][20788] Starting a new job with PID 20788
2018-12-28 08:58:30,993 [salt.minion      :1711][INFO    ][20788] Returning information for job: 20181228085830924545
2018-12-28 08:58:31,842 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.22623992s left)
2018-12-28 08:58:41,155 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085841093705
2018-12-28 08:58:41,180 [salt.minion      :1432][INFO    ][20814] Starting a new job with PID 20814
2018-12-28 08:58:41,200 [salt.minion      :1711][INFO    ][20814] Returning information for job: 20181228085841093705
2018-12-28 08:58:51,160 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085851135759
2018-12-28 08:58:51,194 [salt.minion      :1432][INFO    ][20820] Starting a new job with PID 20820
2018-12-28 08:58:51,217 [salt.minion      :1711][INFO    ][20820] Returning information for job: 20181228085851135759
2018-12-28 08:59:01,381 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085901358182
2018-12-28 08:59:01,408 [salt.minion      :1432][INFO    ][20832] Starting a new job with PID 20832
2018-12-28 08:59:01,431 [salt.minion      :1711][INFO    ][20832] Returning information for job: 20181228085901358182
2018-12-28 08:59:02,781 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.287328s left)
2018-12-28 08:59:11,604 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085911580891
2018-12-28 08:59:11,629 [salt.minion      :1432][INFO    ][20861] Starting a new job with PID 20861
2018-12-28 08:59:11,652 [salt.minion      :1711][INFO    ][20861] Returning information for job: 20181228085911580891
2018-12-28 08:59:21,821 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085921797108
2018-12-28 08:59:21,846 [salt.minion      :1432][INFO    ][20866] Starting a new job with PID 20866
2018-12-28 08:59:21,869 [salt.minion      :1711][INFO    ][20866] Returning information for job: 20181228085921797108
2018-12-28 08:59:32,024 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085932005381
2018-12-28 08:59:32,048 [salt.minion      :1432][INFO    ][20915] Starting a new job with PID 20915
2018-12-28 08:59:32,078 [salt.minion      :1711][INFO    ][20915] Returning information for job: 20181228085932005381
2018-12-28 08:59:33,918 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.15081191s left)
2018-12-28 08:59:42,224 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085942208136
2018-12-28 08:59:42,249 [salt.minion      :1432][INFO    ][20939] Starting a new job with PID 20939
2018-12-28 08:59:42,273 [salt.minion      :1711][INFO    ][20939] Returning information for job: 20181228085942208136
2018-12-28 08:59:52,242 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228085952221686
2018-12-28 08:59:52,267 [salt.minion      :1432][INFO    ][20947] Starting a new job with PID 20947
2018-12-28 08:59:52,289 [salt.minion      :1711][INFO    ][20947] Returning information for job: 20181228085952221686
2018-12-28 09:00:02,440 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090002424681
2018-12-28 09:00:02,462 [salt.minion      :1432][INFO    ][21023] Starting a new job with PID 21023
2018-12-28 09:00:02,484 [salt.minion      :1711][INFO    ][21023] Returning information for job: 20181228090002424681
2018-12-28 09:00:04,892 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.17651796s left)
2018-12-28 09:00:12,656 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090012635075
2018-12-28 09:00:12,691 [salt.minion      :1432][INFO    ][21057] Starting a new job with PID 21057
2018-12-28 09:00:12,721 [salt.minion      :1711][INFO    ][21057] Returning information for job: 20181228090012635075
2018-12-28 09:00:22,688 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090022665836
2018-12-28 09:00:22,713 [salt.minion      :1432][INFO    ][21069] Starting a new job with PID 21069
2018-12-28 09:00:22,751 [salt.minion      :1711][INFO    ][21069] Returning information for job: 20181228090022665836
2018-12-28 09:00:32,709 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090032694291
2018-12-28 09:00:32,733 [salt.minion      :1432][INFO    ][21146] Starting a new job with PID 21146
2018-12-28 09:00:32,762 [salt.minion      :1711][INFO    ][21146] Returning information for job: 20181228090032694291
2018-12-28 09:00:36,154 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1343.91454291s left)
2018-12-28 09:00:42,734 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090042713291
2018-12-28 09:00:42,760 [salt.minion      :1432][INFO    ][21304] Starting a new job with PID 21304
2018-12-28 09:00:42,793 [salt.minion      :1711][INFO    ][21304] Returning information for job: 20181228090042713291
2018-12-28 09:00:52,960 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090052937997
2018-12-28 09:00:52,991 [salt.minion      :1432][INFO    ][21313] Starting a new job with PID 21313
2018-12-28 09:00:53,021 [salt.minion      :1711][INFO    ][21313] Returning information for job: 20181228090052937997
2018-12-28 09:01:02,992 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090102974813
2018-12-28 09:01:03,015 [salt.minion      :1432][INFO    ][21403] Starting a new job with PID 21403
2018-12-28 09:01:03,039 [salt.minion      :1711][INFO    ][21403] Returning information for job: 20181228090102974813
2018-12-28 09:01:07,573 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1312.496032s left)
2018-12-28 09:01:13,212 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090113195732
2018-12-28 09:01:13,248 [salt.minion      :1432][INFO    ][21471] Starting a new job with PID 21471
2018-12-28 09:01:13,278 [salt.minion      :1711][INFO    ][21471] Returning information for job: 20181228090113195732
2018-12-28 09:01:23,220 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090123204193
2018-12-28 09:01:23,241 [salt.minion      :1432][INFO    ][21521] Starting a new job with PID 21521
2018-12-28 09:01:23,269 [salt.minion      :1711][INFO    ][21521] Returning information for job: 20181228090123204193
2018-12-28 09:01:33,430 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090133412248
2018-12-28 09:01:33,455 [salt.minion      :1432][INFO    ][21649] Starting a new job with PID 21649
2018-12-28 09:01:33,486 [salt.minion      :1711][INFO    ][21649] Returning information for job: 20181228090133412248
2018-12-28 09:01:39,405 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1280.66398883s left)
2018-12-28 09:01:43,642 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090143623592
2018-12-28 09:01:43,672 [salt.minion      :1432][INFO    ][21678] Starting a new job with PID 21678
2018-12-28 09:01:43,701 [salt.minion      :1711][INFO    ][21678] Returning information for job: 20181228090143623592
2018-12-28 09:01:53,667 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090153650433
2018-12-28 09:01:53,686 [salt.minion      :1432][INFO    ][21715] Starting a new job with PID 21715
2018-12-28 09:01:53,708 [salt.minion      :1711][INFO    ][21715] Returning information for job: 20181228090153650433
2018-12-28 09:02:03,866 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090203849106
2018-12-28 09:02:03,894 [salt.minion      :1432][INFO    ][21905] Starting a new job with PID 21905
2018-12-28 09:02:03,928 [salt.minion      :1711][INFO    ][21905] Returning information for job: 20181228090203849106
2018-12-28 09:02:11,799 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1248.26956797s left)
2018-12-28 09:02:14,093 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090214069468
2018-12-28 09:02:14,121 [salt.minion      :1432][INFO    ][22023] Starting a new job with PID 22023
2018-12-28 09:02:14,151 [salt.minion      :1711][INFO    ][22023] Returning information for job: 20181228090214069468
2018-12-28 09:02:24,146 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090224125107
2018-12-28 09:02:24,170 [salt.minion      :1432][INFO    ][22065] Starting a new job with PID 22065
2018-12-28 09:02:24,203 [salt.minion      :1711][INFO    ][22065] Returning information for job: 20181228090224125107
2018-12-28 09:02:34,198 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090234181994
2018-12-28 09:02:34,224 [salt.minion      :1432][INFO    ][22264] Starting a new job with PID 22264
2018-12-28 09:02:34,250 [salt.minion      :1711][INFO    ][22264] Returning information for job: 20181228090234181994
2018-12-28 09:02:44,241 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090244221580
2018-12-28 09:02:44,264 [salt.minion      :1432][INFO    ][22357] Starting a new job with PID 22357
2018-12-28 09:02:44,296 [salt.minion      :1711][INFO    ][22357] Returning information for job: 20181228090244221580
2018-12-28 09:02:44,561 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1215.50747395s left)
2018-12-28 09:02:54,304 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090254285750
2018-12-28 09:02:54,333 [salt.minion      :1432][INFO    ][22362] Starting a new job with PID 22362
2018-12-28 09:02:54,356 [salt.minion      :1711][INFO    ][22362] Returning information for job: 20181228090254285750
2018-12-28 09:03:04,345 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090304318406
2018-12-28 09:03:04,368 [salt.minion      :1432][INFO    ][22396] Starting a new job with PID 22396
2018-12-28 09:03:04,395 [salt.minion      :1711][INFO    ][22396] Returning information for job: 20181228090304318406
2018-12-28 09:03:14,404 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090314386525
2018-12-28 09:03:14,428 [salt.minion      :1432][INFO    ][22483] Starting a new job with PID 22483
2018-12-28 09:03:14,449 [salt.minion      :1711][INFO    ][22483] Returning information for job: 20181228090314386525
2018-12-28 09:03:17,468 [salt.loaded.ext.module.maas:1001][INFO    ][20712] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1182.60092592s left)
2018-12-28 09:03:24,462 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090324438674
2018-12-28 09:03:24,495 [salt.minion      :1432][INFO    ][22626] Starting a new job with PID 22626
2018-12-28 09:03:24,518 [salt.minion      :1711][INFO    ][22626] Returning information for job: 20181228090324438674
2018-12-28 09:03:34,541 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090334520251
2018-12-28 09:03:34,567 [salt.minion      :1432][INFO    ][22663] Starting a new job with PID 22663
2018-12-28 09:03:34,588 [salt.minion      :1711][INFO    ][22663] Returning information for job: 20181228090334520251
2018-12-28 09:03:44,621 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090344598995
2018-12-28 09:03:44,649 [salt.minion      :1432][INFO    ][22695] Starting a new job with PID 22695
2018-12-28 09:03:44,673 [salt.minion      :1711][INFO    ][22695] Returning information for job: 20181228090344598995
2018-12-28 09:03:50,301 [salt.state       :300 ][INFO    ][20712] {'ret': True}
2018-12-28 09:03:50,302 [salt.state       :1951][INFO    ][20712] Completed state [maas.wait_for_machine_status] at time 09:03:50.302051 duration_in_ms=350252.668
2018-12-28 09:03:50,307 [salt.minion      :1711][INFO    ][20712] Returning information for job: 20181228085750187825
2018-12-28 09:03:50,862 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228090350842790
2018-12-28 09:03:50,892 [salt.minion      :1432][INFO    ][22707] Starting a new job with PID 22707
2018-12-28 09:03:58,648 [salt.state       :915 ][INFO    ][22707] Loading fresh modules for state activity
2018-12-28 09:03:58,706 [salt.fileclient  :1219][INFO    ][22707] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2018-12-28 09:03:58,813 [salt.state       :1780][INFO    ][22707] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:03:58.813567
2018-12-28 09:03:58,814 [salt.state       :1813][INFO    ][22707] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 09:03:58,817 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22707] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 09:04:00,962 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090400942736
2018-12-28 09:04:01,026 [salt.minion      :1432][INFO    ][22726] Starting a new job with PID 22726
2018-12-28 09:04:01,190 [salt.minion      :1711][INFO    ][22726] Returning information for job: 20181228090400942736
2018-12-28 09:04:01,875 [salt.state       :300 ][INFO    ][22707] {'pid': 22721, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 09:04:01,876 [salt.state       :1951][INFO    ][22707] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:01.876814 duration_in_ms=3063.247
2018-12-28 09:04:01,879 [salt.state       :1780][INFO    ][22707] Running state [maas_machines_storage_cmp002_lvm] at time 09:04:01.879521
2018-12-28 09:04:01,880 [salt.state       :1813][INFO    ][22707] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2018-12-28 09:04:03,058 [salt.loaded.ext.module.maasng:610 ][INFO    ][22707] ffa83n
2018-12-28 09:04:03,058 [salt.loaded.ext.module.maasng:626 ][INFO    ][22707] sda
2018-12-28 09:04:03,614 [salt.loaded.ext.module.maasng:361 ][INFO    ][22707] ffa83n
2018-12-28 09:04:03,692 [salt.loaded.ext.module.maasng:367 ][INFO    ][22707] [{u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'9d351c76-1413-4cc0-97fe-d85652a2ed6e', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffa83n', u'device_id': 2, u'filesystem': {u'uuid': u'bc3083c4-f739-4a1f-a70b-54b18c563117', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/partition/1'}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ffa83n', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 2, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'size': 800109715456}, {u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/4/', u'id_path': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 800097042432, u'partitions': [], u'uuid': u'd756899c-af27-499b-863a-b21aab4c00e4', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'ffa83n', u'partition_table_type': None, u'filesystem': {u'uuid': u'8756c32f-6ca9-457b-96f3-57724a796e55', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 4, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'size': 800097042432}]
2018-12-28 09:04:03,693 [salt.loaded.ext.module.maasng:632 ][INFO    ][22707] vgroot
2018-12-28 09:04:03,693 [salt.loaded.ext.module.maasng:635 ][INFO    ][22707] lvroot
2018-12-28 09:04:03,693 [salt.loaded.ext.module.maasng:639 ][INFO    ][22707] 107374182400
2018-12-28 09:04:04,264 [salt.loaded.ext.module.maasng:645 ][INFO    ][22707] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'boot_interface': {u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 19}], u'tags': [u'sriov'], u'enabled': True, 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'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/5/'}, u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/ffa83n/', u'current_commissioning_result_id': 2, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'ffa83n', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/', u'type': u'physical', u'id': 2, u'tags': [u'ssd'], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ffa83n', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'used_size': 800106479616, u'used_for': u'MBR partitioned with 1 partition', u'partitions': [{u'uuid': u'bce5c815-7831-4173-a88c-4a30f2863af2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffa83n', u'device_id': 2, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'42434454-2f4a-4b45-ab8b-404971e9eb5d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}]}], u'min_hwe_kernel': u'ga-16.04', u'status': 4, u'storage_test_status': 2, u'cpu_count': 40, u'power_state': u'off', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'ffa83n', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/', u'type': u'physical', u'id': 2, u'tags': [u'ssd'], u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ffa83n', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'used_size': 800106479616, u'used_for': u'MBR partitioned with 1 partition', u'partitions': [{u'uuid': u'bce5c815-7831-4173-a88c-4a30f2863af2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffa83n', u'device_id': 2, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'42434454-2f4a-4b45-ab8b-404971e9eb5d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}]}, u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'uuid': u'6a4e40e1-0172-4c77-8e3e-1d9dbe471673', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/12/', u'type': u'virtual', u'id': 12, u'tags': [], u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'ffa83n', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'7c434fd5-6cd4-4bc1-9c26-deb1f45e80e2', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'interface_set': [{u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 19}], u'tags': [u'sriov'], u'enabled': True, 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'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/5/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'id': 13, u'discovered': None, u'params': u'', u'mac_address': u'38:ea:a7:8f:07:50', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/13/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'id': 12, u'discovered': None, u'params': u'', u'mac_address': u'38:ea:a7:8f:07:51', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/12/'}, {u'name': u'ens2f1', u'links': [{u'id': 20, u'mode': u'link_up'}], u'tags': [u'sriov'], u'enabled': True, 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': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'effective_mtu': 1500, u'id': 14, u'discovered': None, u'params': u'', u'mac_address': u'38:ea:a7:8f:12:49', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/14/'}, {u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'link_up', u'id': 21}], u'tags': [u'sriov'], u'enabled': True, 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'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'effective_mtu': 1500, u'id': 15, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'params': u'', u'mac_address': u'9c:b6:54:8a:10:1c', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/15/'}, {u'name': u'ens2f0', u'links': [{u'id': 22, u'mode': u'link_up'}], u'tags': [u'sriov'], u'enabled': True, 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': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'effective_mtu': 1500, u'id': 16, u'discovered': None, u'params': u'', u'mac_address': u'38:ea:a7:8f:12:48', u'parents': [], u'system_id': u'ffa83n', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/interfaces/16/'}], u'address_ttl': None, u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'partition_table_type': u'MBR', u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'type': u'physical', u'id': 2, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'ffa83n', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'size': 800109715456, u'used_size': 800106479616, u'used_for': u'MBR partitioned with 1 partition', u'partitions': [{u'uuid': u'bce5c815-7831-4173-a88c-4a30f2863af2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'ffa83n', u'device_id': 2, u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'42434454-2f4a-4b45-ab8b-404971e9eb5d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}]}, {u'model': None, u'partition_table_type': None, u'block_size': 4096, u'uuid': u'6a4e40e1-0172-4c77-8e3e-1d9dbe471673', u'tags': [], u'type': u'virtual', u'id': 12, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'ffa83n', u'resource_uri': u'/MAAS/api/2.0/nodes/ffa83n/blockdevices/12/', u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'7c434fd5-6cd4-4bc1-9c26-deb1f45e80e2', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'partitions': []}], u'distro_series': u'', u'memory_test_status': -1}
2018-12-28 09:04:04,265 [salt.state       :300 ][INFO    ][22707] {'new': {'storage_layout': 'lvm'}}
2018-12-28 09:04:04,266 [salt.state       :1951][INFO    ][22707] Completed state [maas_machines_storage_cmp002_lvm] at time 09:04:04.265933 duration_in_ms=2386.415
2018-12-28 09:04:04,266 [salt.state       :1780][INFO    ][22707] Running state [maas_machines_storage_cmp001_lvm] at time 09:04:04.266323
2018-12-28 09:04:04,266 [salt.state       :1813][INFO    ][22707] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2018-12-28 09:04:05,382 [salt.loaded.ext.module.maasng:610 ][INFO    ][22707] 6t7pg8
2018-12-28 09:04:05,382 [salt.loaded.ext.module.maasng:626 ][INFO    ][22707] sda
2018-12-28 09:04:05,958 [salt.loaded.ext.module.maasng:361 ][INFO    ][22707] 6t7pg8
2018-12-28 09:04:06,060 [salt.loaded.ext.module.maasng:367 ][INFO    ][22707] [{u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'749cc402-a7bf-44f7-9309-0c7fc210eb53', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6t7pg8', u'device_id': 3, u'filesystem': {u'uuid': u'ba19deb0-d3fb-44ee-b839-66ce83fc329e', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/partition/2'}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'6t7pg8', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 3, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'size': 800109715456}, {u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/5/', u'id_path': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 800097042432, u'partitions': [], u'uuid': u'b05c5971-08ce-45fd-8717-e6f1fd458497', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'6t7pg8', u'partition_table_type': None, u'filesystem': {u'uuid': u'debeec66-19f1-48ab-8d0a-7aeaad85d281', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 5, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'size': 800097042432}]
2018-12-28 09:04:06,061 [salt.loaded.ext.module.maasng:632 ][INFO    ][22707] vgroot
2018-12-28 09:04:06,061 [salt.loaded.ext.module.maasng:635 ][INFO    ][22707] lvroot
2018-12-28 09:04:06,061 [salt.loaded.ext.module.maasng:639 ][INFO    ][22707] 107374182400
2018-12-28 09:04:06,712 [salt.loaded.ext.module.maasng:645 ][INFO    ][22707] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'boot_interface': {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 25, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 6, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/6/'}, u'disable_ipv4': False, u'cpu_count': 40, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'testing_status': 2, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 800109.715456, u'owner_data': {}, u'system_id': u'6t7pg8', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'ip_addresses': [u'192.168.11.39', u'192.168.11.41'], u'blockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'22a3f9cc-1442-4db4-8d29-ac8e8c59c30b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6t7pg8', u'device_id': 3, u'filesystem': {u'uuid': u'721da691-4af4-4fa8-8887-051c585394aa', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/partition/7'}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'6t7pg8', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 3, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'size': 800109715456}, {u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/13/', u'id_path': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'6d1273fc-8de1-4272-9df3-9e2e9bae001a', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'6t7pg8', u'partition_table_type': None, u'filesystem': {u'uuid': u'87c6619f-212c-4e59-af4b-5b868318ab44', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 13, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'22a3f9cc-1442-4db4-8d29-ac8e8c59c30b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6t7pg8', u'device_id': 3, u'filesystem': {u'uuid': u'721da691-4af4-4fa8-8887-051c585394aa', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/partition/7'}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'6t7pg8', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 3, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'size': 800109715456}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'6t7pg8', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'name': u'sda', u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'22a3f9cc-1442-4db4-8d29-ac8e8c59c30b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'6t7pg8', u'device_id': 3, u'filesystem': {u'uuid': u'721da691-4af4-4fa8-8887-051c585394aa', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/3/partition/7'}], u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'6t7pg8', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 3, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'size': 800109715456}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/blockdevices/13/', u'id_path': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'6d1273fc-8de1-4272-9df3-9e2e9bae001a', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'6t7pg8', u'partition_table_type': None, u'filesystem': {u'uuid': u'87c6619f-212c-4e59-af4b-5b868318ab44', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 13, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'id': 25, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 6, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/6/'}, {u'discovered': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'id': 17, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d5', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/17/'}, {u'discovered': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'id': 18, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d4', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/18/'}, {u'discovered': None, u'name': u'ens2f1', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 19, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cd', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/19/'}, {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.41'}], u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'id': 27, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bqycpd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 20, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a4', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/20/'}, {u'discovered': None, u'name': u'ens2f0', u'links': [{u'id': 28, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'id': 21, u'effective_mtu': 1500, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cc', u'system_id': u'6t7pg8', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/6t7pg8/interfaces/21/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/6t7pg8/'}
2018-12-28 09:04:06,715 [salt.state       :300 ][INFO    ][22707] {'new': {'storage_layout': 'lvm'}}
2018-12-28 09:04:06,715 [salt.state       :1951][INFO    ][22707] Completed state [maas_machines_storage_cmp001_lvm] at time 09:04:06.715673 duration_in_ms=2449.349
2018-12-28 09:04:06,721 [salt.minion      :1711][INFO    ][22707] Returning information for job: 20181228090350842790
2018-12-28 09:04:07,294 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228090407272823
2018-12-28 09:04:07,325 [salt.minion      :1432][INFO    ][22764] Starting a new job with PID 22764
2018-12-28 09:04:08,280 [salt.state       :915 ][INFO    ][22764] Loading fresh modules for state activity
2018-12-28 09:04:08,337 [salt.fileclient  :1219][INFO    ][22764] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2018-12-28 09:04:08,393 [salt.state       :1780][INFO    ][22764] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:08.393598
2018-12-28 09:04:08,394 [salt.state       :1813][INFO    ][22764] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 09:04:08,396 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22764] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 09:04:10,512 [salt.state       :300 ][INFO    ][22764] {'pid': 22771, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 09:04:10,514 [salt.state       :1951][INFO    ][22764] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:10.514555 duration_in_ms=2120.956
2018-12-28 09:04:10,518 [salt.state       :1780][INFO    ][22764] Running state [maas.deploy_machines] at time 09:04:10.518318
2018-12-28 09:04:10,518 [salt.state       :1813][INFO    ][22764] Executing state module.run for [maas.deploy_machines]
2018-12-28 09:04:10,520 [salt.utils.decorators:613 ][WARNING ][22764] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 09:04:11,165 [salt.loaded.ext.module.maas:684 ][INFO    ][22764] deploymachines hwe_kernel=ga-16.04 system_id=ffa83n distro_series=xenial
2018-12-28 09:04:13,778 [salt.loaded.ext.module.maas:684 ][INFO    ][22764] deploymachines hwe_kernel=ga-16.04 system_id=6t7pg8 distro_series=xenial
2018-12-28 09:04:16,443 [salt.loaded.ext.module.maas:684 ][INFO    ][22764] deploymachines hwe_kernel=ga-16.04 system_id=63snns distro_series=xenial
2018-12-28 09:04:17,336 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090417320191
2018-12-28 09:04:17,361 [salt.minion      :1432][INFO    ][22895] Starting a new job with PID 22895
2018-12-28 09:04:17,385 [salt.minion      :1711][INFO    ][22895] Returning information for job: 20181228090417320191
2018-12-28 09:04:19,044 [salt.loaded.ext.module.maas:684 ][INFO    ][22764] deploymachines hwe_kernel=ga-16.04 system_id=khgm4n distro_series=xenial
2018-12-28 09:04:21,672 [salt.loaded.ext.module.maas:684 ][INFO    ][22764] deploymachines hwe_kernel=ga-16.04 system_id=88schs distro_series=xenial
2018-12-28 09:04:24,292 [salt.state       :300 ][INFO    ][22764] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2018-12-28 09:04:24,293 [salt.state       :1951][INFO    ][22764] Completed state [maas.deploy_machines] at time 09:04:24.293383 duration_in_ms=13775.063
2018-12-28 09:04:24,297 [salt.minion      :1711][INFO    ][22764] Returning information for job: 20181228090407272823
2018-12-28 09:04:24,880 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command state.apply with jid 20181228090424856398
2018-12-28 09:04:24,905 [salt.minion      :1432][INFO    ][23060] Starting a new job with PID 23060
2018-12-28 09:04:32,638 [salt.state       :915 ][INFO    ][23060] Loading fresh modules for state activity
2018-12-28 09:04:32,707 [salt.fileclient  :1219][INFO    ][23060] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2018-12-28 09:04:32,765 [salt.state       :1780][INFO    ][23060] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:32.764917
2018-12-28 09:04:32,765 [salt.state       :1813][INFO    ][23060] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-28 09:04:32,768 [salt.loaded.int.module.cmdmod:395 ][INFO    ][23060] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-28 09:04:34,971 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090434950744
2018-12-28 09:04:34,997 [salt.minion      :1432][INFO    ][23088] Starting a new job with PID 23088
2018-12-28 09:04:35,087 [salt.minion      :1711][INFO    ][23088] Returning information for job: 20181228090434950744
2018-12-28 09:04:35,193 [salt.state       :300 ][INFO    ][23060] {'pid': 23077, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-28 09:04:35,200 [salt.state       :1951][INFO    ][23060] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:35.200412 duration_in_ms=2435.495
2018-12-28 09:04:35,202 [salt.state       :1780][INFO    ][23060] Running state [maas.wait_for_machine_status] at time 09:04:35.202828
2018-12-28 09:04:35,203 [salt.state       :1813][INFO    ][23060] Executing state module.run for [maas.wait_for_machine_status]
2018-12-28 09:04:35,203 [salt.utils.decorators:613 ][WARNING ][23060] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-28 09:04:38,478 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.74022388s left)
2018-12-28 09:04:45,042 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090445019434
2018-12-28 09:04:45,070 [salt.minion      :1432][INFO    ][23101] Starting a new job with PID 23101
2018-12-28 09:04:45,098 [salt.minion      :1711][INFO    ][23101] Returning information for job: 20181228090445019434
2018-12-28 09:04:55,258 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090455241072
2018-12-28 09:04:55,281 [salt.minion      :1432][INFO    ][23113] Starting a new job with PID 23113
2018-12-28 09:04:55,304 [salt.minion      :1711][INFO    ][23113] Returning information for job: 20181228090455241072
2018-12-28 09:05:05,468 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090505446482
2018-12-28 09:05:05,494 [salt.minion      :1432][INFO    ][23139] Starting a new job with PID 23139
2018-12-28 09:05:05,515 [salt.minion      :1711][INFO    ][23139] Returning information for job: 20181228090505446482
2018-12-28 09:05:11,591 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.62726808s left)
2018-12-28 09:05:15,672 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090515648065
2018-12-28 09:05:15,707 [salt.minion      :1432][INFO    ][23151] Starting a new job with PID 23151
2018-12-28 09:05:15,733 [salt.minion      :1711][INFO    ][23151] Returning information for job: 20181228090515648065
2018-12-28 09:05:25,686 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090525666337
2018-12-28 09:05:25,717 [salt.minion      :1432][INFO    ][23179] Starting a new job with PID 23179
2018-12-28 09:05:25,740 [salt.minion      :1711][INFO    ][23179] Returning information for job: 20181228090525666337
2018-12-28 09:05:35,909 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090535884605
2018-12-28 09:05:35,937 [salt.minion      :1432][INFO    ][23204] Starting a new job with PID 23204
2018-12-28 09:05:35,960 [salt.minion      :1711][INFO    ][23204] Returning information for job: 20181228090535884605
2018-12-28 09:05:45,144 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.07414508s left)
2018-12-28 09:05:46,130 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090546101635
2018-12-28 09:05:46,154 [salt.minion      :1432][INFO    ][23222] Starting a new job with PID 23222
2018-12-28 09:05:46,185 [salt.minion      :1711][INFO    ][23222] Returning information for job: 20181228090546101635
2018-12-28 09:05:56,142 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090556119296
2018-12-28 09:05:56,178 [salt.minion      :1432][INFO    ][23242] Starting a new job with PID 23242
2018-12-28 09:05:56,205 [salt.minion      :1711][INFO    ][23242] Returning information for job: 20181228090556119296
2018-12-28 09:06:06,161 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090606142087
2018-12-28 09:06:06,186 [salt.minion      :1432][INFO    ][23266] Starting a new job with PID 23266
2018-12-28 09:06:06,211 [salt.minion      :1711][INFO    ][23266] Returning information for job: 20181228090606142087
2018-12-28 09:06:16,365 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090616348478
2018-12-28 09:06:16,390 [salt.minion      :1432][INFO    ][23275] Starting a new job with PID 23275
2018-12-28 09:06:16,416 [salt.minion      :1711][INFO    ][23275] Returning information for job: 20181228090616348478
2018-12-28 09:06:18,069 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.14868307s left)
2018-12-28 09:06:26,590 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090626565846
2018-12-28 09:06:26,617 [salt.minion      :1432][INFO    ][23299] Starting a new job with PID 23299
2018-12-28 09:06:26,642 [salt.minion      :1711][INFO    ][23299] Returning information for job: 20181228090626565846
2018-12-28 09:06:36,813 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090636793664
2018-12-28 09:06:36,837 [salt.minion      :1432][INFO    ][23317] Starting a new job with PID 23317
2018-12-28 09:06:36,858 [salt.minion      :1711][INFO    ][23317] Returning information for job: 20181228090636793664
2018-12-28 09:06:47,023 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090647005776
2018-12-28 09:06:47,044 [salt.minion      :1432][INFO    ][23350] Starting a new job with PID 23350
2018-12-28 09:06:47,073 [salt.minion      :1711][INFO    ][23350] Returning information for job: 20181228090647005776
2018-12-28 09:06:50,963 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.2546351s left)
2018-12-28 09:06:57,237 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090657210664
2018-12-28 09:06:57,262 [salt.minion      :1432][INFO    ][23367] Starting a new job with PID 23367
2018-12-28 09:06:57,297 [salt.minion      :1711][INFO    ][23367] Returning information for job: 20181228090657210664
2018-12-28 09:07:07,269 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090707245880
2018-12-28 09:07:07,291 [salt.minion      :1432][INFO    ][23391] Starting a new job with PID 23391
2018-12-28 09:07:07,316 [salt.minion      :1711][INFO    ][23391] Returning information for job: 20181228090707245880
2018-12-28 09:07:17,468 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090717450767
2018-12-28 09:07:17,492 [salt.minion      :1432][INFO    ][23442] Starting a new job with PID 23442
2018-12-28 09:07:17,521 [salt.minion      :1711][INFO    ][23442] Returning information for job: 20181228090717450767
2018-12-28 09:07:23,923 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.29520106s left)
2018-12-28 09:07:27,690 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090727665969
2018-12-28 09:07:27,716 [salt.minion      :1432][INFO    ][23468] Starting a new job with PID 23468
2018-12-28 09:07:27,742 [salt.minion      :1711][INFO    ][23468] Returning information for job: 20181228090727665969
2018-12-28 09:07:37,714 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090737696823
2018-12-28 09:07:37,735 [salt.minion      :1432][INFO    ][23575] Starting a new job with PID 23575
2018-12-28 09:07:37,760 [salt.minion      :1711][INFO    ][23575] Returning information for job: 20181228090737696823
2018-12-28 09:07:47,733 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090747712539
2018-12-28 09:07:47,764 [salt.minion      :1432][INFO    ][23608] Starting a new job with PID 23608
2018-12-28 09:07:47,808 [salt.minion      :1711][INFO    ][23608] Returning information for job: 20181228090747712539
2018-12-28 09:07:57,154 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2048.06426096s left)
2018-12-28 09:07:57,766 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090757745024
2018-12-28 09:07:57,798 [salt.minion      :1432][INFO    ][23628] Starting a new job with PID 23628
2018-12-28 09:07:57,831 [salt.minion      :1711][INFO    ][23628] Returning information for job: 20181228090757745024
2018-12-28 09:08:07,816 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090807786735
2018-12-28 09:08:07,844 [salt.minion      :1432][INFO    ][23654] Starting a new job with PID 23654
2018-12-28 09:08:07,868 [salt.minion      :1711][INFO    ][23654] Returning information for job: 20181228090807786735
2018-12-28 09:08:17,848 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090817829123
2018-12-28 09:08:17,867 [salt.minion      :1432][INFO    ][23660] Starting a new job with PID 23660
2018-12-28 09:08:17,889 [salt.minion      :1711][INFO    ][23660] Returning information for job: 20181228090817829123
2018-12-28 09:08:28,062 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090828044673
2018-12-28 09:08:28,085 [salt.minion      :1432][INFO    ][23684] Starting a new job with PID 23684
2018-12-28 09:08:28,125 [salt.minion      :1711][INFO    ][23684] Returning information for job: 20181228090828044673
2018-12-28 09:08:30,483 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.73465705s left)
2018-12-28 09:08:38,082 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090838064010
2018-12-28 09:08:38,100 [salt.minion      :1432][INFO    ][23911] Starting a new job with PID 23911
2018-12-28 09:08:38,125 [salt.minion      :1711][INFO    ][23911] Returning information for job: 20181228090838064010
2018-12-28 09:08:48,303 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090848275557
2018-12-28 09:08:48,332 [salt.minion      :1432][INFO    ][23918] Starting a new job with PID 23918
2018-12-28 09:08:48,361 [salt.minion      :1711][INFO    ][23918] Returning information for job: 20181228090848275557
2018-12-28 09:08:58,355 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090858331208
2018-12-28 09:08:58,388 [salt.minion      :1432][INFO    ][23937] Starting a new job with PID 23937
2018-12-28 09:08:58,425 [salt.minion      :1711][INFO    ][23937] Returning information for job: 20181228090858331208
2018-12-28 09:09:03,825 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.39328599s left)
2018-12-28 09:09:08,419 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090908398220
2018-12-28 09:09:08,445 [salt.minion      :1432][INFO    ][24035] Starting a new job with PID 24035
2018-12-28 09:09:08,467 [salt.minion      :1711][INFO    ][24035] Returning information for job: 20181228090908398220
2018-12-28 09:09:18,475 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090918454397
2018-12-28 09:09:18,500 [salt.minion      :1432][INFO    ][24053] Starting a new job with PID 24053
2018-12-28 09:09:18,522 [salt.minion      :1711][INFO    ][24053] Returning information for job: 20181228090918454397
2018-12-28 09:09:28,532 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090928512271
2018-12-28 09:09:28,549 [salt.minion      :1432][INFO    ][24081] Starting a new job with PID 24081
2018-12-28 09:09:28,580 [salt.minion      :1711][INFO    ][24081] Returning information for job: 20181228090928512271
2018-12-28 09:09:37,335 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.88247395s left)
2018-12-28 09:09:38,755 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090938733785
2018-12-28 09:09:38,789 [salt.minion      :1432][INFO    ][24396] Starting a new job with PID 24396
2018-12-28 09:09:38,817 [salt.minion      :1711][INFO    ][24396] Returning information for job: 20181228090938733785
2018-12-28 09:09:48,835 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090948807862
2018-12-28 09:09:48,867 [salt.minion      :1432][INFO    ][24405] Starting a new job with PID 24405
2018-12-28 09:09:48,892 [salt.minion      :1711][INFO    ][24405] Returning information for job: 20181228090948807862
2018-12-28 09:09:58,880 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228090958860444
2018-12-28 09:09:58,903 [salt.minion      :1432][INFO    ][24436] Starting a new job with PID 24436
2018-12-28 09:09:58,928 [salt.minion      :1711][INFO    ][24436] Returning information for job: 20181228090958860444
2018-12-28 09:10:08,911 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091008891211
2018-12-28 09:10:08,936 [salt.minion      :1432][INFO    ][24509] Starting a new job with PID 24509
2018-12-28 09:10:08,966 [salt.minion      :1711][INFO    ][24509] Returning information for job: 20181228091008891211
2018-12-28 09:10:10,572 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1914.64560199s left)
2018-12-28 09:10:18,994 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091018969143
2018-12-28 09:10:19,021 [salt.minion      :1432][INFO    ][24520] Starting a new job with PID 24520
2018-12-28 09:10:19,046 [salt.minion      :1711][INFO    ][24520] Returning information for job: 20181228091018969143
2018-12-28 09:10:29,033 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091029005677
2018-12-28 09:10:29,063 [salt.minion      :1432][INFO    ][24571] Starting a new job with PID 24571
2018-12-28 09:10:29,096 [salt.minion      :1711][INFO    ][24571] Returning information for job: 20181228091029005677
2018-12-28 09:10:39,092 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091039072640
2018-12-28 09:10:39,117 [salt.minion      :1432][INFO    ][24756] Starting a new job with PID 24756
2018-12-28 09:10:39,145 [salt.minion      :1711][INFO    ][24756] Returning information for job: 20181228091039072640
2018-12-28 09:10:43,858 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.35989594s left)
2018-12-28 09:10:49,170 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091049146496
2018-12-28 09:10:49,197 [salt.minion      :1432][INFO    ][24774] Starting a new job with PID 24774
2018-12-28 09:10:49,222 [salt.minion      :1711][INFO    ][24774] Returning information for job: 20181228091049146496
2018-12-28 09:10:59,265 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091059245058
2018-12-28 09:10:59,296 [salt.minion      :1432][INFO    ][24788] Starting a new job with PID 24788
2018-12-28 09:10:59,320 [salt.minion      :1711][INFO    ][24788] Returning information for job: 20181228091059245058
2018-12-28 09:11:09,368 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091109340791
2018-12-28 09:11:09,395 [salt.minion      :1432][INFO    ][24876] Starting a new job with PID 24876
2018-12-28 09:11:09,421 [salt.minion      :1711][INFO    ][24876] Returning information for job: 20181228091109340791
2018-12-28 09:11:17,327 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1847.89071488s left)
2018-12-28 09:11:19,460 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091119436209
2018-12-28 09:11:19,489 [salt.minion      :1432][INFO    ][24888] Starting a new job with PID 24888
2018-12-28 09:11:19,517 [salt.minion      :1711][INFO    ][24888] Returning information for job: 20181228091119436209
2018-12-28 09:11:29,577 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091129554239
2018-12-28 09:11:29,603 [salt.minion      :1432][INFO    ][24909] Starting a new job with PID 24909
2018-12-28 09:11:29,634 [salt.minion      :1711][INFO    ][24909] Returning information for job: 20181228091129554239
2018-12-28 09:11:39,680 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091139659328
2018-12-28 09:11:39,706 [salt.minion      :1432][INFO    ][25163] Starting a new job with PID 25163
2018-12-28 09:11:39,732 [salt.minion      :1711][INFO    ][25163] Returning information for job: 20181228091139659328
2018-12-28 09:11:49,721 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091149698414
2018-12-28 09:11:49,741 [salt.minion      :1432][INFO    ][25173] Starting a new job with PID 25173
2018-12-28 09:11:49,773 [salt.minion      :1711][INFO    ][25173] Returning information for job: 20181228091149698414
2018-12-28 09:11:50,859 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.35875893s left)
2018-12-28 09:11:59,790 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091159765885
2018-12-28 09:11:59,817 [salt.minion      :1432][INFO    ][25204] Starting a new job with PID 25204
2018-12-28 09:11:59,844 [salt.minion      :1711][INFO    ][25204] Returning information for job: 20181228091159765885
2018-12-28 09:12:09,912 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091209891373
2018-12-28 09:12:09,941 [salt.minion      :1432][INFO    ][25255] Starting a new job with PID 25255
2018-12-28 09:12:09,964 [salt.minion      :1711][INFO    ][25255] Returning information for job: 20181228091209891373
2018-12-28 09:12:20,051 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091220028891
2018-12-28 09:12:20,073 [salt.minion      :1432][INFO    ][25277] Starting a new job with PID 25277
2018-12-28 09:12:20,102 [salt.minion      :1711][INFO    ][25277] Returning information for job: 20181228091220028891
2018-12-28 09:12:24,105 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1781.11255193s left)
2018-12-28 09:12:30,168 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091230148002
2018-12-28 09:12:30,194 [salt.minion      :1432][INFO    ][25312] Starting a new job with PID 25312
2018-12-28 09:12:30,218 [salt.minion      :1711][INFO    ][25312] Returning information for job: 20181228091230148002
2018-12-28 09:12:40,314 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091240287430
2018-12-28 09:12:40,340 [salt.minion      :1432][INFO    ][25468] Starting a new job with PID 25468
2018-12-28 09:12:40,373 [salt.minion      :1711][INFO    ][25468] Returning information for job: 20181228091240287430
2018-12-28 09:12:50,409 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091250387626
2018-12-28 09:12:50,433 [salt.minion      :1432][INFO    ][25474] Starting a new job with PID 25474
2018-12-28 09:12:50,456 [salt.minion      :1711][INFO    ][25474] Returning information for job: 20181228091250387626
2018-12-28 09:12:57,537 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1747.68103909s left)
2018-12-28 09:13:00,538 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091300514742
2018-12-28 09:13:00,565 [salt.minion      :1432][INFO    ][25497] Starting a new job with PID 25497
2018-12-28 09:13:00,596 [salt.minion      :1711][INFO    ][25497] Returning information for job: 20181228091300514742
2018-12-28 09:13:10,707 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091310685786
2018-12-28 09:13:10,732 [salt.minion      :1432][INFO    ][25560] Starting a new job with PID 25560
2018-12-28 09:13:10,763 [salt.minion      :1711][INFO    ][25560] Returning information for job: 20181228091310685786
2018-12-28 09:13:20,794 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091320769879
2018-12-28 09:13:20,821 [salt.minion      :1432][INFO    ][25582] Starting a new job with PID 25582
2018-12-28 09:13:20,843 [salt.minion      :1711][INFO    ][25582] Returning information for job: 20181228091320769879
2018-12-28 09:13:30,833 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1714.38451099s left)
2018-12-28 09:13:30,956 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091330926042
2018-12-28 09:13:30,980 [salt.minion      :1432][INFO    ][25609] Starting a new job with PID 25609
2018-12-28 09:13:31,005 [salt.minion      :1711][INFO    ][25609] Returning information for job: 20181228091330926042
2018-12-28 09:13:41,135 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091341107695
2018-12-28 09:13:41,163 [salt.minion      :1432][INFO    ][25770] Starting a new job with PID 25770
2018-12-28 09:13:41,190 [salt.minion      :1711][INFO    ][25770] Returning information for job: 20181228091341107695
2018-12-28 09:13:51,323 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091351303179
2018-12-28 09:13:51,343 [salt.minion      :1432][INFO    ][25776] Starting a new job with PID 25776
2018-12-28 09:13:51,363 [salt.minion      :1711][INFO    ][25776] Returning information for job: 20181228091351303179
2018-12-28 09:14:01,450 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091401428098
2018-12-28 09:14:01,476 [salt.minion      :1432][INFO    ][25788] Starting a new job with PID 25788
2018-12-28 09:14:01,509 [salt.minion      :1711][INFO    ][25788] Returning information for job: 20181228091401428098
2018-12-28 09:14:04,042 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1681.17588806s left)
2018-12-28 09:14:11,658 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091411630279
2018-12-28 09:14:11,697 [salt.minion      :1432][INFO    ][25845] Starting a new job with PID 25845
2018-12-28 09:14:11,729 [salt.minion      :1711][INFO    ][25845] Returning information for job: 20181228091411630279
2018-12-28 09:14:21,678 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091421650588
2018-12-28 09:14:21,705 [salt.minion      :1432][INFO    ][25850] Starting a new job with PID 25850
2018-12-28 09:14:21,729 [salt.minion      :1711][INFO    ][25850] Returning information for job: 20181228091421650588
2018-12-28 09:14:31,694 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091431669039
2018-12-28 09:14:31,718 [salt.minion      :1432][INFO    ][25872] Starting a new job with PID 25872
2018-12-28 09:14:31,744 [salt.minion      :1711][INFO    ][25872] Returning information for job: 20181228091431669039
2018-12-28 09:14:37,289 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1647.929389s left)
2018-12-28 09:14:41,869 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091441844553
2018-12-28 09:14:41,899 [salt.minion      :1432][INFO    ][25896] Starting a new job with PID 25896
2018-12-28 09:14:41,926 [salt.minion      :1711][INFO    ][25896] Returning information for job: 20181228091441844553
2018-12-28 09:14:51,912 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091451883539
2018-12-28 09:14:51,942 [salt.minion      :1432][INFO    ][25902] Starting a new job with PID 25902
2018-12-28 09:14:51,964 [salt.minion      :1711][INFO    ][25902] Returning information for job: 20181228091451883539
2018-12-28 09:15:02,081 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091502053153
2018-12-28 09:15:02,105 [salt.minion      :1432][INFO    ][25918] Starting a new job with PID 25918
2018-12-28 09:15:02,137 [salt.minion      :1711][INFO    ][25918] Returning information for job: 20181228091502053153
2018-12-28 09:15:10,763 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1614.45500088s left)
2018-12-28 09:15:12,285 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091512258577
2018-12-28 09:15:12,311 [salt.minion      :1432][INFO    ][25944] Starting a new job with PID 25944
2018-12-28 09:15:12,333 [salt.minion      :1711][INFO    ][25944] Returning information for job: 20181228091512258577
2018-12-28 09:15:22,338 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091522315958
2018-12-28 09:15:22,363 [salt.minion      :1432][INFO    ][25949] Starting a new job with PID 25949
2018-12-28 09:15:22,386 [salt.minion      :1711][INFO    ][25949] Returning information for job: 20181228091522315958
2018-12-28 09:15:32,382 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091532358931
2018-12-28 09:15:32,408 [salt.minion      :1432][INFO    ][26107] Starting a new job with PID 26107
2018-12-28 09:15:32,431 [salt.minion      :1711][INFO    ][26107] Returning information for job: 20181228091532358931
2018-12-28 09:15:42,405 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091542383924
2018-12-28 09:15:42,429 [salt.minion      :1432][INFO    ][26157] Starting a new job with PID 26157
2018-12-28 09:15:42,451 [salt.minion      :1711][INFO    ][26157] Returning information for job: 20181228091542383924
2018-12-28 09:15:44,079 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1581.13921309s left)
2018-12-28 09:15:52,440 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091552414376
2018-12-28 09:15:52,463 [salt.minion      :1432][INFO    ][26200] Starting a new job with PID 26200
2018-12-28 09:15:52,495 [salt.minion      :1711][INFO    ][26200] Returning information for job: 20181228091552414376
2018-12-28 09:16:02,637 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091602617212
2018-12-28 09:16:02,661 [salt.minion      :1432][INFO    ][26277] Starting a new job with PID 26277
2018-12-28 09:16:02,689 [salt.minion      :1711][INFO    ][26277] Returning information for job: 20181228091602617212
2018-12-28 09:16:12,657 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091612637492
2018-12-28 09:16:12,685 [salt.minion      :1432][INFO    ][26306] Starting a new job with PID 26306
2018-12-28 09:16:12,715 [salt.minion      :1711][INFO    ][26306] Returning information for job: 20181228091612637492
2018-12-28 09:16:17,307 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1547.912256s left)
2018-12-28 09:16:22,717 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091622689321
2018-12-28 09:16:22,748 [salt.minion      :1432][INFO    ][26331] Starting a new job with PID 26331
2018-12-28 09:16:22,780 [salt.minion      :1711][INFO    ][26331] Returning information for job: 20181228091622689321
2018-12-28 09:16:32,792 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091632772737
2018-12-28 09:16:32,818 [salt.minion      :1432][INFO    ][26373] Starting a new job with PID 26373
2018-12-28 09:16:32,853 [salt.minion      :1711][INFO    ][26373] Returning information for job: 20181228091632772737
2018-12-28 09:16:42,900 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091642875997
2018-12-28 09:16:42,931 [salt.minion      :1432][INFO    ][26555] Starting a new job with PID 26555
2018-12-28 09:16:42,960 [salt.minion      :1711][INFO    ][26555] Returning information for job: 20181228091642875997
2018-12-28 09:16:50,769 [salt.loaded.ext.module.maas:1001][INFO    ][23060] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1514.44871402s left)
2018-12-28 09:16:52,983 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091652957325
2018-12-28 09:16:53,008 [salt.minion      :1432][INFO    ][26571] Starting a new job with PID 26571
2018-12-28 09:16:53,033 [salt.minion      :1711][INFO    ][26571] Returning information for job: 20181228091652957325
2018-12-28 09:17:03,081 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091703059690
2018-12-28 09:17:03,108 [salt.minion      :1432][INFO    ][26624] Starting a new job with PID 26624
2018-12-28 09:17:03,133 [salt.minion      :1711][INFO    ][26624] Returning information for job: 20181228091703059690
2018-12-28 09:17:13,109 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091713087767
2018-12-28 09:17:13,136 [salt.minion      :1432][INFO    ][26630] Starting a new job with PID 26630
2018-12-28 09:17:13,159 [salt.minion      :1711][INFO    ][26630] Returning information for job: 20181228091713087767
2018-12-28 09:17:23,329 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command saltutil.find_job with jid 20181228091723308915
2018-12-28 09:17:23,356 [salt.minion      :1432][INFO    ][26655] Starting a new job with PID 26655
2018-12-28 09:17:23,383 [salt.minion      :1711][INFO    ][26655] Returning information for job: 20181228091723308915
2018-12-28 09:17:24,203 [salt.state       :300 ][INFO    ][23060] {'ret': True}
2018-12-28 09:17:24,204 [salt.state       :1951][INFO    ][23060] Completed state [maas.wait_for_machine_status] at time 09:17:24.204182 duration_in_ms=769001.352
2018-12-28 09:17:24,211 [salt.minion      :1711][INFO    ][23060] Returning information for job: 20181228090424856398
2018-12-28 09:40:41,940 [salt.utils.schedule:1377][INFO    ][4741] Running scheduled job: __mine_interval
2018-12-28 10:38:46,404 [salt.minion      :1308][INFO    ][4741] User sudo_ubuntu Executing command cp.push_dir with jid 20181228103846390325
2018-12-28 10:38:46,439 [salt.minion      :1432][INFO    ][32501] Starting a new job with PID 32501
