2018-12-27 10:42:25,710 [salt.utils       :831 ][ERROR   ][1511] DNS lookup or connection check of 'salt' failed.
2018-12-27 10:42:25,713 [salt.minion      :152 ][ERROR   ][1511] Master hostname: 'salt' not found or not responsive. Retrying in 30 seconds
2018-12-27 10:42:29,237 [salt.utils.parsers:1051][WARNING ][1511] Minion received a SIGTERM. Exiting.
2018-12-27 10:43:40,185 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,686 [salt.utils.decorators:613 ][WARNING ][1866] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:43:49,775 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,777 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,778 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,779 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,780 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,782 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,783 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,784 [salt.loaded.int.states.file:2298][WARNING ][1866] 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-27 10:43:49,976 [salt.loaded.int.module.cmdmod:730 ][ERROR   ][1866] Command '['umount', '/dev/shm']' failed with return code: 32
2018-12-27 10:43:49,976 [salt.loaded.int.module.cmdmod:734 ][ERROR   ][1866] 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-27 10:43:49,977 [salt.loaded.int.module.cmdmod:736 ][ERROR   ][1866] retcode: 32
2018-12-27 10:44:00,639 [salt.utils.parsers:1051][WARNING ][1721] Minion received a SIGTERM. Exiting.
2018-12-27 10:44:49,142 [salt.utils.decorators:613 ][WARNING ][1934] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:45:06,129 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4577] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2018-12-27 10:45:06,156 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4577] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2018-12-27 10:45:06,175 [salt.utils.parsers:1051][WARNING ][1680] Minion received a SIGTERM. Exiting.
2018-12-27 10:45:07,106 [salt.cli.daemons :293 ][INFO    ][4651] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2018-12-27 10:45:07,232 [salt.cli.daemons :82  ][INFO    ][4651] Starting up the Salt Minion
2018-12-27 10:45:07,233 [salt.utils.event :1017][INFO    ][4651] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2018-12-27 10:45:07,842 [salt.minion      :976 ][INFO    ][4651] Creating minion process manager
2018-12-27 10:45:08,986 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][4651] Executing command ['date', '+%z'] in directory '/root'
2018-12-27 10:45:09,005 [salt.utils.schedule:568 ][INFO    ][4651] Updating job settings for scheduled job: __mine_interval
2018-12-27 10:45:09,008 [salt.minion      :1108][INFO    ][4651] Added mine.update to scheduler
2018-12-27 10:45:09,014 [salt.minion      :1975][INFO    ][4651] Minion is starting as user 'root'
2018-12-27 10:45:09,028 [salt.minion      :2336][INFO    ][4651] Minion is ready to receive requests!
2018-12-27 10:45:15,674 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104515662524
2018-12-27 10:45:15,693 [salt.minion      :1432][INFO    ][4855] Starting a new job with PID 4855
2018-12-27 10:45:15,734 [salt.minion      :1711][INFO    ][4855] Returning information for job: 20181227104515662524
2018-12-27 10:45:18,329 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,408 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,410 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,411 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,412 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,414 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,415 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,416 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,417 [salt.loaded.int.states.file:2298][WARNING ][4621] 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-27 10:45:21,578 [salt.utils.decorators:613 ][WARNING ][4621] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:45:21,929 [salt.loaded.int.module.cmdmod:730 ][ERROR   ][4621] Command '['umount', '/dev/shm']' failed with return code: 32
2018-12-27 10:45:21,930 [salt.loaded.int.module.cmdmod:734 ][ERROR   ][4621] 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-27 10:45:21,930 [salt.loaded.int.module.cmdmod:736 ][ERROR   ][4621] retcode: 32
2018-12-27 10:45:25,754 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104525742669
2018-12-27 10:45:25,788 [salt.minion      :1432][INFO    ][5847] Starting a new job with PID 5847
2018-12-27 10:45:25,823 [salt.minion      :1711][INFO    ][5847] Returning information for job: 20181227104525742669
2018-12-27 10:45:28,837 [salt.utils.decorators:613 ][WARNING ][4621] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:45:28,874 [salt.utils.decorators:613 ][WARNING ][4621] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:45:29,565 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227104529553204
2018-12-27 10:45:29,604 [salt.minion      :1432][INFO    ][6013] Starting a new job with PID 6013
2018-12-27 10:45:35,405 [salt.state       :915 ][INFO    ][6013] Loading fresh modules for state activity
2018-12-27 10:45:35,459 [salt.fileclient  :1219][INFO    ][6013] Fetching file from saltenv 'base', ** done ** 'maas/cluster.sls'
2018-12-27 10:45:36,239 [salt.state       :1780][INFO    ][6013] Running state [maas-rack-controller] at time 10:45:36.239824
2018-12-27 10:45:36,240 [salt.state       :1813][INFO    ][6013] Executing state pkg.installed for [maas-rack-controller]
2018-12-27 10:45:36,240 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-27 10:45:36,637 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['apt-cache', '-q', 'policy', 'maas-rack-controller'] in directory '/root'
2018-12-27 10:45:36,713 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['apt-get', '-q', 'update'] in directory '/root'
2018-12-27 10:45:38,646 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-27 10:45:38,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] 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-27 10:45:39,608 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104539593299
2018-12-27 10:45:39,646 [salt.minion      :1432][INFO    ][6301] Starting a new job with PID 6301
2018-12-27 10:45:39,685 [salt.minion      :1711][INFO    ][6301] Returning information for job: 20181227104539593299
2018-12-27 10:45:49,693 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104549683343
2018-12-27 10:45:49,742 [salt.minion      :1432][INFO    ][8278] Starting a new job with PID 8278
2018-12-27 10:45:49,813 [salt.minion      :1711][INFO    ][8278] Returning information for job: 20181227104549683343
2018-12-27 10:45:59,778 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104559762641
2018-12-27 10:45:59,797 [salt.minion      :1432][INFO    ][8945] Starting a new job with PID 8945
2018-12-27 10:45:59,844 [salt.minion      :1711][INFO    ][8945] Returning information for job: 20181227104559762641
2018-12-27 10:46:09,836 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104609814481
2018-12-27 10:46:09,864 [salt.minion      :1432][INFO    ][9584] Starting a new job with PID 9584
2018-12-27 10:46:09,902 [salt.minion      :1711][INFO    ][9584] Returning information for job: 20181227104609814481
2018-12-27 10:46:17,623 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-27 10:46:17,661 [salt.state       :300 ][INFO    ][6013] 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-27 10:46:17,691 [salt.state       :915 ][INFO    ][6013] Loading fresh modules for state activity
2018-12-27 10:46:17,741 [salt.state       :1951][INFO    ][6013] Completed state [maas-rack-controller] at time 10:46:17.741621 duration_in_ms=41501.797
2018-12-27 10:46:17,747 [salt.state       :1780][INFO    ][6013] Running state [ipmitool] at time 10:46:17.747900
2018-12-27 10:46:17,748 [salt.state       :1813][INFO    ][6013] Executing state pkg.installed for [ipmitool]
2018-12-27 10:46:18,516 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-27 10:46:18,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] 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-27 10:46:19,905 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104619895386
2018-12-27 10:46:19,936 [salt.minion      :1432][INFO    ][9835] Starting a new job with PID 9835
2018-12-27 10:46:19,982 [salt.minion      :1711][INFO    ][9835] Returning information for job: 20181227104619895386
2018-12-27 10:46:22,956 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-27 10:46:22,996 [salt.state       :300 ][INFO    ][6013] 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-27 10:46:23,020 [salt.state       :915 ][INFO    ][6013] Loading fresh modules for state activity
2018-12-27 10:46:23,061 [salt.state       :1951][INFO    ][6013] Completed state [ipmitool] at time 10:46:23.061339 duration_in_ms=5313.438
2018-12-27 10:46:23,066 [salt.state       :1780][INFO    ][6013] Running state [/etc/maas/rackd.conf] at time 10:46:23.066551
2018-12-27 10:46:23,066 [salt.state       :1813][INFO    ][6013] Executing state file.line for [/etc/maas/rackd.conf]
2018-12-27 10:46:23,071 [salt.state       :300 ][INFO    ][6013] No changes needed to be made
2018-12-27 10:46:23,071 [salt.state       :1951][INFO    ][6013] Completed state [/etc/maas/rackd.conf] at time 10:46:23.071944 duration_in_ms=5.393
2018-12-27 10:46:23,072 [salt.state       :1780][INFO    ][6013] Running state [/etc/maas/rackd.conf] at time 10:46:23.072184
2018-12-27 10:46:23,072 [salt.state       :1813][INFO    ][6013] Executing state file.managed for [/etc/maas/rackd.conf]
2018-12-27 10:46:23,072 [salt.loaded.int.states.file:2298][WARNING ][6013] 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-27 10:46:23,073 [salt.state       :300 ][INFO    ][6013] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2018-12-27 10:46:23,073 [salt.state       :1951][INFO    ][6013] Completed state [/etc/maas/rackd.conf] at time 10:46:23.073610 duration_in_ms=1.426
2018-12-27 10:46:23,594 [salt.state       :1780][INFO    ][6013] Running state [maas-rackd] at time 10:46:23.594794
2018-12-27 10:46:23,595 [salt.state       :1813][INFO    ][6013] Executing state service.running for [maas-rackd]
2018-12-27 10:46:23,595 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2018-12-27 10:46:23,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2018-12-27 10:46:23,626 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6013] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2018-12-27 10:46:23,638 [salt.state       :300 ][INFO    ][6013] The service maas-rackd is already running
2018-12-27 10:46:23,639 [salt.state       :1951][INFO    ][6013] Completed state [maas-rackd] at time 10:46:23.639205 duration_in_ms=44.412
2018-12-27 10:46:23,641 [salt.minion      :1711][INFO    ][6013] Returning information for job: 20181227104529553204
2018-12-27 10:46:24,219 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227104624204317
2018-12-27 10:46:24,252 [salt.minion      :1432][INFO    ][10783] Starting a new job with PID 10783
2018-12-27 10:46:29,900 [salt.state       :915 ][INFO    ][10783] Loading fresh modules for state activity
2018-12-27 10:46:29,955 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/region.sls'
2018-12-27 10:46:30,854 [salt.state       :1780][INFO    ][10783] Running state [maas-region-controller] at time 10:46:30.854255
2018-12-27 10:46:30,854 [salt.state       :1813][INFO    ][10783] Executing state pkg.installed for [maas-region-controller]
2018-12-27 10:46:30,855 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-27 10:46:31,245 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['apt-cache', '-q', 'policy', 'maas-region-controller'] in directory '/root'
2018-12-27 10:46:31,314 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['apt-get', '-q', 'update'] in directory '/root'
2018-12-27 10:46:33,129 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['dpkg', '--get-selections', '*'] in directory '/root'
2018-12-27 10:46:33,159 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] 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-27 10:46:34,321 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104634308878
2018-12-27 10:46:34,356 [salt.minion      :1432][INFO    ][11068] Starting a new job with PID 11068
2018-12-27 10:46:34,399 [salt.minion      :1711][INFO    ][11068] Returning information for job: 20181227104634308878
2018-12-27 10:46:44,387 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104644373510
2018-12-27 10:46:44,439 [salt.minion      :1432][INFO    ][11610] Starting a new job with PID 11610
2018-12-27 10:46:44,492 [salt.minion      :1711][INFO    ][11610] Returning information for job: 20181227104644373510
2018-12-27 10:46:54,454 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104654441924
2018-12-27 10:46:54,484 [salt.minion      :1432][INFO    ][13464] Starting a new job with PID 13464
2018-12-27 10:46:54,528 [salt.minion      :1711][INFO    ][13464] Returning information for job: 20181227104654441924
2018-12-27 10:47:04,513 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104704500467
2018-12-27 10:47:04,541 [salt.minion      :1432][INFO    ][14491] Starting a new job with PID 14491
2018-12-27 10:47:04,598 [salt.minion      :1711][INFO    ][14491] Returning information for job: 20181227104704500467
2018-12-27 10:47:14,565 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104714553879
2018-12-27 10:47:14,583 [salt.minion      :1432][INFO    ][14500] Starting a new job with PID 14500
2018-12-27 10:47:14,618 [salt.minion      :1711][INFO    ][14500] Returning information for job: 20181227104714553879
2018-12-27 10:47:24,615 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104724603997
2018-12-27 10:47:24,640 [salt.minion      :1432][INFO    ][14515] Starting a new job with PID 14515
2018-12-27 10:47:24,690 [salt.minion      :1711][INFO    ][14515] Returning information for job: 20181227104724603997
2018-12-27 10:47:34,697 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104734685199
2018-12-27 10:47:34,722 [salt.minion      :1432][INFO    ][15140] Starting a new job with PID 15140
2018-12-27 10:47:34,765 [salt.minion      :1711][INFO    ][15140] Returning information for job: 20181227104734685199
2018-12-27 10:47:44,756 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104744741983
2018-12-27 10:47:44,801 [salt.minion      :1432][INFO    ][15689] Starting a new job with PID 15689
2018-12-27 10:47:44,866 [salt.minion      :1711][INFO    ][15689] Returning information for job: 20181227104744741983
2018-12-27 10:47:54,830 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104754811697
2018-12-27 10:47:54,858 [salt.minion      :1432][INFO    ][16036] Starting a new job with PID 16036
2018-12-27 10:47:54,892 [salt.minion      :1711][INFO    ][16036] Returning information for job: 20181227104754811697
2018-12-27 10:48:04,898 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104804885108
2018-12-27 10:48:04,924 [salt.minion      :1432][INFO    ][16677] Starting a new job with PID 16677
2018-12-27 10:48:04,979 [salt.minion      :1711][INFO    ][16677] Returning information for job: 20181227104804885108
2018-12-27 10:48:14,953 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104814940011
2018-12-27 10:48:15,004 [salt.minion      :1432][INFO    ][16688] Starting a new job with PID 16688
2018-12-27 10:48:15,048 [salt.minion      :1711][INFO    ][16688] Returning information for job: 20181227104814940011
2018-12-27 10:48:25,011 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104824999521
2018-12-27 10:48:25,038 [salt.minion      :1432][INFO    ][16699] Starting a new job with PID 16699
2018-12-27 10:48:25,098 [salt.minion      :1711][INFO    ][16699] Returning information for job: 20181227104824999521
2018-12-27 10:48:35,068 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104835056365
2018-12-27 10:48:35,114 [salt.minion      :1432][INFO    ][16704] Starting a new job with PID 16704
2018-12-27 10:48:35,155 [salt.minion      :1711][INFO    ][16704] Returning information for job: 20181227104835056365
2018-12-27 10:48:45,122 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104845109929
2018-12-27 10:48:45,171 [salt.minion      :1432][INFO    ][16710] Starting a new job with PID 16710
2018-12-27 10:48:45,222 [salt.minion      :1711][INFO    ][16710] Returning information for job: 20181227104845109929
2018-12-27 10:48:55,200 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104855184860
2018-12-27 10:48:55,238 [salt.minion      :1432][INFO    ][16715] Starting a new job with PID 16715
2018-12-27 10:48:55,288 [salt.minion      :1711][INFO    ][16715] Returning information for job: 20181227104855184860
2018-12-27 10:49:05,273 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104905261424
2018-12-27 10:49:05,319 [salt.minion      :1432][INFO    ][16721] Starting a new job with PID 16721
2018-12-27 10:49:05,365 [salt.minion      :1711][INFO    ][16721] Returning information for job: 20181227104905261424
2018-12-27 10:49:15,343 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104915330305
2018-12-27 10:49:15,388 [salt.minion      :1432][INFO    ][16726] Starting a new job with PID 16726
2018-12-27 10:49:15,451 [salt.minion      :1711][INFO    ][16726] Returning information for job: 20181227104915330305
2018-12-27 10:49:25,409 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104925397214
2018-12-27 10:49:25,442 [salt.minion      :1432][INFO    ][16738] Starting a new job with PID 16738
2018-12-27 10:49:25,488 [salt.minion      :1711][INFO    ][16738] Returning information for job: 20181227104925397214
2018-12-27 10:49:35,505 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104935489893
2018-12-27 10:49:35,547 [salt.minion      :1432][INFO    ][17267] Starting a new job with PID 17267
2018-12-27 10:49:35,597 [salt.minion      :1711][INFO    ][17267] Returning information for job: 20181227104935489893
2018-12-27 10:49:45,603 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104945590240
2018-12-27 10:49:45,654 [salt.minion      :1432][INFO    ][17373] Starting a new job with PID 17373
2018-12-27 10:49:45,705 [salt.minion      :1711][INFO    ][17373] Returning information for job: 20181227104945590240
2018-12-27 10:49:48,603 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2018-12-27 10:49:48,648 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:48,675 [salt.state       :915 ][INFO    ][10783] Loading fresh modules for state activity
2018-12-27 10:49:48,723 [salt.state       :1951][INFO    ][10783] Completed state [maas-region-controller] at time 10:49:48.723779 duration_in_ms=197869.523
2018-12-27 10:49:48,731 [salt.state       :1780][INFO    ][10783] Running state [python-oauth] at time 10:49:48.731198
2018-12-27 10:49:48,731 [salt.state       :1813][INFO    ][10783] Executing state pkg.installed for [python-oauth]
2018-12-27 10:49:49,581 [salt.state       :300 ][INFO    ][10783] All specified packages are already installed
2018-12-27 10:49:49,581 [salt.state       :1951][INFO    ][10783] Completed state [python-oauth] at time 10:49:49.581585 duration_in_ms=850.386
2018-12-27 10:49:49,585 [salt.state       :1780][INFO    ][10783] Running state [/etc/maas/regiond.conf] at time 10:49:49.585347
2018-12-27 10:49:49,585 [salt.state       :1813][INFO    ][10783] Executing state file.replace for [/etc/maas/regiond.conf]
2018-12-27 10:49:49,592 [salt.state       :300 ][INFO    ][10783] File changed:
--- 
+++ 
@@ -3,4 +3,4 @@
 database_pass: BuzkuH56p0lC
 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-27 10:49:49,592 [salt.state       :1951][INFO    ][10783] Completed state [/etc/maas/regiond.conf] at time 10:49:49.592515 duration_in_ms=7.168
2018-12-27 10:49:49,593 [salt.state       :1780][INFO    ][10783] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 10:49:49.593047
2018-12-27 10:49:49,593 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2018-12-27 10:49:49,621 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/maas-proxy.conf.template'
2018-12-27 10:49:49,657 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:49,658 [salt.state       :1951][INFO    ][10783] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 10:49:49.658002 duration_in_ms=64.955
2018-12-27 10:49:49,658 [salt.state       :1780][INFO    ][10783] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:49:49.658544
2018-12-27 10:49:49,658 [salt.state       :1813][INFO    ][10783] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2018-12-27 10:49:49,663 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:49,664 [salt.state       :1951][INFO    ][10783] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:49:49.664114 duration_in_ms=5.57
2018-12-27 10:49:49,664 [salt.state       :1780][INFO    ][10783] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:49:49.664588
2018-12-27 10:49:49,664 [salt.state       :1813][INFO    ][10783] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2018-12-27 10:49:49,668 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:49,668 [salt.state       :1951][INFO    ][10783] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 10:49:49.668558 duration_in_ms=3.97
2018-12-27 10:49:49,669 [salt.state       :1780][INFO    ][10783] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 10:49:49.669078
2018-12-27 10:49:49,669 [salt.state       :1813][INFO    ][10783] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2018-12-27 10:49:49,698 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:49,698 [salt.state       :1951][INFO    ][10783] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 10:49:49.698794 duration_in_ms=29.716
2018-12-27 10:49:49,699 [salt.state       :1780][INFO    ][10783] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 10:49:49.699849
2018-12-27 10:49:49,700 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2018-12-27 10:49:49,720 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/maas-http.conf'
2018-12-27 10:49:49,725 [salt.state       :300 ][INFO    ][10783] 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-27 10:49:49,725 [salt.state       :1951][INFO    ][10783] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 10:49:49.725646 duration_in_ms=25.797
2018-12-27 10:49:49,727 [salt.state       :1780][INFO    ][10783] Running state [a2enmod headers] at time 10:49:49.727011
2018-12-27 10:49:49,727 [salt.state       :1813][INFO    ][10783] Executing state cmd.run for [a2enmod headers]
2018-12-27 10:49:49,728 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command 'a2enmod headers' in directory '/root'
2018-12-27 10:49:49,797 [salt.state       :300 ][INFO    ][10783] {'pid': 17587, 'retcode': 0, 'stderr': '', 'stdout': 'Enabling module headers.\nTo activate the new configuration, you need to run:\n  service apache2 restart'}
2018-12-27 10:49:49,797 [salt.state       :1951][INFO    ][10783] Completed state [a2enmod headers] at time 10:49:49.797680 duration_in_ms=70.669
2018-12-27 10:49:49,798 [salt.state       :1780][INFO    ][10783] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 10:49:49.798064
2018-12-27 10:49:49,798 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2018-12-27 10:49:49,830 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/mirantis-styles.css'
2018-12-27 10:49:49,835 [salt.state       :300 ][INFO    ][10783] File changed:
New file
2018-12-27 10:49:49,836 [salt.state       :1951][INFO    ][10783] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 10:49:49.836068 duration_in_ms=38.004
2018-12-27 10:49:49,836 [salt.state       :1780][INFO    ][10783] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 10:49:49.836941
2018-12-27 10:49:49,837 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2018-12-27 10:49:49,858 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_amd64_generic_trusty'
2018-12-27 10:49:49,898 [salt.state       :300 ][INFO    ][10783] File changed:
New file
2018-12-27 10:49:49,898 [salt.state       :1951][INFO    ][10783] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 10:49:49.898743 duration_in_ms=61.802
2018-12-27 10:49:49,899 [salt.state       :1780][INFO    ][10783] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 10:49:49.899566
2018-12-27 10:49:49,899 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2018-12-27 10:49:49,921 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_amd64_generic_xenial'
2018-12-27 10:49:49,973 [salt.state       :300 ][INFO    ][10783] File changed:
New file
2018-12-27 10:49:49,973 [salt.state       :1951][INFO    ][10783] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 10:49:49.973900 duration_in_ms=74.334
2018-12-27 10:49:49,974 [salt.state       :1780][INFO    ][10783] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 10:49:49.974411
2018-12-27 10:49:49,974 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2018-12-27 10:49:49,993 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/curtin_userdata_arm64_generic_xenial'
2018-12-27 10:49:50,054 [salt.state       :300 ][INFO    ][10783] File changed:
New file
2018-12-27 10:49:50,054 [salt.state       :1951][INFO    ][10783] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 10:49:50.054271 duration_in_ms=79.86
2018-12-27 10:49:50,054 [salt.state       :1780][INFO    ][10783] Running state [/root/.pgpass] at time 10:49:50.054528
2018-12-27 10:49:50,054 [salt.state       :1813][INFO    ][10783] Executing state file.managed for [/root/.pgpass]
2018-12-27 10:49:50,073 [salt.fileclient  :1219][INFO    ][10783] Fetching file from saltenv 'base', ** done ** 'maas/files/pgpass'
2018-12-27 10:49:50,123 [salt.state       :300 ][INFO    ][10783] File changed:
New file
2018-12-27 10:49:50,124 [salt.state       :1951][INFO    ][10783] Completed state [/root/.pgpass] at time 10:49:50.124151 duration_in_ms=69.623
2018-12-27 10:49:50,129 [salt.state       :1780][INFO    ][10783] Running state [maas-region syncdb --noinput] at time 10:49:50.129197
2018-12-27 10:49:50,129 [salt.state       :1813][INFO    ][10783] Executing state cmd.run for [maas-region syncdb --noinput]
2018-12-27 10:49:50,130 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command 'maas-region syncdb --noinput' in directory '/root'
2018-12-27 10:49:52,866 [salt.state       :300 ][INFO    ][10783] {'pid': 17605, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: piston3, metadataserver, contenttypes, sites, auth, maasserver, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2018-12-27 10:49:52,866 [salt.state       :1951][INFO    ][10783] Completed state [maas-region syncdb --noinput] at time 10:49:52.866833 duration_in_ms=2737.635
2018-12-27 10:49:52,867 [salt.state       :2022][WARNING ][10783] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2018-12-27 10:49:52,869 [salt.state       :1780][INFO    ][10783] Running state [maas-regiond] at time 10:49:52.869188
2018-12-27 10:49:52,869 [salt.state       :1813][INFO    ][10783] Executing state service.running for [maas-regiond]
2018-12-27 10:49:52,870 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2018-12-27 10:49:52,888 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2018-12-27 10:49:52,905 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2018-12-27 10:49:52,921 [salt.state       :300 ][INFO    ][10783] The service maas-regiond is already running
2018-12-27 10:49:52,922 [salt.state       :1951][INFO    ][10783] Completed state [maas-regiond] at time 10:49:52.922256 duration_in_ms=53.067
2018-12-27 10:49:52,923 [salt.state       :1780][INFO    ][10783] Running state [maas-regiond] at time 10:49:52.922919
2018-12-27 10:49:52,924 [salt.state       :1813][INFO    ][10783] Executing state service.mod_watch for [maas-regiond]
2018-12-27 10:49:52,926 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2018-12-27 10:49:52,945 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'maas-regiond.service'] in directory '/root'
2018-12-27 10:49:53,025 [salt.state       :300 ][INFO    ][10783] {'maas-regiond': True}
2018-12-27 10:49:53,026 [salt.state       :1951][INFO    ][10783] Completed state [maas-regiond] at time 10:49:53.026607 duration_in_ms=103.688
2018-12-27 10:49:53,028 [salt.state       :1780][INFO    ][10783] Running state [bind9] at time 10:49:53.028727
2018-12-27 10:49:53,029 [salt.state       :1813][INFO    ][10783] Executing state service.running for [bind9]
2018-12-27 10:49:53,030 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2018-12-27 10:49:53,046 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2018-12-27 10:49:53,063 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2018-12-27 10:49:53,091 [salt.state       :300 ][INFO    ][10783] The service bind9 is already running
2018-12-27 10:49:53,092 [salt.state       :1951][INFO    ][10783] Completed state [bind9] at time 10:49:53.092014 duration_in_ms=63.287
2018-12-27 10:49:53,092 [salt.state       :1780][INFO    ][10783] Running state [bind9] at time 10:49:53.092305
2018-12-27 10:49:53,092 [salt.state       :1813][INFO    ][10783] Executing state service.mod_watch for [bind9]
2018-12-27 10:49:53,093 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2018-12-27 10:49:53,111 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'bind9.service'] in directory '/root'
2018-12-27 10:49:53,172 [salt.state       :300 ][INFO    ][10783] {'bind9': True}
2018-12-27 10:49:53,172 [salt.state       :1951][INFO    ][10783] Completed state [bind9] at time 10:49:53.172749 duration_in_ms=80.444
2018-12-27 10:49:53,184 [salt.state       :1780][INFO    ][10783] Running state [apache2] at time 10:49:53.184443
2018-12-27 10:49:53,184 [salt.state       :1813][INFO    ][10783] Executing state service.running for [apache2]
2018-12-27 10:49:53,185 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2018-12-27 10:49:53,200 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2018-12-27 10:49:53,223 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2018-12-27 10:49:53,252 [salt.state       :300 ][INFO    ][10783] The service apache2 is already running
2018-12-27 10:49:53,252 [salt.state       :1951][INFO    ][10783] Completed state [apache2] at time 10:49:53.252558 duration_in_ms=68.115
2018-12-27 10:49:53,252 [salt.state       :1780][INFO    ][10783] Running state [apache2] at time 10:49:53.252837
2018-12-27 10:49:53,253 [salt.state       :1813][INFO    ][10783] Executing state service.mod_watch for [apache2]
2018-12-27 10:49:53,254 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2018-12-27 10:49:53,272 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'apache2.service'] in directory '/root'
2018-12-27 10:49:54,543 [salt.state       :300 ][INFO    ][10783] {'apache2': True}
2018-12-27 10:49:54,543 [salt.state       :1951][INFO    ][10783] Completed state [apache2] at time 10:49:54.543789 duration_in_ms=1290.951
2018-12-27 10:49:54,545 [salt.state       :1780][INFO    ][10783] Running state [maasng.wait_for_http_code] at time 10:49:54.545167
2018-12-27 10:49:54,545 [salt.state       :1813][INFO    ][10783] Executing state module.run for [maasng.wait_for_http_code]
2018-12-27 10:49:54,545 [salt.utils.decorators:613 ][WARNING ][10783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:49:54,549 [salt.loaded.ext.module.maasng:1435][INFO    ][10783] Waiting for api:http://localhost:5240/MAAS
sleep for:5s Left:120.0/120s
2018-12-27 10:49:55,694 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227104955681376
2018-12-27 10:49:55,731 [salt.minion      :1432][INFO    ][17900] Starting a new job with PID 17900
2018-12-27 10:49:55,801 [salt.minion      :1711][INFO    ][17900] Returning information for job: 20181227104955681376
2018-12-27 10:49:59,666 [salt.state       :300 ][INFO    ][10783] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2018-12-27 10:49:59,668 [salt.state       :1951][INFO    ][10783] Completed state [maasng.wait_for_http_code] at time 10:49:59.667877 duration_in_ms=5122.708
2018-12-27 10:49:59,670 [salt.state       :1780][INFO    ][10783] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 10:49:59.670172
2018-12-27 10:49:59,670 [salt.state       :1813][INFO    ][10783] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2018-12-27 10:49:59,672 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command 'maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin' in directory '/root'
2018-12-27 10:50:01,632 [salt.state       :300 ][INFO    ][10783] {'pid': 17969, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 10:50:01,633 [salt.state       :1951][INFO    ][10783] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 10:50:01.633137 duration_in_ms=1962.965
2018-12-27 10:50:01,634 [salt.state       :1780][INFO    ][10783] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:50:01.634772
2018-12-27 10:50:01,635 [salt.state       :1813][INFO    ][10783] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 10:50:01,636 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10783] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 10:50:03,615 [salt.state       :300 ][INFO    ][10783] {'pid': 17977, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 10:50:03,615 [salt.state       :1951][INFO    ][10783] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 10:50:03.615787 duration_in_ms=1981.016
2018-12-27 10:50:03,623 [salt.state       :1780][INFO    ][10783] Running state [maas_region_boot_source_resources_mirror] at time 10:50:03.623253
2018-12-27 10:50:03,623 [salt.state       :1813][INFO    ][10783] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2018-12-27 10:50:04,576 [salt.loaded.ext.module.maasng:1508][INFO    ][10783] Removing boot-source:http://images.maas.io/ephemeral-v3/daily/
2018-12-27 10:50:05,795 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105005777285
2018-12-27 10:50:05,823 [salt.minion      :1432][INFO    ][18028] Starting a new job with PID 18028
2018-12-27 10:50:05,863 [salt.minion      :1711][INFO    ][18028] Returning information for job: 20181227105005777285
2018-12-27 10:50:07,353 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2018-12-27 10:50:12,401 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2018-12-27 10:50:15,895 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105015881058
2018-12-27 10:50:15,938 [salt.minion      :1432][INFO    ][18091] Starting a new job with PID 18091
2018-12-27 10:50:15,986 [salt.minion      :1711][INFO    ][18091] Returning information for job: 20181227105015881058
2018-12-27 10:50:17,450 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2018-12-27 10:50:22,511 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2018-12-27 10:50:26,004 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105025981725
2018-12-27 10:50:26,043 [salt.minion      :1432][INFO    ][18150] Starting a new job with PID 18150
2018-12-27 10:50:26,081 [salt.minion      :1711][INFO    ][18150] Returning information for job: 20181227105025981725
2018-12-27 10:50:27,564 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2018-12-27 10:50:32,617 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2018-12-27 10:50:36,123 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105036108366
2018-12-27 10:50:36,151 [salt.minion      :1432][INFO    ][18196] Starting a new job with PID 18196
2018-12-27 10:50:36,197 [salt.minion      :1711][INFO    ][18196] Returning information for job: 20181227105036108366
2018-12-27 10:50:37,703 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2018-12-27 10:50:42,755 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:865.0/900s
2018-12-27 10:50:46,243 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105046228981
2018-12-27 10:50:46,276 [salt.minion      :1432][INFO    ][18239] Starting a new job with PID 18239
2018-12-27 10:50:46,322 [salt.minion      :1711][INFO    ][18239] Returning information for job: 20181227105046228981
2018-12-27 10:50:47,818 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:859.0/900s
2018-12-27 10:50:52,854 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:854.0/900s
2018-12-27 10:50:56,387 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105056361815
2018-12-27 10:50:56,420 [salt.minion      :1432][INFO    ][18303] Starting a new job with PID 18303
2018-12-27 10:50:56,471 [salt.minion      :1711][INFO    ][18303] Returning information for job: 20181227105056361815
2018-12-27 10:50:57,909 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2018-12-27 10:51:02,952 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2018-12-27 10:51:06,449 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105106434419
2018-12-27 10:51:06,486 [salt.minion      :1432][INFO    ][18353] Starting a new job with PID 18353
2018-12-27 10:51:06,532 [salt.minion      :1711][INFO    ][18353] Returning information for job: 20181227105106434419
2018-12-27 10:51:08,014 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2018-12-27 10:51:13,065 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2018-12-27 10:51:16,507 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105116487862
2018-12-27 10:51:16,542 [salt.minion      :1432][INFO    ][18396] Starting a new job with PID 18396
2018-12-27 10:51:16,596 [salt.minion      :1711][INFO    ][18396] Returning information for job: 20181227105116487862
2018-12-27 10:51:18,127 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2018-12-27 10:51:23,302 [salt.state       :300 ][INFO    ][10783] {'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-27 10:51:23,303 [salt.state       :1951][INFO    ][10783] Completed state [maas_region_boot_source_resources_mirror] at time 10:51:23.303008 duration_in_ms=79679.754
2018-12-27 10:51:23,304 [salt.state       :1780][INFO    ][10783] Running state [maasng.boot_resources_import] at time 10:51:23.304133
2018-12-27 10:51:23,304 [salt.state       :1813][INFO    ][10783] Executing state module.run for [maasng.boot_resources_import]
2018-12-27 10:51:23,305 [salt.utils.decorators:613 ][WARNING ][10783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 10:51:24,656 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:899.0/900s
2018-12-27 10:51:26,635 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105126620935
2018-12-27 10:51:26,671 [salt.minion      :1432][INFO    ][18568] Starting a new job with PID 18568
2018-12-27 10:51:26,717 [salt.minion      :1711][INFO    ][18568] Returning information for job: 20181227105126620935
2018-12-27 10:51:29,694 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:894.0/900s
2018-12-27 10:51:35,199 [salt.state       :300 ][INFO    ][10783] {'ret': True}
2018-12-27 10:51:35,200 [salt.state       :1951][INFO    ][10783] Completed state [maasng.boot_resources_import] at time 10:51:35.200323 duration_in_ms=11896.189
2018-12-27 10:51:35,202 [salt.state       :1780][INFO    ][10783] Running state [maas_region_boot_sources_selection_xenial] at time 10:51:35.202255
2018-12-27 10:51:35,202 [salt.state       :1813][INFO    ][10783] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2018-12-27 10:51:36,745 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105136729127
2018-12-27 10:51:36,774 [salt.minion      :1432][INFO    ][18703] Starting a new job with PID 18703
2018-12-27 10:51:36,821 [salt.minion      :1711][INFO    ][18703] Returning information for job: 20181227105136729127
2018-12-27 10:51:40,516 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2018-12-27 10:51:45,570 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2018-12-27 10:51:46,862 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105146845444
2018-12-27 10:51:46,903 [salt.minion      :1432][INFO    ][18730] Starting a new job with PID 18730
2018-12-27 10:51:46,947 [salt.minion      :1711][INFO    ][18730] Returning information for job: 20181227105146845444
2018-12-27 10:51:50,610 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2018-12-27 10:51:55,659 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2018-12-27 10:51:56,990 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105156974687
2018-12-27 10:51:57,029 [salt.minion      :1432][INFO    ][18784] Starting a new job with PID 18784
2018-12-27 10:51:57,075 [salt.minion      :1711][INFO    ][18784] Returning information for job: 20181227105156974687
2018-12-27 10:52:00,725 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2018-12-27 10:52:05,799 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2018-12-27 10:52:07,143 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105207125447
2018-12-27 10:52:07,171 [salt.minion      :1432][INFO    ][18797] Starting a new job with PID 18797
2018-12-27 10:52:07,224 [salt.minion      :1711][INFO    ][18797] Returning information for job: 20181227105207125447
2018-12-27 10:52:10,866 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2018-12-27 10:52:15,927 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:865.0/900s
2018-12-27 10:52:17,298 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105217283623
2018-12-27 10:52:17,324 [salt.minion      :1432][INFO    ][18805] Starting a new job with PID 18805
2018-12-27 10:52:17,370 [salt.minion      :1711][INFO    ][18805] Returning information for job: 20181227105217283623
2018-12-27 10:52:20,992 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:859.0/900s
2018-12-27 10:52:26,039 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:854.0/900s
2018-12-27 10:52:27,451 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105227437343
2018-12-27 10:52:27,476 [salt.minion      :1432][INFO    ][18833] Starting a new job with PID 18833
2018-12-27 10:52:27,536 [salt.minion      :1711][INFO    ][18833] Returning information for job: 20181227105227437343
2018-12-27 10:52:31,092 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2018-12-27 10:52:36,151 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2018-12-27 10:52:37,653 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105237633171
2018-12-27 10:52:37,686 [salt.minion      :1432][INFO    ][18848] Starting a new job with PID 18848
2018-12-27 10:52:37,732 [salt.minion      :1711][INFO    ][18848] Returning information for job: 20181227105237633171
2018-12-27 10:52:41,225 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2018-12-27 10:52:46,284 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2018-12-27 10:52:47,798 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105247783344
2018-12-27 10:52:47,816 [salt.minion      :1432][INFO    ][18857] Starting a new job with PID 18857
2018-12-27 10:52:47,863 [salt.minion      :1711][INFO    ][18857] Returning information for job: 20181227105247783344
2018-12-27 10:52:51,349 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2018-12-27 10:52:56,406 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:824.0/900s
2018-12-27 10:52:57,986 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105257955066
2018-12-27 10:52:58,025 [salt.minion      :1432][INFO    ][18885] Starting a new job with PID 18885
2018-12-27 10:52:58,094 [salt.minion      :1711][INFO    ][18885] Returning information for job: 20181227105257955066
2018-12-27 10:53:01,467 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:819.0/900s
2018-12-27 10:53:06,520 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:814.0/900s
2018-12-27 10:53:08,151 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105308130138
2018-12-27 10:53:08,187 [salt.minion      :1432][INFO    ][18896] Starting a new job with PID 18896
2018-12-27 10:53:08,233 [salt.minion      :1711][INFO    ][18896] Returning information for job: 20181227105308130138
2018-12-27 10:53:11,571 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:809.0/900s
2018-12-27 10:53:16,626 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:804.0/900s
2018-12-27 10:53:18,304 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105318289916
2018-12-27 10:53:18,331 [salt.minion      :1432][INFO    ][18908] Starting a new job with PID 18908
2018-12-27 10:53:18,384 [salt.minion      :1711][INFO    ][18908] Returning information for job: 20181227105318289916
2018-12-27 10:53:21,676 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:799.0/900s
2018-12-27 10:53:26,730 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:794.0/900s
2018-12-27 10:53:28,456 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105328442090
2018-12-27 10:53:28,504 [salt.minion      :1432][INFO    ][18931] Starting a new job with PID 18931
2018-12-27 10:53:28,544 [salt.minion      :1711][INFO    ][18931] Returning information for job: 20181227105328442090
2018-12-27 10:53:31,794 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:789.0/900s
2018-12-27 10:53:36,903 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:784.0/900s
2018-12-27 10:53:38,635 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105338613059
2018-12-27 10:53:38,671 [salt.minion      :1432][INFO    ][18943] Starting a new job with PID 18943
2018-12-27 10:53:38,711 [salt.minion      :1711][INFO    ][18943] Returning information for job: 20181227105338613059
2018-12-27 10:53:41,968 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:779.0/900s
2018-12-27 10:53:47,041 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:773.0/900s
2018-12-27 10:53:48,844 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105348828983
2018-12-27 10:53:48,871 [salt.minion      :1432][INFO    ][18961] Starting a new job with PID 18961
2018-12-27 10:53:48,917 [salt.minion      :1711][INFO    ][18961] Returning information for job: 20181227105348828983
2018-12-27 10:53:52,102 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:768.0/900s
2018-12-27 10:53:57,162 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:763.0/900s
2018-12-27 10:53:59,071 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105359048152
2018-12-27 10:53:59,107 [salt.minion      :1432][INFO    ][18987] Starting a new job with PID 18987
2018-12-27 10:53:59,160 [salt.minion      :1711][INFO    ][18987] Returning information for job: 20181227105359048152
2018-12-27 10:54:02,218 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:758.0/900s
2018-12-27 10:54:07,274 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:753.0/900s
2018-12-27 10:54:09,099 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105409079008
2018-12-27 10:54:09,138 [salt.minion      :1432][INFO    ][18996] Starting a new job with PID 18996
2018-12-27 10:54:09,187 [salt.minion      :1711][INFO    ][18996] Returning information for job: 20181227105409079008
2018-12-27 10:54:12,338 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:748.0/900s
2018-12-27 10:54:17,403 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:743.0/900s
2018-12-27 10:54:19,134 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105419113105
2018-12-27 10:54:19,179 [salt.minion      :1432][INFO    ][19012] Starting a new job with PID 19012
2018-12-27 10:54:19,226 [salt.minion      :1711][INFO    ][19012] Returning information for job: 20181227105419113105
2018-12-27 10:54:22,469 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:738.0/900s
2018-12-27 10:54:27,543 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:733.0/900s
2018-12-27 10:54:29,187 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105429166727
2018-12-27 10:54:29,227 [salt.minion      :1432][INFO    ][19060] Starting a new job with PID 19060
2018-12-27 10:54:29,272 [salt.minion      :1711][INFO    ][19060] Returning information for job: 20181227105429166727
2018-12-27 10:54:32,605 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:728.0/900s
2018-12-27 10:54:37,661 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:723.0/900s
2018-12-27 10:54:39,219 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105439205715
2018-12-27 10:54:39,256 [salt.minion      :1432][INFO    ][19069] Starting a new job with PID 19069
2018-12-27 10:54:39,302 [salt.minion      :1711][INFO    ][19069] Returning information for job: 20181227105439205715
2018-12-27 10:54:42,706 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:718.0/900s
2018-12-27 10:54:47,771 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:713.0/900s
2018-12-27 10:54:49,429 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105449415235
2018-12-27 10:54:49,466 [salt.minion      :1432][INFO    ][19117] Starting a new job with PID 19117
2018-12-27 10:54:49,511 [salt.minion      :1711][INFO    ][19117] Returning information for job: 20181227105449415235
2018-12-27 10:54:52,839 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:708.0/900s
2018-12-27 10:54:57,922 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:703.0/900s
2018-12-27 10:54:59,462 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105459445763
2018-12-27 10:54:59,499 [salt.minion      :1432][INFO    ][19141] Starting a new job with PID 19141
2018-12-27 10:54:59,545 [salt.minion      :1711][INFO    ][19141] Returning information for job: 20181227105459445763
2018-12-27 10:55:02,982 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:697.0/900s
2018-12-27 10:55:08,027 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:692.0/900s
2018-12-27 10:55:09,507 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105509489926
2018-12-27 10:55:09,536 [salt.minion      :1432][INFO    ][19158] Starting a new job with PID 19158
2018-12-27 10:55:09,587 [salt.minion      :1711][INFO    ][19158] Returning information for job: 20181227105509489926
2018-12-27 10:55:13,079 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:687.0/900s
2018-12-27 10:55:18,149 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:682.0/900s
2018-12-27 10:55:19,571 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105519549464
2018-12-27 10:55:19,613 [salt.minion      :1432][INFO    ][19171] Starting a new job with PID 19171
2018-12-27 10:55:19,652 [salt.minion      :1711][INFO    ][19171] Returning information for job: 20181227105519549464
2018-12-27 10:55:23,230 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:677.0/900s
2018-12-27 10:55:28,298 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:672.0/900s
2018-12-27 10:55:29,627 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105529610189
2018-12-27 10:55:29,658 [salt.minion      :1432][INFO    ][19197] Starting a new job with PID 19197
2018-12-27 10:55:29,703 [salt.minion      :1711][INFO    ][19197] Returning information for job: 20181227105529610189
2018-12-27 10:55:33,363 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:667.0/900s
2018-12-27 10:55:38,428 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:662.0/900s
2018-12-27 10:55:39,720 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105539692549
2018-12-27 10:55:39,759 [salt.minion      :1432][INFO    ][19206] Starting a new job with PID 19206
2018-12-27 10:55:39,805 [salt.minion      :1711][INFO    ][19206] Returning information for job: 20181227105539692549
2018-12-27 10:55:43,499 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:657.0/900s
2018-12-27 10:55:48,561 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:652.0/900s
2018-12-27 10:55:49,780 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105549759074
2018-12-27 10:55:49,826 [salt.minion      :1432][INFO    ][19227] Starting a new job with PID 19227
2018-12-27 10:55:49,873 [salt.minion      :1711][INFO    ][19227] Returning information for job: 20181227105549759074
2018-12-27 10:55:53,624 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:647.0/900s
2018-12-27 10:55:58,671 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:642.0/900s
2018-12-27 10:55:59,900 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105559882149
2018-12-27 10:55:59,936 [salt.minion      :1432][INFO    ][19252] Starting a new job with PID 19252
2018-12-27 10:55:59,974 [salt.minion      :1711][INFO    ][19252] Returning information for job: 20181227105559882149
2018-12-27 10:56:03,725 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:637.0/900s
2018-12-27 10:56:08,786 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:632.0/900s
2018-12-27 10:56:10,038 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105610017717
2018-12-27 10:56:10,072 [salt.minion      :1432][INFO    ][19260] Starting a new job with PID 19260
2018-12-27 10:56:10,112 [salt.minion      :1711][INFO    ][19260] Returning information for job: 20181227105610017717
2018-12-27 10:56:13,849 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:627.0/900s
2018-12-27 10:56:18,902 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:622.0/900s
2018-12-27 10:56:20,167 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105620147550
2018-12-27 10:56:20,201 [salt.minion      :1432][INFO    ][19272] Starting a new job with PID 19272
2018-12-27 10:56:20,247 [salt.minion      :1711][INFO    ][19272] Returning information for job: 20181227105620147550
2018-12-27 10:56:23,963 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:617.0/900s
2018-12-27 10:56:29,030 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:611.0/900s
2018-12-27 10:56:30,327 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105630308182
2018-12-27 10:56:30,366 [salt.minion      :1432][INFO    ][19301] Starting a new job with PID 19301
2018-12-27 10:56:30,411 [salt.minion      :1711][INFO    ][19301] Returning information for job: 20181227105630308182
2018-12-27 10:56:34,106 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:606.0/900s
2018-12-27 10:56:39,173 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:601.0/900s
2018-12-27 10:56:40,479 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105640459738
2018-12-27 10:56:40,520 [salt.minion      :1432][INFO    ][19310] Starting a new job with PID 19310
2018-12-27 10:56:40,569 [salt.minion      :1711][INFO    ][19310] Returning information for job: 20181227105640459738
2018-12-27 10:56:44,227 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:596.0/900s
2018-12-27 10:56:49,284 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:591.0/900s
2018-12-27 10:56:50,606 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105650590074
2018-12-27 10:56:50,634 [salt.minion      :1432][INFO    ][19331] Starting a new job with PID 19331
2018-12-27 10:56:50,677 [salt.minion      :1711][INFO    ][19331] Returning information for job: 20181227105650590074
2018-12-27 10:56:54,327 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:586.0/900s
2018-12-27 10:56:59,389 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:581.0/900s
2018-12-27 10:57:00,729 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105700706144
2018-12-27 10:57:00,763 [salt.minion      :1432][INFO    ][19360] Starting a new job with PID 19360
2018-12-27 10:57:00,805 [salt.minion      :1711][INFO    ][19360] Returning information for job: 20181227105700706144
2018-12-27 10:57:04,448 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:576.0/900s
2018-12-27 10:57:09,508 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:571.0/900s
2018-12-27 10:57:10,902 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105710888183
2018-12-27 10:57:10,939 [salt.minion      :1432][INFO    ][19368] Starting a new job with PID 19368
2018-12-27 10:57:10,980 [salt.minion      :1711][INFO    ][19368] Returning information for job: 20181227105710888183
2018-12-27 10:57:14,565 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:566.0/900s
2018-12-27 10:57:19,620 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:561.0/900s
2018-12-27 10:57:21,080 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105721060238
2018-12-27 10:57:21,124 [salt.minion      :1432][INFO    ][19384] Starting a new job with PID 19384
2018-12-27 10:57:21,168 [salt.minion      :1711][INFO    ][19384] Returning information for job: 20181227105721060238
2018-12-27 10:57:24,683 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:556.0/900s
2018-12-27 10:57:29,751 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:551.0/900s
2018-12-27 10:57:31,274 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105731255356
2018-12-27 10:57:31,314 [salt.minion      :1432][INFO    ][19413] Starting a new job with PID 19413
2018-12-27 10:57:31,381 [salt.minion      :1711][INFO    ][19413] Returning information for job: 20181227105731255356
2018-12-27 10:57:34,806 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:546.0/900s
2018-12-27 10:57:39,858 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:541.0/900s
2018-12-27 10:57:41,475 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105741457061
2018-12-27 10:57:41,516 [salt.minion      :1432][INFO    ][19422] Starting a new job with PID 19422
2018-12-27 10:57:41,563 [salt.minion      :1711][INFO    ][19422] Returning information for job: 20181227105741457061
2018-12-27 10:57:44,909 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:536.0/900s
2018-12-27 10:57:49,963 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:531.0/900s
2018-12-27 10:57:51,510 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105751494863
2018-12-27 10:57:51,535 [salt.minion      :1432][INFO    ][19442] Starting a new job with PID 19442
2018-12-27 10:57:51,573 [salt.minion      :1711][INFO    ][19442] Returning information for job: 20181227105751494863
2018-12-27 10:57:55,003 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:525.0/900s
2018-12-27 10:58:00,047 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:520.0/900s
2018-12-27 10:58:01,587 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105801567803
2018-12-27 10:58:01,615 [salt.minion      :1432][INFO    ][19468] Starting a new job with PID 19468
2018-12-27 10:58:01,664 [salt.minion      :1711][INFO    ][19468] Returning information for job: 20181227105801567803
2018-12-27 10:58:05,114 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:515.0/900s
2018-12-27 10:58:10,179 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:510.0/900s
2018-12-27 10:58:11,706 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105811691493
2018-12-27 10:58:11,741 [salt.minion      :1432][INFO    ][19477] Starting a new job with PID 19477
2018-12-27 10:58:11,789 [salt.minion      :1711][INFO    ][19477] Returning information for job: 20181227105811691493
2018-12-27 10:58:15,245 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:505.0/900s
2018-12-27 10:58:20,324 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:500.0/900s
2018-12-27 10:58:21,936 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105821916157
2018-12-27 10:58:21,976 [salt.minion      :1432][INFO    ][19489] Starting a new job with PID 19489
2018-12-27 10:58:22,017 [salt.minion      :1711][INFO    ][19489] Returning information for job: 20181227105821916157
2018-12-27 10:58:25,384 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:495.0/900s
2018-12-27 10:58:30,444 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:490.0/900s
2018-12-27 10:58:32,148 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105832131939
2018-12-27 10:58:32,177 [salt.minion      :1432][INFO    ][19517] Starting a new job with PID 19517
2018-12-27 10:58:32,221 [salt.minion      :1711][INFO    ][19517] Returning information for job: 20181227105832131939
2018-12-27 10:58:35,506 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:485.0/900s
2018-12-27 10:58:40,568 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:480.0/900s
2018-12-27 10:58:42,169 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105842151068
2018-12-27 10:58:42,211 [salt.minion      :1432][INFO    ][19527] Starting a new job with PID 19527
2018-12-27 10:58:42,257 [salt.minion      :1711][INFO    ][19527] Returning information for job: 20181227105842151068
2018-12-27 10:58:45,623 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:475.0/900s
2018-12-27 10:58:50,692 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:470.0/900s
2018-12-27 10:58:52,208 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105852185653
2018-12-27 10:58:52,244 [salt.minion      :1432][INFO    ][19546] Starting a new job with PID 19546
2018-12-27 10:58:52,297 [salt.minion      :1711][INFO    ][19546] Returning information for job: 20181227105852185653
2018-12-27 10:58:55,735 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:465.0/900s
2018-12-27 10:59:00,796 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:460.0/900s
2018-12-27 10:59:02,425 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105902407536
2018-12-27 10:59:02,457 [salt.minion      :1432][INFO    ][19571] Starting a new job with PID 19571
2018-12-27 10:59:02,509 [salt.minion      :1711][INFO    ][19571] Returning information for job: 20181227105902407536
2018-12-27 10:59:05,840 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:455.0/900s
2018-12-27 10:59:10,895 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:450.0/900s
2018-12-27 10:59:12,645 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105912625182
2018-12-27 10:59:12,679 [salt.minion      :1432][INFO    ][19597] Starting a new job with PID 19597
2018-12-27 10:59:12,722 [salt.minion      :1711][INFO    ][19597] Returning information for job: 20181227105912625182
2018-12-27 10:59:15,953 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:445.0/900s
2018-12-27 10:59:20,999 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:439.0/900s
2018-12-27 10:59:22,663 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105922646140
2018-12-27 10:59:22,698 [salt.minion      :1432][INFO    ][19610] Starting a new job with PID 19610
2018-12-27 10:59:22,752 [salt.minion      :1711][INFO    ][19610] Returning information for job: 20181227105922646140
2018-12-27 10:59:26,043 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:434.0/900s
2018-12-27 10:59:31,103 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:429.0/900s
2018-12-27 10:59:32,707 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105932689799
2018-12-27 10:59:32,743 [salt.minion      :1432][INFO    ][19636] Starting a new job with PID 19636
2018-12-27 10:59:32,793 [salt.minion      :1711][INFO    ][19636] Returning information for job: 20181227105932689799
2018-12-27 10:59:36,172 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:424.0/900s
2018-12-27 10:59:41,239 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:419.0/900s
2018-12-27 10:59:42,774 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105942756154
2018-12-27 10:59:42,822 [salt.minion      :1432][INFO    ][19645] Starting a new job with PID 19645
2018-12-27 10:59:42,858 [salt.minion      :1711][INFO    ][19645] Returning information for job: 20181227105942756154
2018-12-27 10:59:46,313 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:414.0/900s
2018-12-27 10:59:51,365 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:409.0/900s
2018-12-27 10:59:52,845 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227105952828088
2018-12-27 10:59:52,891 [salt.minion      :1432][INFO    ][19672] Starting a new job with PID 19672
2018-12-27 10:59:52,938 [salt.minion      :1711][INFO    ][19672] Returning information for job: 20181227105952828088
2018-12-27 10:59:56,416 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:404.0/900s
2018-12-27 11:00:01,481 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:399.0/900s
2018-12-27 11:00:02,958 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110002933605
2018-12-27 11:00:02,996 [salt.minion      :1432][INFO    ][19702] Starting a new job with PID 19702
2018-12-27 11:00:03,038 [salt.minion      :1711][INFO    ][19702] Returning information for job: 20181227110002933605
2018-12-27 11:00:06,527 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:394.0/900s
2018-12-27 11:00:11,587 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:389.0/900s
2018-12-27 11:00:12,979 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110012961998
2018-12-27 11:00:13,015 [salt.minion      :1432][INFO    ][19734] Starting a new job with PID 19734
2018-12-27 11:00:13,059 [salt.minion      :1711][INFO    ][19734] Returning information for job: 20181227110012961998
2018-12-27 11:00:16,643 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:384.0/900s
2018-12-27 11:00:21,698 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:379.0/900s
2018-12-27 11:00:23,194 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110023169565
2018-12-27 11:00:23,230 [salt.minion      :1432][INFO    ][19747] Starting a new job with PID 19747
2018-12-27 11:00:23,272 [salt.minion      :1711][INFO    ][19747] Returning information for job: 20181227110023169565
2018-12-27 11:00:26,756 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:374.0/900s
2018-12-27 11:00:31,811 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:369.0/900s
2018-12-27 11:00:33,344 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110033322263
2018-12-27 11:00:33,391 [salt.minion      :1432][INFO    ][19770] Starting a new job with PID 19770
2018-12-27 11:00:33,453 [salt.minion      :1711][INFO    ][19770] Returning information for job: 20181227110033322263
2018-12-27 11:00:36,870 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:364.0/900s
2018-12-27 11:00:41,938 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:359.0/900s
2018-12-27 11:00:43,530 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110043508438
2018-12-27 11:00:43,569 [salt.minion      :1432][INFO    ][19778] Starting a new job with PID 19778
2018-12-27 11:00:43,605 [salt.minion      :1711][INFO    ][19778] Returning information for job: 20181227110043508438
2018-12-27 11:00:47,014 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:353.0/900s
2018-12-27 11:00:52,082 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:348.0/900s
2018-12-27 11:00:53,693 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110053668611
2018-12-27 11:00:53,731 [salt.minion      :1432][INFO    ][19797] Starting a new job with PID 19797
2018-12-27 11:00:53,767 [salt.minion      :1711][INFO    ][19797] Returning information for job: 20181227110053668611
2018-12-27 11:00:57,136 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:343.0/900s
2018-12-27 11:01:02,188 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:338.0/900s
2018-12-27 11:01:03,834 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110103808824
2018-12-27 11:01:03,872 [salt.minion      :1432][INFO    ][19821] Starting a new job with PID 19821
2018-12-27 11:01:03,915 [salt.minion      :1711][INFO    ][19821] Returning information for job: 20181227110103808824
2018-12-27 11:01:07,253 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:333.0/900s
2018-12-27 11:01:12,293 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:328.0/900s
2018-12-27 11:01:14,007 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110113986705
2018-12-27 11:01:14,039 [salt.minion      :1432][INFO    ][19832] Starting a new job with PID 19832
2018-12-27 11:01:14,094 [salt.minion      :1711][INFO    ][19832] Returning information for job: 20181227110113986705
2018-12-27 11:01:17,338 [salt.loaded.ext.module.maasng:1600][INFO    ][10783] Waiting boot-resources import done
sleep for:5s Left:323.0/900s
2018-12-27 11:01:22,416 [salt.state       :300 ][INFO    ][10783] boot-source selection for http://images.maas.io/ephemeral-v3/daily was created
2018-12-27 11:01:22,417 [salt.state       :1951][INFO    ][10783] Completed state [maas_region_boot_sources_selection_xenial] at time 11:01:22.416926 duration_in_ms=587214.671
2018-12-27 11:01:22,418 [salt.state       :1780][INFO    ][10783] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 11:01:22.418242
2018-12-27 11:01:22,418 [salt.state       :1813][INFO    ][10783] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2018-12-27 11:01:22,419 [salt.utils.decorators:613 ][WARNING ][10783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:01:22,419 [salt.loaded.ext.module.maasng:1771][INFO    ][10783] boot-sources sync initiated for ALL Rack's
2018-12-27 11:01:22,891 [salt.loaded.ext.module.maasng:1878][INFO    ][10783] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2018-12-27 11:01:24,053 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110124032671
2018-12-27 11:01:24,091 [salt.minion      :1432][INFO    ][19863] Starting a new job with PID 19863
2018-12-27 11:01:24,138 [salt.minion      :1711][INFO    ][19863] Returning information for job: 20181227110124032671
2018-12-27 11:01:28,146 [salt.loaded.ext.module.maasng:1878][INFO    ][10783] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:895.0/900s
2018-12-27 11:01:33,437 [salt.loaded.ext.module.maasng:1878][INFO    ][10783] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2018-12-27 11:01:34,275 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110134256326
2018-12-27 11:01:34,330 [salt.minion      :1432][INFO    ][19892] Starting a new job with PID 19892
2018-12-27 11:01:34,372 [salt.minion      :1711][INFO    ][19892] Returning information for job: 20181227110134256326
2018-12-27 11:01:38,836 [salt.loaded.ext.module.maasng:1878][INFO    ][10783] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:884.0/900s
2018-12-27 11:01:44,326 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110144307509
2018-12-27 11:01:44,373 [salt.minion      :1432][INFO    ][20033] Starting a new job with PID 20033
2018-12-27 11:01:44,429 [salt.minion      :1711][INFO    ][20033] Returning information for job: 20181227110144307509
2018-12-27 11:01:44,761 [salt.state       :300 ][INFO    ][10783] {'ret': True}
2018-12-27 11:01:44,761 [salt.state       :1951][INFO    ][10783] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 11:01:44.761899 duration_in_ms=22343.656
2018-12-27 11:01:44,764 [salt.state       :1780][INFO    ][10783] Running state [maas.process_maas_config] at time 11:01:44.764039
2018-12-27 11:01:44,764 [salt.state       :1813][INFO    ][10783] Executing state module.run for [maas.process_maas_config]
2018-12-27 11:01:44,765 [salt.utils.decorators:613 ][WARNING ][10783] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:01:44,765 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=enable_http_proxy value=True
2018-12-27 11:01:44,812 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=upstream_dns value=8.8.8.8
2018-12-27 11:01:44,862 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=commissioning_distro_series value=xenial
2018-12-27 11:01:44,929 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=default_osystem value=ubuntu
2018-12-27 11:01:47,142 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=active_discovery_interval value=600
2018-12-27 11:01:47,193 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=dnssec_validation value=no
2018-12-27 11:01:47,241 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=maas_name value=mas01
2018-12-27 11:01:47,284 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=network_discovery value=enabled
2018-12-27 11:01:47,390 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=enable_third_party_drivers value=True
2018-12-27 11:01:47,433 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=default_storage_layout value=lvm
2018-12-27 11:01:47,482 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=ntp_external_only value=True
2018-12-27 11:01:47,526 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=disk_erase_with_secure_erase value=False
2018-12-27 11:01:47,562 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=default_distro_series value=xenial
2018-12-27 11:01:47,607 [salt.loaded.ext.module.maas:92  ][INFO    ][10783] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2018-12-27 11:01:47,710 [salt.state       :300 ][INFO    ][10783] {'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-27 11:01:47,711 [salt.state       :1951][INFO    ][10783] Completed state [maas.process_maas_config] at time 11:01:47.711050 duration_in_ms=2947.01
2018-12-27 11:01:47,712 [salt.state       :1780][INFO    ][10783] Running state [pxe_admin] at time 11:01:47.712258
2018-12-27 11:01:47,712 [salt.state       :1813][INFO    ][10783] Executing state maasng.fabric_present for [pxe_admin]
2018-12-27 11:01:47,768 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'primary_rack': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}]
2018-12-27 11:01:47,811 [salt.loaded.ext.module.maasng:1008][WARNING ][10783] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2018-12-27 11:01:47,812 [salt.loaded.ext.module.maasng:1011][WARNING ][10783] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2018-12-27 11:01:47,876 [salt.state       :300 ][INFO    ][10783] {'new': 'Fabric  pxe_admin created', 'result': True}
2018-12-27 11:01:47,876 [salt.state       :1951][INFO    ][10783] Completed state [pxe_admin] at time 11:01:47.876549 duration_in_ms=164.29
2018-12-27 11:01:47,877 [salt.state       :1780][INFO    ][10783] Running state [vlan 0] at time 11:01:47.877629
2018-12-27 11:01:47,878 [salt.state       :1813][INFO    ][10783] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2018-12-27 11:01:47,938 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-27 11:01:48,029 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': 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'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2018-12-27 11:01:48,423 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': u'10.20.0.1', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2018-12-27 11:01:48,483 [salt.state       :300 ][INFO    ][10783] {'new': 'Vlan untagged was updated'}
2018-12-27 11:01:48,484 [salt.state       :1951][INFO    ][10783] Completed state [vlan 0] at time 11:01:48.483988 duration_in_ms=606.359
2018-12-27 11:01:48,485 [salt.state       :1780][INFO    ][10783] Running state [192.168.11.0/24] at time 11:01:48.484966
2018-12-27 11:01:48,485 [salt.state       :1813][INFO    ][10783] Executing state maasng.subnet_present for [192.168.11.0/24]
2018-12-27 11:01:48,631 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'name': u'fabric-0', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': u'10.20.0.1', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2018-12-27 11:01:48,631 [salt.loaded.ext.module.maasng:1235][WARNING ][10783] Ignoring parameter vlan:0
2018-12-27 11:01:48,703 [salt.state       :300 ][INFO    ][10783] Subnet 192.168.11.0/24 has been updated for pxe_admin
2018-12-27 11:01:48,704 [salt.state       :1951][INFO    ][10783] Completed state [192.168.11.0/24] at time 11:01:48.704220 duration_in_ms=219.254
2018-12-27 11:01:48,705 [salt.state       :1780][INFO    ][10783] Running state [maas_create_iprange_1] at time 11:01:48.705090
2018-12-27 11:01:48,705 [salt.state       :1813][INFO    ][10783] Executing state maasng.iprange_present for [maas_create_iprange_1]
2018-12-27 11:01:48,852 [salt.state       :300 ][INFO    ][10783] {'new': 'Iprange: Type:dynamic: 192.168.11.38-192.168.11.254 has been created'}
2018-12-27 11:01:48,852 [salt.state       :1951][INFO    ][10783] Completed state [maas_create_iprange_1] at time 11:01:48.852717 duration_in_ms=147.626
2018-12-27 11:01:48,853 [salt.state       :1780][INFO    ][10783] Running state [vlan 0] at time 11:01:48.853110
2018-12-27 11:01:48,853 [salt.state       :1813][INFO    ][10783] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2018-12-27 11:01:48,896 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': u'10.20.0.1', u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'mhs3yd', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2018-12-27 11:01:48,970 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': 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'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2018-12-27 11:01:49,271 [salt.loaded.ext.module.maasng:945 ][INFO    ][10783] [{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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {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'mhs3yd', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2018-12-27 11:01:49,374 [salt.state       :300 ][INFO    ][10783] {'new': 'Vlan untagged was updated'}
2018-12-27 11:01:49,374 [salt.state       :1951][INFO    ][10783] Completed state [vlan 0] at time 11:01:49.374651 duration_in_ms=521.54
2018-12-27 11:01:49,375 [salt.state       :1780][INFO    ][10783] Running state [opnfv] at time 11:01:49.375397
2018-12-27 11:01:49,375 [salt.state       :1813][INFO    ][10783] Executing state maasng.sshkey_present for [opnfv]
2018-12-27 11:01:49,412 [salt.loaded.ext.module.maasng:1903][INFO    ][10783] []
2018-12-27 11:01:49,508 [salt.state       :300 ][INFO    ][10783] {'new': 'SSH Key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCwbsLV1UY13y2+2b7H9h6zOFMrcnumZvKOz6oqAXgttZjoKci01cqGRU8OMjob/9xeAOP2Cmu7HOBpRxda00X57yYx4UidSgEtlbOi7LLj2DuvJScix+rgPAd19aukdCiTuMmyLZQPMzVrdBxqzupJ5zqS3djSCllnQ2myEwswcSBn0Dpusgt3bnwdsCgI6B6ZgL9aR9DLnyMPMVroI6ZZH7aP7syIy1sPEsiJd3smWEULgeRElsuK+4I3YKG1Z1J2n80lmtR2gVD5tuKLFRRxnbjAqzyCEXQBTUVRc13SAFrH0b5bzFaqfxY1wdQPzP+dBSA+t25KcjnpTAAtL86H was added.'}
2018-12-27 11:01:49,508 [salt.state       :1951][INFO    ][10783] Completed state [opnfv] at time 11:01:49.508446 duration_in_ms=133.049
2018-12-27 11:01:49,512 [salt.minion      :1711][INFO    ][10783] Returning information for job: 20181227104624204317
2018-12-27 11:01:50,202 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227110150184497
2018-12-27 11:01:50,240 [salt.minion      :1432][INFO    ][20136] Starting a new job with PID 20136
2018-12-27 11:01:55,929 [salt.state       :915 ][INFO    ][20136] Loading fresh modules for state activity
2018-12-27 11:01:56,006 [salt.fileclient  :1219][INFO    ][20136] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2018-12-27 11:01:56,058 [salt.state       :1780][INFO    ][20136] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:01:56.058834
2018-12-27 11:01:56,059 [salt.state       :1813][INFO    ][20136] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 11:01:56,061 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20136] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 11:01:57,949 [salt.state       :300 ][INFO    ][20136] {'pid': 20192, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 11:01:57,950 [salt.state       :1951][INFO    ][20136] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:01:57.950403 duration_in_ms=1891.569
2018-12-27 11:01:57,953 [salt.state       :1780][INFO    ][20136] Running state [maas.process_machines] at time 11:01:57.952999
2018-12-27 11:01:57,953 [salt.state       :1813][INFO    ][20136] Executing state module.run for [maas.process_machines]
2018-12-27 11:01:57,953 [salt.utils.decorators:613 ][WARNING ][20136] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:01:58,014 [salt.loaded.ext.module.maas:412 ][WARNING ][20136] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-27 11:01:58,015 [salt.loaded.ext.module.maas:92  ][INFO    ][20136] 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-27 11:01:59,356 [salt.loaded.ext.module.maas:412 ][WARNING ][20136] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-27 11:01:59,356 [salt.loaded.ext.module.maas:92  ][INFO    ][20136] 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-27 11:02:00,230 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110200212822
2018-12-27 11:02:00,261 [salt.minion      :1432][INFO    ][20300] Starting a new job with PID 20300
2018-12-27 11:02:00,299 [salt.minion      :1711][INFO    ][20300] Returning information for job: 20181227110200212822
2018-12-27 11:02:00,646 [salt.loaded.ext.module.maas:412 ][WARNING ][20136] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-27 11:02:00,646 [salt.loaded.ext.module.maas:92  ][INFO    ][20136] 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-27 11:02:01,885 [salt.loaded.ext.module.maas:412 ][WARNING ][20136] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-27 11:02:01,885 [salt.loaded.ext.module.maas:92  ][INFO    ][20136] 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-27 11:02:03,136 [salt.loaded.ext.module.maas:412 ][WARNING ][20136] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2018-12-27 11:02:03,137 [salt.loaded.ext.module.maas:92  ][INFO    ][20136] 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-27 11:02:04,368 [salt.state       :300 ][INFO    ][20136] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2018-12-27 11:02:04,369 [salt.state       :1951][INFO    ][20136] Completed state [maas.process_machines] at time 11:02:04.369061 duration_in_ms=6416.062
2018-12-27 11:02:04,371 [salt.minion      :1711][INFO    ][20136] Returning information for job: 20181227110150184497
2018-12-27 11:02:45,662 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227110245640067
2018-12-27 11:02:45,684 [salt.minion      :1432][INFO    ][20516] Starting a new job with PID 20516
2018-12-27 11:02:51,302 [salt.state       :915 ][INFO    ][20516] Loading fresh modules for state activity
2018-12-27 11:02:51,355 [salt.fileclient  :1219][INFO    ][20516] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2018-12-27 11:02:51,410 [salt.state       :1780][INFO    ][20516] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:02:51.410338
2018-12-27 11:02:51,410 [salt.state       :1813][INFO    ][20516] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 11:02:51,412 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20516] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 11:02:53,253 [salt.state       :300 ][INFO    ][20516] {'pid': 20533, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 11:02:53,254 [salt.state       :1951][INFO    ][20516] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:02:53.253914 duration_in_ms=1843.577
2018-12-27 11:02:53,262 [salt.state       :1780][INFO    ][20516] Running state [maas.wait_for_machine_status] at time 11:02:53.262185
2018-12-27 11:02:53,262 [salt.state       :1813][INFO    ][20516] Executing state module.run for [maas.wait_for_machine_status]
2018-12-27 11:02:53,263 [salt.utils.decorators:613 ][WARNING ][20516] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:02:54,170 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.10196018s left)
2018-12-27 11:02:55,720 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110255702740
2018-12-27 11:02:55,742 [salt.minion      :1432][INFO    ][20550] Starting a new job with PID 20550
2018-12-27 11:02:55,766 [salt.minion      :1711][INFO    ][20550] Returning information for job: 20181227110255702740
2018-12-27 11:03:05,937 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110305908445
2018-12-27 11:03:05,964 [salt.minion      :1432][INFO    ][20563] Starting a new job with PID 20563
2018-12-27 11:03:05,988 [salt.minion      :1711][INFO    ][20563] Returning information for job: 20181227110305908445
2018-12-27 11:03:16,155 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110316130823
2018-12-27 11:03:16,180 [salt.minion      :1432][INFO    ][20568] Starting a new job with PID 20568
2018-12-27 11:03:16,204 [salt.minion      :1711][INFO    ][20568] Returning information for job: 20181227110316130823
2018-12-27 11:03:24,909 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.36280417s left)
2018-12-27 11:03:26,352 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110326335385
2018-12-27 11:03:26,368 [salt.minion      :1432][INFO    ][20598] Starting a new job with PID 20598
2018-12-27 11:03:26,388 [salt.minion      :1711][INFO    ][20598] Returning information for job: 20181227110326335385
2018-12-27 11:03:36,589 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110336528069
2018-12-27 11:03:36,609 [salt.minion      :1432][INFO    ][20606] Starting a new job with PID 20606
2018-12-27 11:03:36,631 [salt.minion      :1711][INFO    ][20606] Returning information for job: 20181227110336528069
2018-12-27 11:03:46,586 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110346565317
2018-12-27 11:03:46,608 [salt.minion      :1432][INFO    ][20612] Starting a new job with PID 20612
2018-12-27 11:03:46,631 [salt.minion      :1711][INFO    ][20612] Returning information for job: 20181227110346565317
2018-12-27 11:03:55,776 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.49594617s left)
2018-12-27 11:03:56,607 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110356584864
2018-12-27 11:03:56,633 [salt.minion      :1432][INFO    ][20643] Starting a new job with PID 20643
2018-12-27 11:03:56,656 [salt.minion      :1711][INFO    ][20643] Returning information for job: 20181227110356584864
2018-12-27 11:04:06,826 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110406802833
2018-12-27 11:04:06,853 [salt.minion      :1432][INFO    ][20654] Starting a new job with PID 20654
2018-12-27 11:04:06,875 [salt.minion      :1711][INFO    ][20654] Returning information for job: 20181227110406802833
2018-12-27 11:04:17,049 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110417025850
2018-12-27 11:04:17,071 [salt.minion      :1432][INFO    ][20659] Starting a new job with PID 20659
2018-12-27 11:04:17,091 [salt.minion      :1711][INFO    ][20659] Returning information for job: 20181227110417025850
2018-12-27 11:04:26,858 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.41392016s left)
2018-12-27 11:04:27,226 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110427209132
2018-12-27 11:04:27,244 [salt.minion      :1432][INFO    ][20712] Starting a new job with PID 20712
2018-12-27 11:04:27,265 [salt.minion      :1711][INFO    ][20712] Returning information for job: 20181227110427209132
2018-12-27 11:04:37,423 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110437398740
2018-12-27 11:04:37,449 [salt.minion      :1432][INFO    ][20719] Starting a new job with PID 20719
2018-12-27 11:04:37,479 [salt.minion      :1711][INFO    ][20719] Returning information for job: 20181227110437398740
2018-12-27 11:04:47,433 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110447418726
2018-12-27 11:04:47,452 [salt.minion      :1432][INFO    ][20748] Starting a new job with PID 20748
2018-12-27 11:04:47,475 [salt.minion      :1711][INFO    ][20748] Returning information for job: 20181227110447418726
2018-12-27 11:04:57,616 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110457600111
2018-12-27 11:04:57,633 [salt.minion      :1432][INFO    ][20843] Starting a new job with PID 20843
2018-12-27 11:04:57,654 [salt.minion      :1711][INFO    ][20843] Returning information for job: 20181227110457600111
2018-12-27 11:04:57,915 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.35728812s left)
2018-12-27 11:05:07,835 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110507811521
2018-12-27 11:05:07,863 [salt.minion      :1432][INFO    ][20872] Starting a new job with PID 20872
2018-12-27 11:05:07,889 [salt.minion      :1711][INFO    ][20872] Returning information for job: 20181227110507811521
2018-12-27 11:05:17,868 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110517840903
2018-12-27 11:05:17,893 [salt.minion      :1432][INFO    ][20880] Starting a new job with PID 20880
2018-12-27 11:05:17,919 [salt.minion      :1711][INFO    ][20880] Returning information for job: 20181227110517840903
2018-12-27 11:05:28,082 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110528064831
2018-12-27 11:05:28,101 [salt.minion      :1432][INFO    ][20950] Starting a new job with PID 20950
2018-12-27 11:05:28,129 [salt.minion      :1711][INFO    ][20950] Returning information for job: 20181227110528064831
2018-12-27 11:05:29,156 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.11599398s left)
2018-12-27 11:05:38,287 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110538272703
2018-12-27 11:05:38,304 [salt.minion      :1432][INFO    ][20961] Starting a new job with PID 20961
2018-12-27 11:05:38,337 [salt.minion      :1711][INFO    ][20961] Returning information for job: 20181227110538272703
2018-12-27 11:05:48,309 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110548289120
2018-12-27 11:05:48,330 [salt.minion      :1432][INFO    ][21002] Starting a new job with PID 21002
2018-12-27 11:05:48,356 [salt.minion      :1711][INFO    ][21002] Returning information for job: 20181227110548289120
2018-12-27 11:05:58,353 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110558327980
2018-12-27 11:05:58,372 [salt.minion      :1432][INFO    ][21140] Starting a new job with PID 21140
2018-12-27 11:05:58,399 [salt.minion      :1711][INFO    ][21140] Returning information for job: 20181227110558327980
2018-12-27 11:06:00,375 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1312.89649916s left)
2018-12-27 11:06:08,553 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110608536011
2018-12-27 11:06:08,573 [salt.minion      :1432][INFO    ][21208] Starting a new job with PID 21208
2018-12-27 11:06:08,597 [salt.minion      :1711][INFO    ][21208] Returning information for job: 20181227110608536011
2018-12-27 11:06:18,743 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110618727367
2018-12-27 11:06:18,761 [salt.minion      :1432][INFO    ][21243] Starting a new job with PID 21243
2018-12-27 11:06:18,787 [salt.minion      :1711][INFO    ][21243] Returning information for job: 20181227110618727367
2018-12-27 11:06:28,765 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110628739770
2018-12-27 11:06:28,785 [salt.minion      :1432][INFO    ][21314] Starting a new job with PID 21314
2018-12-27 11:06:28,812 [salt.minion      :1711][INFO    ][21314] Returning information for job: 20181227110628739770
2018-12-27 11:06:31,883 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1281.38892698s left)
2018-12-27 11:06:38,798 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110638768965
2018-12-27 11:06:38,819 [salt.minion      :1432][INFO    ][21345] Starting a new job with PID 21345
2018-12-27 11:06:38,847 [salt.minion      :1711][INFO    ][21345] Returning information for job: 20181227110638768965
2018-12-27 11:06:48,811 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110648794181
2018-12-27 11:06:48,833 [salt.minion      :1432][INFO    ][21393] Starting a new job with PID 21393
2018-12-27 11:06:48,855 [salt.minion      :1711][INFO    ][21393] Returning information for job: 20181227110648794181
2018-12-27 11:06:59,021 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110658997769
2018-12-27 11:06:59,048 [salt.minion      :1432][INFO    ][21625] Starting a new job with PID 21625
2018-12-27 11:06:59,071 [salt.minion      :1711][INFO    ][21625] Returning information for job: 20181227110658997769
2018-12-27 11:07:03,742 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1249.52947903s left)
2018-12-27 11:07:09,043 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110709026808
2018-12-27 11:07:09,062 [salt.minion      :1432][INFO    ][21662] Starting a new job with PID 21662
2018-12-27 11:07:09,086 [salt.minion      :1711][INFO    ][21662] Returning information for job: 20181227110709026808
2018-12-27 11:07:19,059 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110719039411
2018-12-27 11:07:19,082 [salt.minion      :1432][INFO    ][21688] Starting a new job with PID 21688
2018-12-27 11:07:19,113 [salt.minion      :1711][INFO    ][21688] Returning information for job: 20181227110719039411
2018-12-27 11:07:29,079 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110729062749
2018-12-27 11:07:29,096 [salt.minion      :1432][INFO    ][21864] Starting a new job with PID 21864
2018-12-27 11:07:29,116 [salt.minion      :1711][INFO    ][21864] Returning information for job: 20181227110729062749
2018-12-27 11:07:36,128 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1217.14407921s left)
2018-12-27 11:07:39,301 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110739274403
2018-12-27 11:07:39,324 [salt.minion      :1432][INFO    ][21925] Starting a new job with PID 21925
2018-12-27 11:07:39,349 [salt.minion      :1711][INFO    ][21925] Returning information for job: 20181227110739274403
2018-12-27 11:07:49,326 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110749309598
2018-12-27 11:07:49,347 [salt.minion      :1432][INFO    ][21976] Starting a new job with PID 21976
2018-12-27 11:07:49,367 [salt.minion      :1711][INFO    ][21976] Returning information for job: 20181227110749309598
2018-12-27 11:07:59,358 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110759341110
2018-12-27 11:07:59,382 [salt.minion      :1432][INFO    ][22154] Starting a new job with PID 22154
2018-12-27 11:07:59,411 [salt.minion      :1711][INFO    ][22154] Returning information for job: 20181227110759341110
2018-12-27 11:08:08,615 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1184.65776014s left)
2018-12-27 11:08:09,368 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110809352903
2018-12-27 11:08:09,389 [salt.minion      :1432][INFO    ][22195] Starting a new job with PID 22195
2018-12-27 11:08:09,415 [salt.minion      :1711][INFO    ][22195] Returning information for job: 20181227110809352903
2018-12-27 11:08:19,443 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110819417350
2018-12-27 11:08:19,467 [salt.minion      :1432][INFO    ][22215] Starting a new job with PID 22215
2018-12-27 11:08:19,495 [salt.minion      :1711][INFO    ][22215] Returning information for job: 20181227110819417350
2018-12-27 11:08:29,526 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110829503926
2018-12-27 11:08:29,549 [salt.minion      :1432][INFO    ][22266] Starting a new job with PID 22266
2018-12-27 11:08:29,573 [salt.minion      :1711][INFO    ][22266] Returning information for job: 20181227110829503926
2018-12-27 11:08:39,586 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110839569562
2018-12-27 11:08:39,606 [salt.minion      :1432][INFO    ][22345] Starting a new job with PID 22345
2018-12-27 11:08:39,630 [salt.minion      :1711][INFO    ][22345] Returning information for job: 20181227110839569562
2018-12-27 11:08:41,182 [salt.loaded.ext.module.maas:1001][INFO    ][20516] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1152.08978105s left)
2018-12-27 11:08:49,808 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110849788809
2018-12-27 11:08:49,836 [salt.minion      :1432][INFO    ][22445] Starting a new job with PID 22445
2018-12-27 11:08:49,860 [salt.minion      :1711][INFO    ][22445] Returning information for job: 20181227110849788809
2018-12-27 11:08:59,865 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110859840963
2018-12-27 11:08:59,889 [salt.minion      :1432][INFO    ][22470] Starting a new job with PID 22470
2018-12-27 11:08:59,917 [salt.minion      :1711][INFO    ][22470] Returning information for job: 20181227110859840963
2018-12-27 11:09:09,952 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110909931340
2018-12-27 11:09:09,977 [salt.minion      :1432][INFO    ][22559] Starting a new job with PID 22559
2018-12-27 11:09:10,012 [salt.minion      :1711][INFO    ][22559] Returning information for job: 20181227110909931340
2018-12-27 11:09:14,445 [salt.state       :300 ][INFO    ][20516] {'ret': True}
2018-12-27 11:09:14,445 [salt.state       :1951][INFO    ][20516] Completed state [maas.wait_for_machine_status] at time 11:09:14.445767 duration_in_ms=381183.582
2018-12-27 11:09:14,450 [salt.minion      :1711][INFO    ][20516] Returning information for job: 20181227110245640067
2018-12-27 11:09:15,002 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227110914977516
2018-12-27 11:09:15,026 [salt.minion      :1432][INFO    ][22575] Starting a new job with PID 22575
2018-12-27 11:09:20,607 [salt.state       :915 ][INFO    ][22575] Loading fresh modules for state activity
2018-12-27 11:09:20,665 [salt.fileclient  :1219][INFO    ][22575] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2018-12-27 11:09:20,768 [salt.state       :1780][INFO    ][22575] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:20.768312
2018-12-27 11:09:20,768 [salt.state       :1813][INFO    ][22575] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 11:09:20,770 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22575] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 11:09:22,701 [salt.state       :300 ][INFO    ][22575] {'pid': 22587, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 11:09:22,703 [salt.state       :1951][INFO    ][22575] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:22.703443 duration_in_ms=1935.131
2018-12-27 11:09:22,707 [salt.state       :1780][INFO    ][22575] Running state [maas_machines_storage_cmp002_lvm] at time 11:09:22.707765
2018-12-27 11:09:22,708 [salt.state       :1813][INFO    ][22575] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2018-12-27 11:09:23,963 [salt.loaded.ext.module.maasng:610 ][INFO    ][22575] 7ys8pe
2018-12-27 11:09:23,963 [salt.loaded.ext.module.maasng:626 ][INFO    ][22575] sda
2018-12-27 11:09:24,607 [salt.loaded.ext.module.maasng:361 ][INFO    ][22575] 7ys8pe
2018-12-27 11:09:24,721 [salt.loaded.ext.module.maasng:367 ][INFO    ][22575] [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/', u'used_size': 800106479616, u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'7ys8pe', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'partitions': [{u'uuid': u'4650e246-2149-406e-b801-5c8b569bd609', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7ys8pe', u'device_id': 2, u'filesystem': {u'uuid': u'832fb3ce-a5a7-4c7c-8e36-fb9a6b7245b8', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/partition/1', u'type': u'partition', u'id': 1, u'size': 800101236736}], u'type': u'physical', u'id': 2, u'tags': [u'ssd'], u'size': 800109715456}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/4/', u'used_size': 800097042432, u'filesystem': {u'uuid': u'f8cee690-e3c6-4f42-8c94-07eafab4e1bb', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'uuid': u'd4a60957-488f-4e62-a289-eb99ba61d183', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'7ys8pe', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 4, u'tags': [], u'size': 800097042432}]
2018-12-27 11:09:24,721 [salt.loaded.ext.module.maasng:632 ][INFO    ][22575] vgroot
2018-12-27 11:09:24,721 [salt.loaded.ext.module.maasng:635 ][INFO    ][22575] lvroot
2018-12-27 11:09:24,721 [salt.loaded.ext.module.maasng:639 ][INFO    ][22575] 107374182400
2018-12-27 11:09:25,030 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110925013183
2018-12-27 11:09:25,050 [salt.minion      :1432][INFO    ][22599] Starting a new job with PID 22599
2018-12-27 11:09:25,069 [salt.minion      :1711][INFO    ][22599] Returning information for job: 20181227110925013183
2018-12-27 11:09:25,462 [salt.loaded.ext.module.maasng:645 ][INFO    ][22575] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', 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'boot_interface': {u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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': 20}], 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'primary_rack': u'mhs3yd', 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'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/5/'}, u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 800109715456, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'c75e2388-6aa9-411a-8e82-d941889676dc', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7ys8pe', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'58c86fc9-cf89-4c83-8c04-71423ff2c452', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'7ys8pe', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/'}, u'blockdevice_set': [{u'size': 800109715456, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'c75e2388-6aa9-411a-8e82-d941889676dc', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7ys8pe', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'58c86fc9-cf89-4c83-8c04-71423ff2c452', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'7ys8pe', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/'}, {u'size': 107374182400, u'uuid': u'f487e288-18c4-47d1-b5ac-851cd69d71b7', u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'baa73ffe-1c47-4beb-bba1-c0bb8d6c1517', u'fstype': u'ext4'}, u'id': 12, u'system_id': u'7ys8pe', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/12/'}], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/7ys8pe/', 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'7ys8pe', u'power_state': u'off', u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'uuid': u'f487e288-18c4-47d1-b5ac-851cd69d71b7', u'name': u'vgroot-lvroot', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'baa73ffe-1c47-4beb-bba1-c0bb8d6c1517', u'fstype': u'ext4'}, u'id': 12, u'system_id': u'7ys8pe', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/12/'}], u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'cpu_count': 40, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'7ys8pe', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'memory_test_status_name': u'Unknown', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 800109715456, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'c75e2388-6aa9-411a-8e82-d941889676dc', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'7ys8pe', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'58c86fc9-cf89-4c83-8c04-71423ff2c452', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 6, u'size': 800101236736}], u'filesystem': None, u'id': 2, u'system_id': u'7ys8pe', u'partition_table_type': u'MBR', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/blockdevices/2/'}], u'netboot': True, u'osystem': u'', u'status_action': u'', u'disable_ipv4': False, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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': 20}], 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'primary_rack': u'mhs3yd', 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'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'9c:b6:54:8a:10:18', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/5/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'38:ea:a7:8f:07:51', u'parents': [], u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/12/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'38:ea:a7:8f:07:50', u'parents': [], u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/15/'}, {u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 21}], 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'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'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'38:ea:a7:8f:12:49', u'parents': [], u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/13/'}, {u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 22}], 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'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'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'38:ea:a7:8f:12:48', u'parents': [], u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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': 23}], 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'primary_rack': u'mhs3yd', 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'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', 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'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'system_id': u'7ys8pe', u'params': u'', u'mac_address': u'9c:b6:54:8a:10:1c', u'parents': [], u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/7ys8pe/interfaces/16/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2018-12-27 11:09:25,464 [salt.state       :300 ][INFO    ][22575] {'new': {'storage_layout': 'lvm'}}
2018-12-27 11:09:25,465 [salt.state       :1951][INFO    ][22575] Completed state [maas_machines_storage_cmp002_lvm] at time 11:09:25.464949 duration_in_ms=2757.189
2018-12-27 11:09:25,465 [salt.state       :1780][INFO    ][22575] Running state [maas_machines_storage_cmp001_lvm] at time 11:09:25.465501
2018-12-27 11:09:25,465 [salt.state       :1813][INFO    ][22575] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2018-12-27 11:09:26,878 [salt.loaded.ext.module.maasng:610 ][INFO    ][22575] hq74m4
2018-12-27 11:09:26,878 [salt.loaded.ext.module.maasng:626 ][INFO    ][22575] sda
2018-12-27 11:09:27,469 [salt.loaded.ext.module.maasng:361 ][INFO    ][22575] hq74m4
2018-12-27 11:09:27,582 [salt.loaded.ext.module.maasng:367 ][INFO    ][22575] [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/', u'system_id': u'hq74m4', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'size': 800109715456, u'used_size': 800106479616, u'id': 3, u'partitions': [{u'uuid': u'593041c1-e3eb-4e1b-8dc4-7f48e783e135', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hq74m4', u'device_id': 3, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'6fce5023-0131-4390-b994-032a91bd2438', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/partition/2', u'type': u'partition', u'id': 2, u'size': 800101236736}]}, {u'model': None, u'block_size': 4096, u'available_size': 0, u'uuid': u'62fd33d7-082c-4d38-a261-6ff2c912564f', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/5/', u'system_id': u'hq74m4', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'39e3f94c-1a69-47c2-ab67-17d0e9f4c742', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'size': 800097042432, u'used_size': 800097042432, u'id': 5, u'partitions': []}]
2018-12-27 11:09:27,582 [salt.loaded.ext.module.maasng:632 ][INFO    ][22575] vgroot
2018-12-27 11:09:27,582 [salt.loaded.ext.module.maasng:635 ][INFO    ][22575] lvroot
2018-12-27 11:09:27,583 [salt.loaded.ext.module.maasng:639 ][INFO    ][22575] 107374182400
2018-12-27 11:09:28,264 [salt.loaded.ext.module.maasng:645 ][INFO    ][22575] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.39', u'192.168.11.43'], 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'fqdn': u'cmp001.maas', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/', u'used_size': 800106479616, u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'hq74m4', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'uuid': u'52c7c706-c1a0-4120-9926-7b748df6c060', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hq74m4', u'device_id': 3, u'filesystem': {u'uuid': u'280bea60-8f16-4e07-ae0f-9872e8f039c6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'type': u'physical', u'id': 3, u'tags': [u'ssd'], u'size': 800109715456}, u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/', u'used_size': 800106479616, u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'hq74m4', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'uuid': u'52c7c706-c1a0-4120-9926-7b748df6c060', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hq74m4', u'device_id': 3, u'filesystem': {u'uuid': u'280bea60-8f16-4e07-ae0f-9872e8f039c6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'type': u'physical', u'id': 3, u'tags': [u'ssd'], u'size': 800109715456}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/13/', u'used_size': 107374182400, u'filesystem': {u'uuid': u'455570c3-b7ed-4e14-aaa9-5807d3addb74', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'uuid': u'1dde2e43-08c9-4c8e-9f62-5c34f56ae4cc', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hq74m4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 13, u'tags': [], u'size': 107374182400}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/hq74m4/', u'current_commissioning_result_id': 4, u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'hq74m4', u'power_state': u'off', u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'disable_ipv4': False, u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 40, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'hq74m4', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/', u'used_size': 800106479616, u'filesystem': None, u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'system_id': u'hq74m4', u'partition_table_type': u'MBR', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'partitions': [{u'uuid': u'52c7c706-c1a0-4120-9926-7b748df6c060', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hq74m4', u'device_id': 3, u'filesystem': {u'uuid': u'280bea60-8f16-4e07-ae0f-9872e8f039c6', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/3/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}], u'type': u'physical', u'id': 3, u'tags': [u'ssd'], u'size': 800109715456}], u'netboot': True, u'osystem': u'', u'node_type': 0, u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/blockdevices/13/', u'used_size': 107374182400, u'filesystem': {u'uuid': u'455570c3-b7ed-4e14-aaa9-5807d3addb74', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'uuid': u'1dde2e43-08c9-4c8e-9f62-5c34f56ae4cc', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hq74m4', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'type': u'virtual', u'id': 13, u'tags': [], u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 27}], 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'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'hq74m4', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/6/'}, 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'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 27}], 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'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a0', u'system_id': u'hq74m4', u'type': u'physical', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/6/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d5', u'system_id': u'hq74m4', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/18/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:1f:d4', u'system_id': u'hq74m4', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/19/'}, {u'name': u'ens2f1', u'links': [{u'id': 28, 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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': u'10.20.0.1', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cd', u'system_id': u'hq74m4', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/17/'}, {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'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'link_up', u'id': 29}], 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'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'mhs3yd', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.43'}], u'parents': [], u'params': u'', u'mac_address': u'9c:b6:54:8a:95:a4', u'system_id': u'hq74m4', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/20/'}, {u'name': u'ens2f0', u'links': [{u'id': 30, 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'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': u'10.20.0.1', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'38:ea:a7:8f:52:cc', u'system_id': u'hq74m4', u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/hq74m4/interfaces/21/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2018-12-27 11:09:28,266 [salt.state       :300 ][INFO    ][22575] {'new': {'storage_layout': 'lvm'}}
2018-12-27 11:09:28,266 [salt.state       :1951][INFO    ][22575] Completed state [maas_machines_storage_cmp001_lvm] at time 11:09:28.266759 duration_in_ms=2801.258
2018-12-27 11:09:28,270 [salt.minion      :1711][INFO    ][22575] Returning information for job: 20181227110914977516
2018-12-27 11:09:28,805 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227110928782144
2018-12-27 11:09:28,828 [salt.minion      :1432][INFO    ][22633] Starting a new job with PID 22633
2018-12-27 11:09:29,592 [salt.state       :915 ][INFO    ][22633] Loading fresh modules for state activity
2018-12-27 11:09:29,646 [salt.fileclient  :1219][INFO    ][22633] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2018-12-27 11:09:29,693 [salt.state       :1780][INFO    ][22633] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:29.693896
2018-12-27 11:09:29,694 [salt.state       :1813][INFO    ][22633] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 11:09:29,696 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22633] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 11:09:31,456 [salt.state       :300 ][INFO    ][22633] {'pid': 22640, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 11:09:31,457 [salt.state       :1951][INFO    ][22633] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:31.457047 duration_in_ms=1763.152
2018-12-27 11:09:31,459 [salt.state       :1780][INFO    ][22633] Running state [maas.deploy_machines] at time 11:09:31.459688
2018-12-27 11:09:31,460 [salt.state       :1813][INFO    ][22633] Executing state module.run for [maas.deploy_machines]
2018-12-27 11:09:31,464 [salt.utils.decorators:613 ][WARNING ][22633] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:09:32,086 [salt.loaded.ext.module.maas:684 ][INFO    ][22633] deploymachines hwe_kernel=hwe-16.04 system_id=7ys8pe distro_series=xenial
2018-12-27 11:09:34,611 [salt.loaded.ext.module.maas:684 ][INFO    ][22633] deploymachines hwe_kernel=hwe-16.04 system_id=hq74m4 distro_series=xenial
2018-12-27 11:09:37,078 [salt.loaded.ext.module.maas:684 ][INFO    ][22633] deploymachines hwe_kernel=hwe-16.04 system_id=yckg8r distro_series=xenial
2018-12-27 11:09:38,858 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110938842014
2018-12-27 11:09:38,877 [salt.minion      :1432][INFO    ][22796] Starting a new job with PID 22796
2018-12-27 11:09:38,906 [salt.minion      :1711][INFO    ][22796] Returning information for job: 20181227110938842014
2018-12-27 11:09:39,589 [salt.loaded.ext.module.maas:684 ][INFO    ][22633] deploymachines hwe_kernel=hwe-16.04 system_id=4a8qdn distro_series=xenial
2018-12-27 11:09:41,960 [salt.loaded.ext.module.maas:684 ][INFO    ][22633] deploymachines hwe_kernel=hwe-16.04 system_id=6rdcrs distro_series=xenial
2018-12-27 11:09:44,328 [salt.state       :300 ][INFO    ][22633] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2018-12-27 11:09:44,328 [salt.state       :1951][INFO    ][22633] Completed state [maas.deploy_machines] at time 11:09:44.328722 duration_in_ms=12869.033
2018-12-27 11:09:44,332 [salt.minion      :1711][INFO    ][22633] Returning information for job: 20181227110928782144
2018-12-27 11:09:44,871 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command state.apply with jid 20181227110944851454
2018-12-27 11:09:44,896 [salt.minion      :1432][INFO    ][22918] Starting a new job with PID 22918
2018-12-27 11:09:50,468 [salt.state       :915 ][INFO    ][22918] Loading fresh modules for state activity
2018-12-27 11:09:50,520 [salt.fileclient  :1219][INFO    ][22918] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2018-12-27 11:09:50,577 [salt.state       :1780][INFO    ][22918] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:50.577856
2018-12-27 11:09:50,578 [salt.state       :1813][INFO    ][22918] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2018-12-27 11:09:50,580 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22918] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2018-12-27 11:09:52,453 [salt.state       :300 ][INFO    ][22918] {'pid': 22952, 'retcode': 0, 'stderr': '', 'stdout': ''}
2018-12-27 11:09:52,453 [salt.state       :1951][INFO    ][22918] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 11:09:52.453776 duration_in_ms=1875.92
2018-12-27 11:09:52,455 [salt.state       :1780][INFO    ][22918] Running state [maas.wait_for_machine_status] at time 11:09:52.455444
2018-12-27 11:09:52,456 [salt.state       :1813][INFO    ][22918] Executing state module.run for [maas.wait_for_machine_status]
2018-12-27 11:09:52,457 [salt.utils.decorators:613 ][WARNING ][22918] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2018-12-27 11:09:54,890 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227110954871166
2018-12-27 11:09:54,910 [salt.minion      :1432][INFO    ][22967] Starting a new job with PID 22967
2018-12-27 11:09:54,932 [salt.minion      :1711][INFO    ][22967] Returning information for job: 20181227110954871166
2018-12-27 11:09:55,719 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.74946499s left)
2018-12-27 11:10:05,081 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111005060007
2018-12-27 11:10:05,107 [salt.minion      :1432][INFO    ][22997] Starting a new job with PID 22997
2018-12-27 11:10:05,127 [salt.minion      :1711][INFO    ][22997] Returning information for job: 20181227111005060007
2018-12-27 11:10:15,296 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111015271445
2018-12-27 11:10:15,319 [salt.minion      :1432][INFO    ][23009] Starting a new job with PID 23009
2018-12-27 11:10:15,342 [salt.minion      :1711][INFO    ][23009] Returning information for job: 20181227111015271445
2018-12-27 11:10:25,504 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111025484652
2018-12-27 11:10:25,520 [salt.minion      :1432][INFO    ][23033] Starting a new job with PID 23033
2018-12-27 11:10:25,551 [salt.minion      :1711][INFO    ][23033] Returning information for job: 20181227111025484652
2018-12-27 11:10:28,822 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.64616609s left)
2018-12-27 11:10:35,717 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111035696004
2018-12-27 11:10:35,744 [salt.minion      :1432][INFO    ][23054] Starting a new job with PID 23054
2018-12-27 11:10:35,768 [salt.minion      :1711][INFO    ][23054] Returning information for job: 20181227111035696004
2018-12-27 11:10:45,937 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111045911972
2018-12-27 11:10:45,959 [salt.minion      :1432][INFO    ][23063] Starting a new job with PID 23063
2018-12-27 11:10:45,979 [salt.minion      :1711][INFO    ][23063] Returning information for job: 20181227111045911972
2018-12-27 11:10:55,954 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111055936037
2018-12-27 11:10:55,976 [salt.minion      :1432][INFO    ][23089] Starting a new job with PID 23089
2018-12-27 11:10:56,000 [salt.minion      :1711][INFO    ][23089] Returning information for job: 20181227111055936037
2018-12-27 11:11:02,115 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.35335994s left)
2018-12-27 11:11:06,144 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111106126423
2018-12-27 11:11:06,163 [salt.minion      :1432][INFO    ][23111] Starting a new job with PID 23111
2018-12-27 11:11:06,190 [salt.minion      :1711][INFO    ][23111] Returning information for job: 20181227111106126423
2018-12-27 11:11:16,365 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111116338786
2018-12-27 11:11:16,388 [salt.minion      :1432][INFO    ][23116] Starting a new job with PID 23116
2018-12-27 11:11:16,410 [salt.minion      :1711][INFO    ][23116] Returning information for job: 20181227111116338786
2018-12-27 11:11:26,577 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111126559763
2018-12-27 11:11:26,600 [salt.minion      :1432][INFO    ][23142] Starting a new job with PID 23142
2018-12-27 11:11:26,622 [salt.minion      :1711][INFO    ][23142] Returning information for job: 20181227111126559763
2018-12-27 11:11:35,284 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.18464088s left)
2018-12-27 11:11:36,790 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111136767207
2018-12-27 11:11:36,814 [salt.minion      :1432][INFO    ][23153] Starting a new job with PID 23153
2018-12-27 11:11:36,838 [salt.minion      :1711][INFO    ][23153] Returning information for job: 20181227111136767207
2018-12-27 11:11:47,019 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111146994588
2018-12-27 11:11:47,044 [salt.minion      :1432][INFO    ][23159] Starting a new job with PID 23159
2018-12-27 11:11:47,066 [salt.minion      :1711][INFO    ][23159] Returning information for job: 20181227111146994588
2018-12-27 11:11:57,218 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111157195690
2018-12-27 11:11:57,243 [salt.minion      :1432][INFO    ][23189] Starting a new job with PID 23189
2018-12-27 11:11:57,265 [salt.minion      :1711][INFO    ][23189] Returning information for job: 20181227111157195690
2018-12-27 11:12:07,433 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111207414145
2018-12-27 11:12:07,452 [salt.minion      :1432][INFO    ][23200] Starting a new job with PID 23200
2018-12-27 11:12:07,481 [salt.minion      :1711][INFO    ][23200] Returning information for job: 20181227111207414145
2018-12-27 11:12:08,430 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.0388701s left)
2018-12-27 11:12:17,625 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111217608432
2018-12-27 11:12:17,646 [salt.minion      :1432][INFO    ][23225] Starting a new job with PID 23225
2018-12-27 11:12:17,668 [salt.minion      :1711][INFO    ][23225] Returning information for job: 20181227111217608432
2018-12-27 11:12:27,832 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111227808117
2018-12-27 11:12:27,859 [salt.minion      :1432][INFO    ][23256] Starting a new job with PID 23256
2018-12-27 11:12:27,881 [salt.minion      :1711][INFO    ][23256] Returning information for job: 20181227111227808117
2018-12-27 11:12:37,842 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111237824396
2018-12-27 11:12:37,857 [salt.minion      :1432][INFO    ][23281] Starting a new job with PID 23281
2018-12-27 11:12:37,878 [salt.minion      :1711][INFO    ][23281] Returning information for job: 20181227111237824396
2018-12-27 11:12:41,470 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.99813008s left)
2018-12-27 11:12:48,039 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111248011862
2018-12-27 11:12:48,062 [salt.minion      :1432][INFO    ][23315] Starting a new job with PID 23315
2018-12-27 11:12:48,089 [salt.minion      :1711][INFO    ][23315] Returning information for job: 20181227111248011862
2018-12-27 11:12:58,070 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111258048589
2018-12-27 11:12:58,091 [salt.minion      :1432][INFO    ][23404] Starting a new job with PID 23404
2018-12-27 11:12:58,118 [salt.minion      :1711][INFO    ][23404] Returning information for job: 20181227111258048589
2018-12-27 11:13:08,093 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111308070449
2018-12-27 11:13:08,118 [salt.minion      :1432][INFO    ][23418] Starting a new job with PID 23418
2018-12-27 11:13:08,141 [salt.minion      :1711][INFO    ][23418] Returning information for job: 20181227111308070449
2018-12-27 11:13:14,611 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.8579731s left)
2018-12-27 11:13:18,304 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111318285759
2018-12-27 11:13:18,322 [salt.minion      :1432][INFO    ][23461] Starting a new job with PID 23461
2018-12-27 11:13:18,348 [salt.minion      :1711][INFO    ][23461] Returning information for job: 20181227111318285759
2018-12-27 11:13:28,528 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111328501637
2018-12-27 11:13:28,555 [salt.minion      :1432][INFO    ][23508] Starting a new job with PID 23508
2018-12-27 11:13:28,584 [salt.minion      :1711][INFO    ][23508] Returning information for job: 20181227111328501637
2018-12-27 11:13:38,566 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111338547561
2018-12-27 11:13:38,592 [salt.minion      :1432][INFO    ][23514] Starting a new job with PID 23514
2018-12-27 11:13:38,614 [salt.minion      :1711][INFO    ][23514] Returning information for job: 20181227111338547561
2018-12-27 11:13:47,908 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.5610261s left)
2018-12-27 11:13:48,586 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111348567604
2018-12-27 11:13:48,616 [salt.minion      :1432][INFO    ][23540] Starting a new job with PID 23540
2018-12-27 11:13:48,649 [salt.minion      :1711][INFO    ][23540] Returning information for job: 20181227111348567604
2018-12-27 11:13:58,808 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111358785981
2018-12-27 11:13:58,829 [salt.minion      :1432][INFO    ][23772] Starting a new job with PID 23772
2018-12-27 11:13:58,862 [salt.minion      :1711][INFO    ][23772] Returning information for job: 20181227111358785981
2018-12-27 11:14:09,021 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111409000016
2018-12-27 11:14:09,042 [salt.minion      :1432][INFO    ][23779] Starting a new job with PID 23779
2018-12-27 11:14:09,064 [salt.minion      :1711][INFO    ][23779] Returning information for job: 20181227111409000016
2018-12-27 11:14:19,060 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111419037373
2018-12-27 11:14:19,079 [salt.minion      :1432][INFO    ][23790] Starting a new job with PID 23790
2018-12-27 11:14:19,108 [salt.minion      :1711][INFO    ][23790] Returning information for job: 20181227111419037373
2018-12-27 11:14:21,002 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.46633196s left)
2018-12-27 11:14:29,088 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111429064827
2018-12-27 11:14:29,109 [salt.minion      :1432][INFO    ][23895] Starting a new job with PID 23895
2018-12-27 11:14:29,129 [salt.minion      :1711][INFO    ][23895] Returning information for job: 20181227111429064827
2018-12-27 11:14:39,144 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111439115856
2018-12-27 11:14:39,171 [salt.minion      :1432][INFO    ][23902] Starting a new job with PID 23902
2018-12-27 11:14:39,200 [salt.minion      :1711][INFO    ][23902] Returning information for job: 20181227111439115856
2018-12-27 11:14:49,210 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111449191527
2018-12-27 11:14:49,232 [salt.minion      :1432][INFO    ][23922] Starting a new job with PID 23922
2018-12-27 11:14:49,261 [salt.minion      :1711][INFO    ][23922] Returning information for job: 20181227111449191527
2018-12-27 11:14:54,252 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1948.21713805s left)
2018-12-27 11:14:59,251 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111459231517
2018-12-27 11:14:59,268 [salt.minion      :1432][INFO    ][24153] Starting a new job with PID 24153
2018-12-27 11:14:59,293 [salt.minion      :1711][INFO    ][24153] Returning information for job: 20181227111459231517
2018-12-27 11:15:09,459 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111509441158
2018-12-27 11:15:09,476 [salt.minion      :1432][INFO    ][24172] Starting a new job with PID 24172
2018-12-27 11:15:09,498 [salt.minion      :1711][INFO    ][24172] Returning information for job: 20181227111509441158
2018-12-27 11:15:19,519 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111519496737
2018-12-27 11:15:19,547 [salt.minion      :1432][INFO    ][24182] Starting a new job with PID 24182
2018-12-27 11:15:19,572 [salt.minion      :1711][INFO    ][24182] Returning information for job: 20181227111519496737
2018-12-27 11:15:27,828 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1914.64006901s left)
2018-12-27 11:15:29,549 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111529529901
2018-12-27 11:15:29,565 [salt.minion      :1432][INFO    ][24262] Starting a new job with PID 24262
2018-12-27 11:15:29,598 [salt.minion      :1711][INFO    ][24262] Returning information for job: 20181227111529529901
2018-12-27 11:15:39,629 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111539603381
2018-12-27 11:15:39,659 [salt.minion      :1432][INFO    ][24297] Starting a new job with PID 24297
2018-12-27 11:15:39,684 [salt.minion      :1711][INFO    ][24297] Returning information for job: 20181227111539603381
2018-12-27 11:15:49,655 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111549630214
2018-12-27 11:15:49,684 [salt.minion      :1432][INFO    ][24316] Starting a new job with PID 24316
2018-12-27 11:15:49,713 [salt.minion      :1711][INFO    ][24316] Returning information for job: 20181227111549630214
2018-12-27 11:15:59,724 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111559700124
2018-12-27 11:15:59,750 [salt.minion      :1432][INFO    ][24579] Starting a new job with PID 24579
2018-12-27 11:15:59,777 [salt.minion      :1711][INFO    ][24579] Returning information for job: 20181227111559700124
2018-12-27 11:16:01,181 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.28762293s left)
2018-12-27 11:16:09,814 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111609790464
2018-12-27 11:16:09,838 [salt.minion      :1432][INFO    ][24593] Starting a new job with PID 24593
2018-12-27 11:16:09,861 [salt.minion      :1711][INFO    ][24593] Returning information for job: 20181227111609790464
2018-12-27 11:16:19,902 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111619882257
2018-12-27 11:16:19,919 [salt.minion      :1432][INFO    ][24608] Starting a new job with PID 24608
2018-12-27 11:16:19,948 [salt.minion      :1711][INFO    ][24608] Returning information for job: 20181227111619882257
2018-12-27 11:16:29,983 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111629963129
2018-12-27 11:16:29,998 [salt.minion      :1432][INFO    ][24737] Starting a new job with PID 24737
2018-12-27 11:16:30,019 [salt.minion      :1711][INFO    ][24737] Returning information for job: 20181227111629963129
2018-12-27 11:16:33,940 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1848.52882099s left)
2018-12-27 11:16:40,041 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111640018451
2018-12-27 11:16:40,065 [salt.minion      :1432][INFO    ][24749] Starting a new job with PID 24749
2018-12-27 11:16:40,086 [salt.minion      :1711][INFO    ][24749] Returning information for job: 20181227111640018451
2018-12-27 11:16:50,121 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111650099956
2018-12-27 11:16:50,144 [salt.minion      :1432][INFO    ][24767] Starting a new job with PID 24767
2018-12-27 11:16:50,164 [salt.minion      :1711][INFO    ][24767] Returning information for job: 20181227111650099956
2018-12-27 11:17:00,224 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111700197738
2018-12-27 11:17:00,248 [salt.minion      :1432][INFO    ][24920] Starting a new job with PID 24920
2018-12-27 11:17:00,270 [salt.minion      :1711][INFO    ][24920] Returning information for job: 20181227111700197738
2018-12-27 11:17:07,180 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1815.28900599s left)
2018-12-27 11:17:10,261 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111710230236
2018-12-27 11:17:10,286 [salt.minion      :1432][INFO    ][24937] Starting a new job with PID 24937
2018-12-27 11:17:10,310 [salt.minion      :1711][INFO    ][24937] Returning information for job: 20181227111710230236
2018-12-27 11:17:20,369 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111720341072
2018-12-27 11:17:20,395 [salt.minion      :1432][INFO    ][24949] Starting a new job with PID 24949
2018-12-27 11:17:20,421 [salt.minion      :1711][INFO    ][24949] Returning information for job: 20181227111720341072
2018-12-27 11:17:30,498 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111730476104
2018-12-27 11:17:30,522 [salt.minion      :1432][INFO    ][25000] Starting a new job with PID 25000
2018-12-27 11:17:30,544 [salt.minion      :1711][INFO    ][25000] Returning information for job: 20181227111730476104
2018-12-27 11:17:40,300 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1782.16851902s left)
2018-12-27 11:17:40,529 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111740507992
2018-12-27 11:17:40,547 [salt.minion      :1432][INFO    ][25025] Starting a new job with PID 25025
2018-12-27 11:17:40,569 [salt.minion      :1711][INFO    ][25025] Returning information for job: 20181227111740507992
2018-12-27 11:17:50,606 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111750580920
2018-12-27 11:17:50,630 [salt.minion      :1432][INFO    ][25055] Starting a new job with PID 25055
2018-12-27 11:17:50,655 [salt.minion      :1711][INFO    ][25055] Returning information for job: 20181227111750580920
2018-12-27 11:18:00,703 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111800681394
2018-12-27 11:18:00,722 [salt.minion      :1432][INFO    ][25302] Starting a new job with PID 25302
2018-12-27 11:18:00,750 [salt.minion      :1711][INFO    ][25302] Returning information for job: 20181227111800681394
2018-12-27 11:18:10,856 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111810835590
2018-12-27 11:18:10,871 [salt.minion      :1432][INFO    ][25315] Starting a new job with PID 25315
2018-12-27 11:18:10,897 [salt.minion      :1711][INFO    ][25315] Returning information for job: 20181227111810835590
2018-12-27 11:18:13,637 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1748.83165288s left)
2018-12-27 11:18:20,988 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111820959320
2018-12-27 11:18:21,013 [salt.minion      :1432][INFO    ][25330] Starting a new job with PID 25330
2018-12-27 11:18:21,040 [salt.minion      :1711][INFO    ][25330] Returning information for job: 20181227111820959320
2018-12-27 11:18:31,118 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111831095111
2018-12-27 11:18:31,141 [salt.minion      :1432][INFO    ][25422] Starting a new job with PID 25422
2018-12-27 11:18:31,162 [salt.minion      :1711][INFO    ][25422] Returning information for job: 20181227111831095111
2018-12-27 11:18:41,234 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111841215369
2018-12-27 11:18:41,252 [salt.minion      :1432][INFO    ][25429] Starting a new job with PID 25429
2018-12-27 11:18:41,270 [salt.minion      :1711][INFO    ][25429] Returning information for job: 20181227111841215369
2018-12-27 11:18:46,593 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1715.8756001s left)
2018-12-27 11:18:51,258 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111851226275
2018-12-27 11:18:51,281 [salt.minion      :1432][INFO    ][25467] Starting a new job with PID 25467
2018-12-27 11:18:51,313 [salt.minion      :1711][INFO    ][25467] Returning information for job: 20181227111851226275
2018-12-27 11:19:01,426 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111901405210
2018-12-27 11:19:01,449 [salt.minion      :1432][INFO    ][25550] Starting a new job with PID 25550
2018-12-27 11:19:01,477 [salt.minion      :1711][INFO    ][25550] Returning information for job: 20181227111901405210
2018-12-27 11:19:11,492 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111911472597
2018-12-27 11:19:11,519 [salt.minion      :1432][INFO    ][25567] Starting a new job with PID 25567
2018-12-27 11:19:11,550 [salt.minion      :1711][INFO    ][25567] Returning information for job: 20181227111911472597
2018-12-27 11:19:19,910 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1682.55857801s left)
2018-12-27 11:19:21,656 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111921633735
2018-12-27 11:19:21,679 [salt.minion      :1432][INFO    ][25595] Starting a new job with PID 25595
2018-12-27 11:19:21,703 [salt.minion      :1711][INFO    ][25595] Returning information for job: 20181227111921633735
2018-12-27 11:19:31,774 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111931755227
2018-12-27 11:19:31,789 [salt.minion      :1432][INFO    ][25661] Starting a new job with PID 25661
2018-12-27 11:19:31,811 [salt.minion      :1711][INFO    ][25661] Returning information for job: 20181227111931755227
2018-12-27 11:19:41,843 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111941818159
2018-12-27 11:19:41,865 [salt.minion      :1432][INFO    ][25682] Starting a new job with PID 25682
2018-12-27 11:19:41,894 [salt.minion      :1711][INFO    ][25682] Returning information for job: 20181227111941818159
2018-12-27 11:19:51,972 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227111951952655
2018-12-27 11:19:51,991 [salt.minion      :1432][INFO    ][25835] Starting a new job with PID 25835
2018-12-27 11:19:52,026 [salt.minion      :1711][INFO    ][25835] Returning information for job: 20181227111951952655
2018-12-27 11:19:52,817 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1649.65195203s left)
2018-12-27 11:20:02,130 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112002103978
2018-12-27 11:20:02,156 [salt.minion      :1432][INFO    ][25993] Starting a new job with PID 25993
2018-12-27 11:20:02,184 [salt.minion      :1711][INFO    ][25993] Returning information for job: 20181227112002103978
2018-12-27 11:20:12,333 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112012309972
2018-12-27 11:20:12,356 [salt.minion      :1432][INFO    ][26005] Starting a new job with PID 26005
2018-12-27 11:20:12,379 [salt.minion      :1711][INFO    ][26005] Returning information for job: 20181227112012309972
2018-12-27 11:20:22,493 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112022466556
2018-12-27 11:20:22,518 [salt.minion      :1432][INFO    ][26018] Starting a new job with PID 26018
2018-12-27 11:20:22,540 [salt.minion      :1711][INFO    ][26018] Returning information for job: 20181227112022466556
2018-12-27 11:20:26,157 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1616.31197786s left)
2018-12-27 11:20:32,688 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112032664198
2018-12-27 11:20:32,709 [salt.minion      :1432][INFO    ][26063] Starting a new job with PID 26063
2018-12-27 11:20:32,735 [salt.minion      :1711][INFO    ][26063] Returning information for job: 20181227112032664198
2018-12-27 11:20:42,726 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112042703823
2018-12-27 11:20:42,752 [salt.minion      :1432][INFO    ][26070] Starting a new job with PID 26070
2018-12-27 11:20:42,773 [salt.minion      :1711][INFO    ][26070] Returning information for job: 20181227112042703823
2018-12-27 11:20:52,761 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112052742631
2018-12-27 11:20:52,777 [salt.minion      :1432][INFO    ][26088] Starting a new job with PID 26088
2018-12-27 11:20:52,799 [salt.minion      :1711][INFO    ][26088] Returning information for job: 20181227112052742631
2018-12-27 11:20:59,487 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1582.98200488s left)
2018-12-27 11:21:02,944 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112102913528
2018-12-27 11:21:02,969 [salt.minion      :1432][INFO    ][26118] Starting a new job with PID 26118
2018-12-27 11:21:03,005 [salt.minion      :1711][INFO    ][26118] Returning information for job: 20181227112102913528
2018-12-27 11:21:13,002 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112112975655
2018-12-27 11:21:13,030 [salt.minion      :1432][INFO    ][26124] Starting a new job with PID 26124
2018-12-27 11:21:13,058 [salt.minion      :1711][INFO    ][26124] Returning information for job: 20181227112112975655
2018-12-27 11:21:23,040 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112123014420
2018-12-27 11:21:23,066 [salt.minion      :1432][INFO    ][26134] Starting a new job with PID 26134
2018-12-27 11:21:23,090 [salt.minion      :1711][INFO    ][26134] Returning information for job: 20181227112123014420
2018-12-27 11:21:32,639 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1549.82941794s left)
2018-12-27 11:21:33,217 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112133199757
2018-12-27 11:21:33,240 [salt.minion      :1432][INFO    ][26166] Starting a new job with PID 26166
2018-12-27 11:21:33,266 [salt.minion      :1711][INFO    ][26166] Returning information for job: 20181227112133199757
2018-12-27 11:21:43,301 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112143275325
2018-12-27 11:21:43,324 [salt.minion      :1432][INFO    ][26192] Starting a new job with PID 26192
2018-12-27 11:21:43,347 [salt.minion      :1711][INFO    ][26192] Returning information for job: 20181227112143275325
2018-12-27 11:21:53,433 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112153409800
2018-12-27 11:21:53,455 [salt.minion      :1432][INFO    ][26231] Starting a new job with PID 26231
2018-12-27 11:21:53,484 [salt.minion      :1711][INFO    ][26231] Returning information for job: 20181227112153409800
2018-12-27 11:22:03,623 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112203603638
2018-12-27 11:22:03,642 [salt.minion      :1432][INFO    ][26273] Starting a new job with PID 26273
2018-12-27 11:22:03,678 [salt.minion      :1711][INFO    ][26273] Returning information for job: 20181227112203603638
2018-12-27 11:22:05,983 [salt.loaded.ext.module.maas:1001][INFO    ][22918] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1516.48532009s left)
2018-12-27 11:22:13,655 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112213636557
2018-12-27 11:22:13,677 [salt.minion      :1432][INFO    ][26319] Starting a new job with PID 26319
2018-12-27 11:22:13,704 [salt.minion      :1711][INFO    ][26319] Returning information for job: 20181227112213636557
2018-12-27 11:22:23,735 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112223708630
2018-12-27 11:22:23,758 [salt.minion      :1432][INFO    ][26349] Starting a new job with PID 26349
2018-12-27 11:22:23,783 [salt.minion      :1711][INFO    ][26349] Returning information for job: 20181227112223708630
2018-12-27 11:22:33,799 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command saltutil.find_job with jid 20181227112233772892
2018-12-27 11:22:33,824 [salt.minion      :1432][INFO    ][26461] Starting a new job with PID 26461
2018-12-27 11:22:33,859 [salt.minion      :1711][INFO    ][26461] Returning information for job: 20181227112233772892
2018-12-27 11:22:39,140 [salt.state       :300 ][INFO    ][22918] {'ret': True}
2018-12-27 11:22:39,140 [salt.state       :1951][INFO    ][22918] Completed state [maas.wait_for_machine_status] at time 11:22:39.140670 duration_in_ms=766685.225
2018-12-27 11:22:39,147 [salt.minion      :1711][INFO    ][22918] Returning information for job: 20181227110944851454
2018-12-27 11:45:10,033 [salt.utils.schedule:1377][INFO    ][4651] Running scheduled job: __mine_interval
2018-12-27 12:29:34,395 [salt.minion      :1308][INFO    ][4651] User sudo_ubuntu Executing command cp.push_dir with jid 20181227122934372845
2018-12-27 12:29:34,432 [salt.minion      :1432][INFO    ][31484] Starting a new job with PID 31484
