2019-05-09 05:05:41,085 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-09 05:06:31,122 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-09 05:07:21,162 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-09 05:08:11,208 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-09 05:09:01,258 [salt.minion      :870 ][ERROR   ][354] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-09 05:11:09,906 [salt.utils.decorators:613 ][WARNING ][2843] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 05:11:10,504 [salt.utils.decorators:613 ][WARNING ][2843] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 05:11:12,582 [salt.loaded.int.states.file:2298][WARNING ][2996] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-09 05:11:17,895 [salt.state       :2022][WARNING ][3093] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-09 05:11:20,659 [salt.utils.decorators:613 ][WARNING ][3093] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 05:26:27,518 [salt.utils.decorators:613 ][WARNING ][3093] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 05:53:02,707 [salt.utils.decorators:613 ][WARNING ][3093] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:08:03,117 [salt.utils.decorators:613 ][WARNING ][3093] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:08:07,461 [salt.loaded.ext.module.maasng:1008][WARNING ][3093] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-09 06:08:07,462 [salt.loaded.ext.module.maasng:1011][WARNING ][3093] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-09 06:08:08,271 [salt.loaded.ext.module.maasng:1235][WARNING ][3093] Ignoring parameter vlan:0
2019-05-09 06:08:14,861 [salt.utils.decorators:613 ][WARNING ][8685] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:08:14,908 [salt.loaded.ext.module.maas:412 ][WARNING ][8685] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:08:19,082 [salt.loaded.ext.module.maas:412 ][WARNING ][8685] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:08:22,946 [salt.loaded.ext.module.maas:412 ][WARNING ][8685] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:08:27,330 [salt.loaded.ext.module.maas:412 ][WARNING ][8685] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:08:30,126 [salt.loaded.ext.module.maas:412 ][WARNING ][8685] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:08:36,731 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9630] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-09 06:08:36,763 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9630] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-09 06:08:36,785 [salt.utils.parsers:1051][WARNING ][354] Minion received a SIGTERM. Exiting.
2019-05-09 06:08:37,866 [salt.cli.daemons :293 ][INFO    ][9675] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-05-09 06:08:37,965 [salt.cli.daemons :82  ][INFO    ][9675] Starting up the Salt Minion
2019-05-09 06:08:37,966 [salt.utils.event :1017][INFO    ][9675] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-05-09 06:08:38,934 [salt.minion      :976 ][INFO    ][9675] Creating minion process manager
2019-05-09 06:08:40,319 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][9675] Executing command ['date', '+%z'] in directory '/root'
2019-05-09 06:08:40,338 [salt.utils.schedule:568 ][INFO    ][9675] Updating job settings for scheduled job: __mine_interval
2019-05-09 06:08:40,339 [salt.minion      :1108][INFO    ][9675] Added mine.update to scheduler
2019-05-09 06:08:40,343 [salt.minion      :1975][INFO    ][9675] Minion is starting as user 'root'
2019-05-09 06:08:40,355 [salt.minion      :2336][INFO    ][9675] Minion is ready to receive requests!
2019-05-09 06:09:04,596 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509060904582860
2019-05-09 06:09:04,617 [salt.minion      :1432][INFO    ][9767] Starting a new job with PID 9767
2019-05-09 06:09:08,261 [salt.state       :915 ][INFO    ][9767] Loading fresh modules for state activity
2019-05-09 06:09:08,314 [salt.fileclient  :1219][INFO    ][9767] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-09 06:09:08,360 [salt.state       :1780][INFO    ][9767] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:09:08.360035
2019-05-09 06:09:08,360 [salt.state       :1813][INFO    ][9767] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:09:08,362 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9767] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:09:09,928 [salt.state       :300 ][INFO    ][9767] {'pid': 9775, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:09:09,929 [salt.state       :1951][INFO    ][9767] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:09:09.929634 duration_in_ms=1569.597
2019-05-09 06:09:09,932 [salt.state       :1780][INFO    ][9767] Running state [maas.wait_for_machine_status] at time 06:09:09.932433
2019-05-09 06:09:09,933 [salt.state       :1813][INFO    ][9767] Executing state module.run for [maas.wait_for_machine_status]
2019-05-09 06:09:09,934 [salt.utils.decorators:613 ][WARNING ][9767] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:09:10,879 [salt.loaded.ext.module.maas:1023][INFO    ][9767] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.06577182s left)
2019-05-09 06:09:19,652 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509060919639072
2019-05-09 06:09:19,675 [salt.minion      :1432][INFO    ][9801] Starting a new job with PID 9801
2019-05-09 06:09:19,699 [salt.minion      :1711][INFO    ][9801] Returning information for job: 20190509060919639072
2019-05-09 06:09:41,861 [salt.loaded.ext.module.maas:1023][INFO    ][9767] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.08323479s left)
2019-05-09 06:09:49,694 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509060949682472
2019-05-09 06:09:49,717 [salt.minion      :1432][INFO    ][9848] Starting a new job with PID 9848
2019-05-09 06:09:49,740 [salt.minion      :1711][INFO    ][9848] Returning information for job: 20190509060949682472
2019-05-09 06:10:12,859 [salt.loaded.ext.module.maas:1023][INFO    ][9767] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.08573985s left)
2019-05-09 06:10:19,767 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061019754335
2019-05-09 06:10:19,789 [salt.minion      :1432][INFO    ][10030] Starting a new job with PID 10030
2019-05-09 06:10:19,813 [salt.minion      :1711][INFO    ][10030] Returning information for job: 20190509061019754335
2019-05-09 06:10:44,252 [salt.loaded.ext.module.maas:1023][INFO    ][9767] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.69271183s left)
2019-05-09 06:10:49,812 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061049804092
2019-05-09 06:10:49,833 [salt.minion      :1432][INFO    ][10230] Starting a new job with PID 10230
2019-05-09 06:10:49,857 [salt.minion      :1711][INFO    ][10230] Returning information for job: 20190509061049804092
2019-05-09 06:11:15,930 [salt.loaded.ext.module.maas:1023][INFO    ][9767] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.01504898s left)
2019-05-09 06:11:19,873 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061119862292
2019-05-09 06:11:19,894 [salt.minion      :1432][INFO    ][10381] Starting a new job with PID 10381
2019-05-09 06:11:19,917 [salt.minion      :1711][INFO    ][10381] Returning information for job: 20190509061119862292
2019-05-09 06:11:49,948 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061149934432
2019-05-09 06:11:49,973 [salt.minion      :1432][INFO    ][11120] Starting a new job with PID 11120
2019-05-09 06:11:49,994 [salt.minion      :1711][INFO    ][11120] Returning information for job: 20190509061149934432
2019-05-09 06:12:20,026 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061220013585
2019-05-09 06:12:20,045 [salt.minion      :1432][INFO    ][11280] Starting a new job with PID 11280
2019-05-09 06:12:20,068 [salt.minion      :1711][INFO    ][11280] Returning information for job: 20190509061220013585
2019-05-09 06:12:50,112 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061250099219
2019-05-09 06:12:50,134 [salt.minion      :1432][INFO    ][11354] Starting a new job with PID 11354
2019-05-09 06:12:50,156 [salt.minion      :1711][INFO    ][11354] Returning information for job: 20190509061250099219
2019-05-09 06:13:20,184 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061320167955
2019-05-09 06:13:20,202 [salt.minion      :1432][INFO    ][11393] Starting a new job with PID 11393
2019-05-09 06:13:20,217 [salt.minion      :1711][INFO    ][11393] Returning information for job: 20190509061320167955
2019-05-09 06:13:50,254 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061350244614
2019-05-09 06:13:50,272 [salt.minion      :1432][INFO    ][11429] Starting a new job with PID 11429
2019-05-09 06:13:50,285 [salt.minion      :1711][INFO    ][11429] Returning information for job: 20190509061350244614
2019-05-09 06:14:20,333 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061420323665
2019-05-09 06:14:20,355 [salt.minion      :1432][INFO    ][11469] Starting a new job with PID 11469
2019-05-09 06:14:20,373 [salt.minion      :1711][INFO    ][11469] Returning information for job: 20190509061420323665
2019-05-09 06:14:50,431 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061450420360
2019-05-09 06:14:50,450 [salt.minion      :1432][INFO    ][11514] Starting a new job with PID 11514
2019-05-09 06:14:50,470 [salt.minion      :1711][INFO    ][11514] Returning information for job: 20190509061450420360
2019-05-09 06:15:20,536 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061520524198
2019-05-09 06:15:20,558 [salt.minion      :1432][INFO    ][11562] Starting a new job with PID 11562
2019-05-09 06:15:20,575 [salt.minion      :1711][INFO    ][11562] Returning information for job: 20190509061520524198
2019-05-09 06:15:50,649 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061550635328
2019-05-09 06:15:50,668 [salt.minion      :1432][INFO    ][11598] Starting a new job with PID 11598
2019-05-09 06:15:50,688 [salt.minion      :1711][INFO    ][11598] Returning information for job: 20190509061550635328
2019-05-09 06:16:20,756 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061620744366
2019-05-09 06:16:20,778 [salt.minion      :1432][INFO    ][11638] Starting a new job with PID 11638
2019-05-09 06:16:20,799 [salt.minion      :1711][INFO    ][11638] Returning information for job: 20190509061620744366
2019-05-09 06:16:50,874 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061650862317
2019-05-09 06:16:50,893 [salt.minion      :1432][INFO    ][11663] Starting a new job with PID 11663
2019-05-09 06:16:50,913 [salt.minion      :1711][INFO    ][11663] Returning information for job: 20190509061650862317
2019-05-09 06:17:20,999 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061720989427
2019-05-09 06:17:21,020 [salt.minion      :1432][INFO    ][11703] Starting a new job with PID 11703
2019-05-09 06:17:21,044 [salt.minion      :1711][INFO    ][11703] Returning information for job: 20190509061720989427
2019-05-09 06:17:51,126 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061751114381
2019-05-09 06:17:51,149 [salt.minion      :1432][INFO    ][11731] Starting a new job with PID 11731
2019-05-09 06:17:51,173 [salt.minion      :1711][INFO    ][11731] Returning information for job: 20190509061751114381
2019-05-09 06:17:53,914 [salt.state       :302 ][ERROR   ][9767] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-05-09 06:17:53,915 [salt.state       :1951][INFO    ][9767] Completed state [maas.wait_for_machine_status] at time 06:17:53.915310 duration_in_ms=523982.876
2019-05-09 06:17:53,918 [salt.minion      :1711][INFO    ][9767] Returning information for job: 20190509060904582860
2019-05-09 06:18:04,620 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command pillar.get with jid 20190509061804607476
2019-05-09 06:18:04,641 [salt.minion      :1432][INFO    ][11981] Starting a new job with PID 11981
2019-05-09 06:18:04,649 [salt.minion      :1711][INFO    ][11981] Returning information for job: 20190509061804607476
2019-05-09 06:18:05,183 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command service.status with jid 20190509061805169919
2019-05-09 06:18:05,204 [salt.minion      :1432][INFO    ][11989] Starting a new job with PID 11989
2019-05-09 06:18:05,598 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11989] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:05,632 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11989] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-09 06:18:05,647 [salt.minion      :1711][INFO    ][11989] Returning information for job: 20190509061805169919
2019-05-09 06:18:06,230 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509061806218126
2019-05-09 06:18:06,249 [salt.minion      :1432][INFO    ][12001] Starting a new job with PID 12001
2019-05-09 06:18:10,030 [salt.state       :915 ][INFO    ][12001] Loading fresh modules for state activity
2019-05-09 06:18:10,461 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'salt-minion --version' in directory '/root'
2019-05-09 06:18:10,759 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'salt-minion --version' in directory '/root'
2019-05-09 06:18:11,621 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'salt-minion --version' in directory '/root'
2019-05-09 06:18:11,965 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'salt-minion --version' in directory '/root'
2019-05-09 06:18:13,297 [salt.state       :1780][INFO    ][12001] Running state [salt-minion] at time 06:18:13.297093
2019-05-09 06:18:13,297 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [salt-minion]
2019-05-09 06:18:13,297 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-09 06:18:13,382 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,383 [salt.state       :1951][INFO    ][12001] Completed state [salt-minion] at time 06:18:13.383103 duration_in_ms=86.009
2019-05-09 06:18:13,383 [salt.state       :1780][INFO    ][12001] Running state [salt_minion_dependency_packages] at time 06:18:13.383422
2019-05-09 06:18:13,383 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-09 06:18:13,390 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,390 [salt.state       :1951][INFO    ][12001] Completed state [salt_minion_dependency_packages] at time 06:18:13.390282 duration_in_ms=6.86
2019-05-09 06:18:13,393 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/minion.d/minion.conf] at time 06:18:13.393279
2019-05-09 06:18:13,393 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-09 06:18:13,590 [salt.state       :300 ][INFO    ][12001] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-09 06:18:13,590 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/minion.d/minion.conf] at time 06:18:13.590593 duration_in_ms=197.314
2019-05-09 06:18:13,590 [salt.state       :1780][INFO    ][12001] Running state [python-netaddr] at time 06:18:13.590840
2019-05-09 06:18:13,591 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [python-netaddr]
2019-05-09 06:18:13,597 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,598 [salt.state       :1951][INFO    ][12001] Completed state [python-netaddr] at time 06:18:13.598096 duration_in_ms=7.255
2019-05-09 06:18:13,601 [salt.state       :1780][INFO    ][12001] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:18:13.601131
2019-05-09 06:18:13,601 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-09 06:18:13,612 [salt.state       :300 ][INFO    ][12001] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-09 06:18:13,613 [salt.state       :1951][INFO    ][12001] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 06:18:13.612952 duration_in_ms=11.821
2019-05-09 06:18:13,614 [salt.state       :1780][INFO    ][12001] Running state [salt-minion] at time 06:18:13.614018
2019-05-09 06:18:13,614 [salt.state       :1813][INFO    ][12001] Executing state service.running for [salt-minion]
2019-05-09 06:18:13,614 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:13,651 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-09 06:18:13,669 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-09 06:18:13,685 [salt.state       :300 ][INFO    ][12001] The service salt-minion is already running
2019-05-09 06:18:13,686 [salt.state       :1951][INFO    ][12001] Completed state [salt-minion] at time 06:18:13.686315 duration_in_ms=72.297
2019-05-09 06:18:13,688 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains.d] at time 06:18:13.687991
2019-05-09 06:18:13,688 [salt.state       :1813][INFO    ][12001] Executing state file.directory for [/etc/salt/grains.d]
2019-05-09 06:18:13,689 [salt.state       :300 ][INFO    ][12001] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-09 06:18:13,689 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains.d] at time 06:18:13.689659 duration_in_ms=1.668
2019-05-09 06:18:13,690 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains] at time 06:18:13.690384
2019-05-09 06:18:13,690 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/grains]
2019-05-09 06:18:13,691 [salt.state       :300 ][INFO    ][12001] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-09 06:18:13,691 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains] at time 06:18:13.691593 duration_in_ms=1.209
2019-05-09 06:18:13,692 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains.d/placeholder] at time 06:18:13.692089
2019-05-09 06:18:13,692 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-09 06:18:13,693 [salt.state       :300 ][INFO    ][12001] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-09 06:18:13,693 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains.d/placeholder] at time 06:18:13.693207 duration_in_ms=1.119
2019-05-09 06:18:13,693 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains.d/sphinx] at time 06:18:13.693703
2019-05-09 06:18:13,694 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-09 06:18:13,703 [salt.state       :300 ][INFO    ][12001] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-09 06:18:13,704 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains.d/sphinx] at time 06:18:13.704042 duration_in_ms=10.339
2019-05-09 06:18:13,706 [salt.state       :1780][INFO    ][12001] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.706381
2019-05-09 06:18:13,706 [salt.state       :1813][INFO    ][12001] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-09 06:18:13,707 [salt.state       :300 ][INFO    ][12001] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-09 06:18:13,707 [salt.state       :1951][INFO    ][12001] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.707298 duration_in_ms=0.917
2019-05-09 06:18:13,707 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains.d/dns_records] at time 06:18:13.707813
2019-05-09 06:18:13,708 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-09 06:18:13,721 [salt.state       :300 ][INFO    ][12001] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-09 06:18:13,722 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains.d/dns_records] at time 06:18:13.722333 duration_in_ms=14.518
2019-05-09 06:18:13,724 [salt.state       :1780][INFO    ][12001] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.724045
2019-05-09 06:18:13,724 [salt.state       :1813][INFO    ][12001] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-09 06:18:13,725 [salt.state       :300 ][INFO    ][12001] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-09 06:18:13,725 [salt.state       :1951][INFO    ][12001] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.725740 duration_in_ms=1.694
2019-05-09 06:18:13,726 [salt.state       :1780][INFO    ][12001] Running state [/etc/salt/grains.d/salt] at time 06:18:13.726731
2019-05-09 06:18:13,727 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-09 06:18:13,739 [salt.state       :300 ][INFO    ][12001] File /etc/salt/grains.d/salt is in the correct state
2019-05-09 06:18:13,740 [salt.state       :1951][INFO    ][12001] Completed state [/etc/salt/grains.d/salt] at time 06:18:13.740169 duration_in_ms=13.437
2019-05-09 06:18:13,741 [salt.state       :1780][INFO    ][12001] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.741688
2019-05-09 06:18:13,742 [salt.state       :1813][INFO    ][12001] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-09 06:18:13,742 [salt.state       :300 ][INFO    ][12001] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-09 06:18:13,743 [salt.state       :1951][INFO    ][12001] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 06:18:13.743255 duration_in_ms=1.566
2019-05-09 06:18:13,746 [salt.state       :1780][INFO    ][12001] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:18:13.746224
2019-05-09 06:18:13,746 [salt.state       :1813][INFO    ][12001] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-09 06:18:13,747 [salt.state       :300 ][INFO    ][12001] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-09 06:18:13,747 [salt.state       :1951][INFO    ][12001] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 06:18:13.747776 duration_in_ms=1.552
2019-05-09 06:18:13,748 [salt.state       :1780][INFO    ][12001] Running state [mine.update] at time 06:18:13.748918
2019-05-09 06:18:13,749 [salt.state       :1813][INFO    ][12001] Executing state module.wait for [mine.update]
2019-05-09 06:18:13,750 [salt.state       :300 ][INFO    ][12001] No changes made for mine.update
2019-05-09 06:18:13,750 [salt.state       :1951][INFO    ][12001] Completed state [mine.update] at time 06:18:13.750341 duration_in_ms=1.422
2019-05-09 06:18:13,750 [salt.state       :1780][INFO    ][12001] Running state [ca-certificates] at time 06:18:13.750860
2019-05-09 06:18:13,751 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [ca-certificates]
2019-05-09 06:18:13,761 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,761 [salt.state       :1951][INFO    ][12001] Completed state [ca-certificates] at time 06:18:13.761710 duration_in_ms=10.85
2019-05-09 06:18:13,762 [salt.state       :1780][INFO    ][12001] Running state [update-ca-certificates] at time 06:18:13.762839
2019-05-09 06:18:13,763 [salt.state       :1813][INFO    ][12001] Executing state cmd.wait for [update-ca-certificates]
2019-05-09 06:18:13,763 [salt.state       :300 ][INFO    ][12001] No changes made for update-ca-certificates
2019-05-09 06:18:13,764 [salt.state       :1951][INFO    ][12001] Completed state [update-ca-certificates] at time 06:18:13.764247 duration_in_ms=1.407
2019-05-09 06:18:13,764 [salt.state       :1780][INFO    ][12001] Running state [iptables] at time 06:18:13.764748
2019-05-09 06:18:13,765 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [iptables]
2019-05-09 06:18:13,774 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,774 [salt.state       :1951][INFO    ][12001] Completed state [iptables] at time 06:18:13.774591 duration_in_ms=9.842
2019-05-09 06:18:13,775 [salt.state       :1780][INFO    ][12001] Running state [iptables-persistent] at time 06:18:13.775050
2019-05-09 06:18:13,775 [salt.state       :1813][INFO    ][12001] Executing state pkg.installed for [iptables-persistent]
2019-05-09 06:18:13,784 [salt.state       :300 ][INFO    ][12001] All specified packages are already installed
2019-05-09 06:18:13,784 [salt.state       :1951][INFO    ][12001] Completed state [iptables-persistent] at time 06:18:13.784451 duration_in_ms=9.401
2019-05-09 06:18:13,785 [salt.state       :1780][INFO    ][12001] Running state [iptables_modules_v4_load] at time 06:18:13.785885
2019-05-09 06:18:13,786 [salt.state       :1813][INFO    ][12001] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-09 06:18:13,787 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'lsmod' in directory '/root'
2019-05-09 06:18:13,812 [salt.state       :300 ][INFO    ][12001] Kernel modules iptable_filter, ip_tables are already present
2019-05-09 06:18:13,812 [salt.state       :1951][INFO    ][12001] Completed state [iptables_modules_v4_load] at time 06:18:13.812688 duration_in_ms=26.802
2019-05-09 06:18:13,813 [salt.state       :1780][INFO    ][12001] Running state [/etc/iptables/rules.v4] at time 06:18:13.813596
2019-05-09 06:18:13,814 [salt.state       :1813][INFO    ][12001] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-09 06:18:13,919 [salt.state       :300 ][INFO    ][12001] File /etc/iptables/rules.v4 is in the correct state
2019-05-09 06:18:13,920 [salt.state       :1951][INFO    ][12001] Completed state [/etc/iptables/rules.v4] at time 06:18:13.920061 duration_in_ms=106.465
2019-05-09 06:18:13,922 [salt.state       :1780][INFO    ][12001] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:18:13.922125
2019-05-09 06:18:13,922 [salt.state       :1813][INFO    ][12001] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-09 06:18:13,923 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-09 06:18:13,940 [salt.state       :300 ][INFO    ][12001] onlyif execution failed
2019-05-09 06:18:13,940 [salt.state       :1951][INFO    ][12001] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 06:18:13.940803 duration_in_ms=18.678
2019-05-09 06:18:13,941 [salt.state       :1780][INFO    ][12001] Running state [netfilter-persistent] at time 06:18:13.941864
2019-05-09 06:18:13,942 [salt.state       :1813][INFO    ][12001] Executing state service.running for [netfilter-persistent]
2019-05-09 06:18:13,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:13,962 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-09 06:18:13,978 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-09 06:18:13,992 [salt.state       :300 ][INFO    ][12001] The service netfilter-persistent is already running
2019-05-09 06:18:13,993 [salt.state       :1951][INFO    ][12001] Completed state [netfilter-persistent] at time 06:18:13.993265 duration_in_ms=51.4
2019-05-09 06:18:13,994 [salt.state       :1780][INFO    ][12001] Running state [iptables_extra.remove_stale_tables] at time 06:18:13.994339
2019-05-09 06:18:13,994 [salt.state       :1813][INFO    ][12001] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-09 06:18:13,995 [salt.state       :300 ][INFO    ][12001] No changes made for iptables_extra.remove_stale_tables
2019-05-09 06:18:13,995 [salt.state       :1951][INFO    ][12001] Completed state [iptables_extra.remove_stale_tables] at time 06:18:13.995431 duration_in_ms=1.091
2019-05-09 06:18:13,995 [salt.state       :1780][INFO    ][12001] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:18:13.995749
2019-05-09 06:18:13,996 [salt.state       :1813][INFO    ][12001] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-09 06:18:13,996 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12001] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-09 06:18:14,009 [salt.state       :300 ][INFO    ][12001] onlyif execution failed
2019-05-09 06:18:14,009 [salt.state       :1951][INFO    ][12001] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 06:18:14.009777 duration_in_ms=14.028
2019-05-09 06:18:14,010 [salt.state       :1780][INFO    ][12001] Running state [/etc/iptables/rules.v6] at time 06:18:14.010779
2019-05-09 06:18:14,011 [salt.state       :1813][INFO    ][12001] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-09 06:18:14,011 [salt.state       :300 ][INFO    ][12001] File /etc/iptables/rules.v6 is not present
2019-05-09 06:18:14,011 [salt.state       :1951][INFO    ][12001] Completed state [/etc/iptables/rules.v6] at time 06:18:14.011817 duration_in_ms=1.038
2019-05-09 06:18:14,012 [salt.state       :1780][INFO    ][12001] Running state [iptables_extra.flush_all] at time 06:18:14.012465
2019-05-09 06:18:14,012 [salt.state       :1813][INFO    ][12001] Executing state module.wait for [iptables_extra.flush_all]
2019-05-09 06:18:14,013 [salt.state       :300 ][INFO    ][12001] No changes made for iptables_extra.flush_all
2019-05-09 06:18:14,013 [salt.state       :1951][INFO    ][12001] Completed state [iptables_extra.flush_all] at time 06:18:14.013263 duration_in_ms=0.797
2019-05-09 06:18:14,016 [salt.minion      :1711][INFO    ][12001] Returning information for job: 20190509061806218126
2019-05-09 06:18:14,538 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509061814526057
2019-05-09 06:18:14,556 [salt.minion      :1432][INFO    ][12110] Starting a new job with PID 12110
2019-05-09 06:18:15,256 [salt.state       :915 ][INFO    ][12110] Loading fresh modules for state activity
2019-05-09 06:18:15,886 [salt.state       :1780][INFO    ][12110] Running state [maas-rack-controller] at time 06:18:15.886635
2019-05-09 06:18:15,886 [salt.state       :1813][INFO    ][12110] Executing state pkg.installed for [maas-rack-controller]
2019-05-09 06:18:15,887 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12110] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-09 06:18:16,017 [salt.state       :300 ][INFO    ][12110] All specified packages are already installed
2019-05-09 06:18:16,017 [salt.state       :1951][INFO    ][12110] Completed state [maas-rack-controller] at time 06:18:16.017376 duration_in_ms=130.742
2019-05-09 06:18:16,017 [salt.state       :1780][INFO    ][12110] Running state [ipmitool] at time 06:18:16.017641
2019-05-09 06:18:16,017 [salt.state       :1813][INFO    ][12110] Executing state pkg.installed for [ipmitool]
2019-05-09 06:18:16,022 [salt.state       :300 ][INFO    ][12110] All specified packages are already installed
2019-05-09 06:18:16,022 [salt.state       :1951][INFO    ][12110] Completed state [ipmitool] at time 06:18:16.022496 duration_in_ms=4.854
2019-05-09 06:18:16,024 [salt.state       :1780][INFO    ][12110] Running state [/etc/maas/rackd.conf] at time 06:18:16.024875
2019-05-09 06:18:16,025 [salt.state       :1813][INFO    ][12110] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-09 06:18:16,025 [salt.state       :300 ][INFO    ][12110] No changes needed to be made
2019-05-09 06:18:16,026 [salt.state       :1951][INFO    ][12110] Completed state [/etc/maas/rackd.conf] at time 06:18:16.025987 duration_in_ms=1.113
2019-05-09 06:18:16,026 [salt.state       :1780][INFO    ][12110] Running state [/etc/maas/rackd.conf] at time 06:18:16.026153
2019-05-09 06:18:16,026 [salt.state       :1813][INFO    ][12110] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-09 06:18:16,026 [salt.loaded.int.states.file:2298][WARNING ][12110] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-09 06:18:16,026 [salt.state       :300 ][INFO    ][12110] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-09 06:18:16,027 [salt.state       :1951][INFO    ][12110] Completed state [/etc/maas/rackd.conf] at time 06:18:16.027030 duration_in_ms=0.877
2019-05-09 06:18:16,027 [salt.state       :1780][INFO    ][12110] Running state [maas-rackd] at time 06:18:16.027720
2019-05-09 06:18:16,027 [salt.state       :1813][INFO    ][12110] Executing state service.running for [maas-rackd]
2019-05-09 06:18:16,028 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12110] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:16,060 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12110] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-09 06:18:16,076 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12110] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-09 06:18:16,091 [salt.state       :300 ][INFO    ][12110] The service maas-rackd is already running
2019-05-09 06:18:16,092 [salt.state       :1951][INFO    ][12110] Completed state [maas-rackd] at time 06:18:16.092070 duration_in_ms=64.35
2019-05-09 06:18:16,093 [salt.minion      :1711][INFO    ][12110] Returning information for job: 20190509061814526057
2019-05-09 06:18:16,642 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509061816628910
2019-05-09 06:18:16,663 [salt.minion      :1432][INFO    ][12161] Starting a new job with PID 12161
2019-05-09 06:18:17,397 [salt.state       :915 ][INFO    ][12161] Loading fresh modules for state activity
2019-05-09 06:18:18,075 [salt.state       :1780][INFO    ][12161] Running state [maas-region-controller] at time 06:18:18.075612
2019-05-09 06:18:18,075 [salt.state       :1813][INFO    ][12161] Executing state pkg.installed for [maas-region-controller]
2019-05-09 06:18:18,076 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-09 06:18:18,188 [salt.state       :300 ][INFO    ][12161] All specified packages are already installed
2019-05-09 06:18:18,188 [salt.state       :1951][INFO    ][12161] Completed state [maas-region-controller] at time 06:18:18.188554 duration_in_ms=112.941
2019-05-09 06:18:18,189 [salt.state       :1780][INFO    ][12161] Running state [python-oauth] at time 06:18:18.189029
2019-05-09 06:18:18,189 [salt.state       :1813][INFO    ][12161] Executing state pkg.installed for [python-oauth]
2019-05-09 06:18:18,199 [salt.state       :300 ][INFO    ][12161] All specified packages are already installed
2019-05-09 06:18:18,200 [salt.state       :1951][INFO    ][12161] Completed state [python-oauth] at time 06:18:18.200006 duration_in_ms=10.978
2019-05-09 06:18:18,204 [salt.state       :1780][INFO    ][12161] Running state [/etc/maas/regiond.conf] at time 06:18:18.204400
2019-05-09 06:18:18,204 [salt.state       :1813][INFO    ][12161] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-09 06:18:18,256 [salt.state       :300 ][INFO    ][12161] No changes needed to be made
2019-05-09 06:18:18,256 [salt.state       :1951][INFO    ][12161] Completed state [/etc/maas/regiond.conf] at time 06:18:18.256378 duration_in_ms=51.978
2019-05-09 06:18:18,257 [salt.state       :1780][INFO    ][12161] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:18:18.257090
2019-05-09 06:18:18,257 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-09 06:18:18,333 [salt.state       :300 ][INFO    ][12161] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-09 06:18:18,333 [salt.state       :1951][INFO    ][12161] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 06:18:18.333382 duration_in_ms=76.292
2019-05-09 06:18:18,334 [salt.state       :1780][INFO    ][12161] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:18:18.334045
2019-05-09 06:18:18,334 [salt.state       :1813][INFO    ][12161] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-09 06:18:18,348 [salt.state       :300 ][INFO    ][12161] No changes needed to be made
2019-05-09 06:18:18,348 [salt.state       :1951][INFO    ][12161] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:18:18.348796 duration_in_ms=14.752
2019-05-09 06:18:18,349 [salt.state       :1780][INFO    ][12161] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:18:18.349402
2019-05-09 06:18:18,349 [salt.state       :1813][INFO    ][12161] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-09 06:18:18,372 [salt.state       :300 ][INFO    ][12161] No changes needed to be made
2019-05-09 06:18:18,372 [salt.state       :1951][INFO    ][12161] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 06:18:18.372690 duration_in_ms=23.287
2019-05-09 06:18:18,373 [salt.state       :1780][INFO    ][12161] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:18:18.373305
2019-05-09 06:18:18,373 [salt.state       :1813][INFO    ][12161] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-09 06:18:18,411 [salt.state       :300 ][INFO    ][12161] No changes needed to be made
2019-05-09 06:18:18,413 [salt.state       :1951][INFO    ][12161] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 06:18:18.413209 duration_in_ms=39.896
2019-05-09 06:18:18,414 [salt.state       :1780][INFO    ][12161] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:18:18.414742
2019-05-09 06:18:18,415 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-09 06:18:18,431 [salt.state       :300 ][INFO    ][12161] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-09 06:18:18,432 [salt.state       :1951][INFO    ][12161] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 06:18:18.432071 duration_in_ms=17.329
2019-05-09 06:18:18,436 [salt.state       :1780][INFO    ][12161] Running state [a2enmod headers] at time 06:18:18.436799
2019-05-09 06:18:18,437 [salt.state       :1813][INFO    ][12161] Executing state cmd.run for [a2enmod headers]
2019-05-09 06:18:18,438 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command 'a2enmod headers' in directory '/root'
2019-05-09 06:18:18,494 [salt.state       :300 ][INFO    ][12161] {'pid': 12180, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-09 06:18:18,495 [salt.state       :1951][INFO    ][12161] Completed state [a2enmod headers] at time 06:18:18.495261 duration_in_ms=58.461
2019-05-09 06:18:18,495 [salt.state       :1780][INFO    ][12161] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:18:18.495819
2019-05-09 06:18:18,496 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-09 06:18:18,514 [salt.state       :300 ][INFO    ][12161] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-09 06:18:18,515 [salt.state       :1951][INFO    ][12161] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 06:18:18.514951 duration_in_ms=19.132
2019-05-09 06:18:18,515 [salt.state       :1780][INFO    ][12161] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:18:18.515772
2019-05-09 06:18:18,516 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-09 06:18:18,604 [salt.state       :300 ][INFO    ][12161] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-09 06:18:18,605 [salt.state       :1951][INFO    ][12161] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 06:18:18.605052 duration_in_ms=89.279
2019-05-09 06:18:18,605 [salt.state       :1780][INFO    ][12161] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:18:18.605895
2019-05-09 06:18:18,606 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-09 06:18:18,676 [salt.state       :300 ][INFO    ][12161] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-09 06:18:18,676 [salt.state       :1951][INFO    ][12161] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 06:18:18.676632 duration_in_ms=70.737
2019-05-09 06:18:18,677 [salt.state       :1780][INFO    ][12161] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:18:18.677286
2019-05-09 06:18:18,677 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-09 06:18:18,753 [salt.state       :300 ][INFO    ][12161] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-09 06:18:18,754 [salt.state       :1951][INFO    ][12161] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 06:18:18.754161 duration_in_ms=76.876
2019-05-09 06:18:18,754 [salt.state       :1780][INFO    ][12161] Running state [/root/.pgpass] at time 06:18:18.754452
2019-05-09 06:18:18,754 [salt.state       :1813][INFO    ][12161] Executing state file.managed for [/root/.pgpass]
2019-05-09 06:18:18,808 [salt.state       :300 ][INFO    ][12161] File /root/.pgpass is in the correct state
2019-05-09 06:18:18,808 [salt.state       :1951][INFO    ][12161] Completed state [/root/.pgpass] at time 06:18:18.808405 duration_in_ms=53.952
2019-05-09 06:18:18,817 [salt.state       :1780][INFO    ][12161] Running state [maas-region syncdb --noinput] at time 06:18:18.816992
2019-05-09 06:18:18,817 [salt.state       :1813][INFO    ][12161] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-09 06:18:18,818 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-09 06:18:20,873 [salt.state       :300 ][INFO    ][12161] {'pid': 12194, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: maasserver, metadataserver, contenttypes, sessions, auth, piston3, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-09 06:18:20,873 [salt.state       :1951][INFO    ][12161] Completed state [maas-region syncdb --noinput] at time 06:18:20.873854 duration_in_ms=2056.861
2019-05-09 06:18:20,874 [salt.state       :2022][WARNING ][12161] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-09 06:18:20,877 [salt.state       :1780][INFO    ][12161] Running state [maas-regiond] at time 06:18:20.877101
2019-05-09 06:18:20,877 [salt.state       :1813][INFO    ][12161] Executing state service.running for [maas-regiond]
2019-05-09 06:18:20,879 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:20,923 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-09 06:18:20,942 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-09 06:18:20,961 [salt.state       :300 ][INFO    ][12161] The service maas-regiond is already running
2019-05-09 06:18:20,962 [salt.state       :1951][INFO    ][12161] Completed state [maas-regiond] at time 06:18:20.961893 duration_in_ms=84.792
2019-05-09 06:18:20,964 [salt.state       :1780][INFO    ][12161] Running state [bind9] at time 06:18:20.964546
2019-05-09 06:18:20,965 [salt.state       :1813][INFO    ][12161] Executing state service.running for [bind9]
2019-05-09 06:18:20,966 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:20,985 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-09 06:18:21,003 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-09 06:18:21,020 [salt.state       :300 ][INFO    ][12161] The service bind9 is already running
2019-05-09 06:18:21,021 [salt.state       :1951][INFO    ][12161] Completed state [bind9] at time 06:18:21.021057 duration_in_ms=56.511
2019-05-09 06:18:21,023 [salt.state       :1780][INFO    ][12161] Running state [apache2] at time 06:18:21.023403
2019-05-09 06:18:21,023 [salt.state       :1813][INFO    ][12161] Executing state service.running for [apache2]
2019-05-09 06:18:21,024 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-09 06:18:21,041 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-09 06:18:21,059 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-09 06:18:21,082 [salt.state       :300 ][INFO    ][12161] The service apache2 is already running
2019-05-09 06:18:21,082 [salt.state       :1951][INFO    ][12161] Completed state [apache2] at time 06:18:21.082480 duration_in_ms=59.077
2019-05-09 06:18:21,084 [salt.state       :1780][INFO    ][12161] Running state [maasng.wait_for_http_code] at time 06:18:21.084698
2019-05-09 06:18:21,085 [salt.state       :1813][INFO    ][12161] Executing state module.run for [maasng.wait_for_http_code]
2019-05-09 06:18:21,085 [salt.utils.decorators:613 ][WARNING ][12161] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:18:21,204 [salt.state       :300 ][INFO    ][12161] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-09 06:18:21,205 [salt.state       :1951][INFO    ][12161] Completed state [maasng.wait_for_http_code] at time 06:18:21.205121 duration_in_ms=120.423
2019-05-09 06:18:21,206 [salt.state       :1780][INFO    ][12161] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:18:21.206156
2019-05-09 06:18:21,206 [salt.state       :1813][INFO    ][12161] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-09 06:18:21,207 [salt.state       :300 ][INFO    ][12161] /var/lib/maas/.setup_admin exists
2019-05-09 06:18:21,207 [salt.state       :1951][INFO    ][12161] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 06:18:21.207404 duration_in_ms=1.249
2019-05-09 06:18:21,208 [salt.state       :1780][INFO    ][12161] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:21.208272
2019-05-09 06:18:21,208 [salt.state       :1813][INFO    ][12161] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:18:21,209 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12161] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:18:22,690 [salt.state       :300 ][INFO    ][12161] {'pid': 12245, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:18:22,691 [salt.state       :1951][INFO    ][12161] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:22.691466 duration_in_ms=1483.193
2019-05-09 06:18:22,700 [salt.state       :1780][INFO    ][12161] Running state [maas_region_boot_source_resources_mirror] at time 06:18:22.700290
2019-05-09 06:18:22,700 [salt.state       :1813][INFO    ][12161] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-09 06:18:22,803 [salt.state       :300 ][INFO    ][12161] {'changes': {}}
2019-05-09 06:18:22,803 [salt.state       :1951][INFO    ][12161] Completed state [maas_region_boot_source_resources_mirror] at time 06:18:22.803809 duration_in_ms=103.519
2019-05-09 06:18:22,805 [salt.state       :1780][INFO    ][12161] Running state [maasng.boot_resources_import] at time 06:18:22.804962
2019-05-09 06:18:22,805 [salt.state       :1813][INFO    ][12161] Executing state module.run for [maasng.boot_resources_import]
2019-05-09 06:18:22,806 [salt.utils.decorators:613 ][WARNING ][12161] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:18:22,924 [salt.loaded.ext.module.maasng:1600][INFO    ][12161] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-09 06:18:27,985 [salt.loaded.ext.module.maasng:1600][INFO    ][12161] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-09 06:18:31,678 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061831665195
2019-05-09 06:18:31,701 [salt.minion      :1432][INFO    ][12292] Starting a new job with PID 12292
2019-05-09 06:18:31,723 [salt.minion      :1711][INFO    ][12292] Returning information for job: 20190509061831665195
2019-05-09 06:18:33,051 [salt.loaded.ext.module.maasng:1600][INFO    ][12161] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-09 06:18:38,159 [salt.state       :300 ][INFO    ][12161] {'ret': True}
2019-05-09 06:18:38,160 [salt.state       :1951][INFO    ][12161] Completed state [maasng.boot_resources_import] at time 06:18:38.160247 duration_in_ms=15355.282
2019-05-09 06:18:38,161 [salt.state       :1780][INFO    ][12161] Running state [maas_region_boot_sources_selection_xenial] at time 06:18:38.161503
2019-05-09 06:18:38,162 [salt.state       :1813][INFO    ][12161] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-09 06:18:38,362 [salt.state       :300 ][INFO    ][12161] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-09 06:18:38,363 [salt.state       :1951][INFO    ][12161] Completed state [maas_region_boot_sources_selection_xenial] at time 06:18:38.363258 duration_in_ms=201.754
2019-05-09 06:18:38,364 [salt.state       :1780][INFO    ][12161] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 06:18:38.364562
2019-05-09 06:18:38,365 [salt.state       :1813][INFO    ][12161] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-09 06:18:38,365 [salt.utils.decorators:613 ][WARNING ][12161] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:18:38,366 [salt.loaded.ext.module.maasng:1771][INFO    ][12161] boot-sources sync initiated for ALL Rack's
2019-05-09 06:18:39,410 [salt.state       :300 ][INFO    ][12161] {'ret': True}
2019-05-09 06:18:39,411 [salt.state       :1951][INFO    ][12161] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 06:18:39.411175 duration_in_ms=1046.612
2019-05-09 06:18:39,413 [salt.state       :1780][INFO    ][12161] Running state [maas.process_maas_config] at time 06:18:39.413343
2019-05-09 06:18:39,413 [salt.state       :1813][INFO    ][12161] Executing state module.run for [maas.process_maas_config]
2019-05-09 06:18:39,414 [salt.utils.decorators:613 ][WARNING ][12161] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:18:39,415 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=enable_http_proxy value=True
2019-05-09 06:18:39,479 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=upstream_dns value=8.8.8.8
2019-05-09 06:18:39,549 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=commissioning_distro_series value=xenial
2019-05-09 06:18:39,614 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=default_osystem value=ubuntu
2019-05-09 06:18:39,674 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=active_discovery_interval value=600
2019-05-09 06:18:39,734 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=dnssec_validation value=no
2019-05-09 06:18:39,801 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=maas_name value=mas01
2019-05-09 06:18:39,854 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=network_discovery value=enabled
2019-05-09 06:18:39,962 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=enable_third_party_drivers value=True
2019-05-09 06:18:40,028 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=default_storage_layout value=lvm
2019-05-09 06:18:42,408 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=ntp_external_only value=True
2019-05-09 06:18:42,465 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-09 06:18:42,521 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=default_distro_series value=xenial
2019-05-09 06:18:42,579 [salt.loaded.ext.module.maas:92  ][INFO    ][12161] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-05-09 06:18:42,717 [salt.state       :300 ][INFO    ][12161] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-09 06:18:42,717 [salt.state       :1951][INFO    ][12161] Completed state [maas.process_maas_config] at time 06:18:42.717673 duration_in_ms=3304.328
2019-05-09 06:18:42,718 [salt.state       :1780][INFO    ][12161] Running state [pxe_admin] at time 06:18:42.718767
2019-05-09 06:18:42,719 [salt.state       :1813][INFO    ][12161] Executing state maasng.fabric_present for [pxe_admin]
2019-05-09 06:18:42,794 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'gwcp8d', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-09 06:18:42,860 [salt.loaded.ext.module.maasng:1008][WARNING ][12161] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-09 06:18:42,860 [salt.loaded.ext.module.maasng:1011][WARNING ][12161] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-09 06:18:42,921 [salt.state       :300 ][INFO    ][12161] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-09 06:18:42,921 [salt.state       :1951][INFO    ][12161] Completed state [pxe_admin] at time 06:18:42.921341 duration_in_ms=202.574
2019-05-09 06:18:42,921 [salt.state       :1780][INFO    ][12161] Running state [vlan 0] at time 06:18:42.921804
2019-05-09 06:18:42,922 [salt.state       :1813][INFO    ][12161] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-09 06:18:42,986 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-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': True, u'mtu': 1500, u'primary_rack': u'gwcp8d', 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/'}]
2019-05-09 06:18:43,105 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'gwcp8d', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-09 06:18:43,399 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-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': True, u'mtu': 1500, u'primary_rack': u'gwcp8d', 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/'}]
2019-05-09 06:18:43,497 [salt.state       :300 ][INFO    ][12161] {'new': 'Vlan untagged was updated'}
2019-05-09 06:18:43,498 [salt.state       :1951][INFO    ][12161] Completed state [vlan 0] at time 06:18:43.498173 duration_in_ms=576.367
2019-05-09 06:18:43,500 [salt.state       :1780][INFO    ][12161] Running state [192.168.11.0/24] at time 06:18:43.499982
2019-05-09 06:18:43,500 [salt.state       :1813][INFO    ][12161] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-09 06:18:43,710 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-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'gwcp8d', 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/'}]
2019-05-09 06:18:43,711 [salt.loaded.ext.module.maasng:1235][WARNING ][12161] Ignoring parameter vlan:0
2019-05-09 06:18:43,783 [salt.state       :300 ][INFO    ][12161] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-09 06:18:43,783 [salt.state       :1951][INFO    ][12161] Completed state [192.168.11.0/24] at time 06:18:43.783913 duration_in_ms=283.931
2019-05-09 06:18:43,785 [salt.state       :1780][INFO    ][12161] Running state [maas_create_iprange_1] at time 06:18:43.785118
2019-05-09 06:18:43,785 [salt.state       :1813][INFO    ][12161] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-09 06:18:43,854 [salt.state       :300 ][INFO    ][12161] Iprange maas_create_iprange_1 already exist.
2019-05-09 06:18:43,855 [salt.state       :1951][INFO    ][12161] Completed state [maas_create_iprange_1] at time 06:18:43.855172 duration_in_ms=70.053
2019-05-09 06:18:43,855 [salt.state       :1780][INFO    ][12161] Running state [vlan 0] at time 06:18:43.855477
2019-05-09 06:18:43,855 [salt.state       :1813][INFO    ][12161] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-09 06:18:43,896 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'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'gwcp8d', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-09 06:18:43,992 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'gwcp8d', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-09 06:18:44,244 [salt.loaded.ext.module.maasng:945 ][INFO    ][12161] [{u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'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'gwcp8d', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-09 06:18:44,340 [salt.state       :300 ][INFO    ][12161] {'new': 'Vlan untagged was updated'}
2019-05-09 06:18:44,340 [salt.state       :1951][INFO    ][12161] Completed state [vlan 0] at time 06:18:44.340840 duration_in_ms=485.362
2019-05-09 06:18:44,341 [salt.state       :1780][INFO    ][12161] Running state [opnfv] at time 06:18:44.341623
2019-05-09 06:18:44,342 [salt.state       :1813][INFO    ][12161] Executing state maasng.sshkey_present for [opnfv]
2019-05-09 06:18:44,393 [salt.loaded.ext.module.maasng:1903][INFO    ][12161] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-05-09 06:18:44,394 [salt.state       :300 ][INFO    ][12161] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-09 06:18:44,394 [salt.state       :1951][INFO    ][12161] Completed state [opnfv] at time 06:18:44.394317 duration_in_ms=52.693
2019-05-09 06:18:44,398 [salt.minion      :1711][INFO    ][12161] Returning information for job: 20190509061816628910
2019-05-09 06:18:44,913 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509061844901699
2019-05-09 06:18:44,931 [salt.minion      :1432][INFO    ][12654] Starting a new job with PID 12654
2019-05-09 06:18:48,399 [salt.state       :915 ][INFO    ][12654] Loading fresh modules for state activity
2019-05-09 06:18:48,492 [salt.state       :1780][INFO    ][12654] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:48.492878
2019-05-09 06:18:48,493 [salt.state       :1813][INFO    ][12654] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:18:48,495 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12654] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:18:49,868 [salt.state       :300 ][INFO    ][12654] {'pid': 12678, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:18:49,869 [salt.state       :1951][INFO    ][12654] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:18:49.868967 duration_in_ms=1376.09
2019-05-09 06:18:49,870 [salt.state       :1780][INFO    ][12654] Running state [maas.process_machines] at time 06:18:49.870071
2019-05-09 06:18:49,870 [salt.state       :1813][INFO    ][12654] Executing state module.run for [maas.process_machines]
2019-05-09 06:18:49,870 [salt.utils.decorators:613 ][WARNING ][12654] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:18:50,483 [salt.loaded.ext.module.maas:412 ][WARNING ][12654] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:18:50,484 [salt.loaded.ext.module.maas:92  ][INFO    ][12654] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=grc7fe architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:18:51,767 [salt.loaded.ext.module.maas:412 ][WARNING ][12654] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:18:51,767 [salt.loaded.ext.module.maas:92  ][INFO    ][12654] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=myr4rf architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:18:52,737 [salt.loaded.ext.module.maas:412 ][WARNING ][12654] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:18:52,738 [salt.loaded.ext.module.maas:92  ][INFO    ][12654] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=pwracg architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:18:54,036 [salt.loaded.ext.module.maas:412 ][WARNING ][12654] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:18:54,037 [salt.loaded.ext.module.maas:92  ][INFO    ][12654] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=msec67 architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:18:55,109 [salt.loaded.ext.module.maas:412 ][WARNING ][12654] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:18:55,110 [salt.loaded.ext.module.maas:92  ][INFO    ][12654] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=ncwcww architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:18:56,386 [salt.state       :300 ][INFO    ][12654] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-09 06:18:56,387 [salt.state       :1951][INFO    ][12654] Completed state [maas.process_machines] at time 06:18:56.386921 duration_in_ms=6516.847
2019-05-09 06:18:56,390 [salt.minion      :1711][INFO    ][12654] Returning information for job: 20190509061844901699
2019-05-09 06:19:27,431 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509061927417791
2019-05-09 06:19:27,452 [salt.minion      :1432][INFO    ][12941] Starting a new job with PID 12941
2019-05-09 06:19:31,201 [salt.state       :915 ][INFO    ][12941] Loading fresh modules for state activity
2019-05-09 06:19:31,292 [salt.state       :1780][INFO    ][12941] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:19:31.292816
2019-05-09 06:19:31,293 [salt.state       :1813][INFO    ][12941] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:19:31,295 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12941] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:19:32,765 [salt.state       :300 ][INFO    ][12941] {'pid': 12949, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:19:32,766 [salt.state       :1951][INFO    ][12941] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:19:32.766200 duration_in_ms=1473.385
2019-05-09 06:19:32,767 [salt.state       :1780][INFO    ][12941] Running state [maas.wait_for_machine_status] at time 06:19:32.767718
2019-05-09 06:19:32,767 [salt.state       :1813][INFO    ][12941] Executing state module.run for [maas.wait_for_machine_status]
2019-05-09 06:19:32,768 [salt.utils.decorators:613 ][WARNING ][12941] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:19:35,464 [salt.loaded.ext.module.maas:981 ][INFO    ][12941] Machine msec67 deleted
2019-05-09 06:19:36,379 [salt.loaded.ext.module.maas:412 ][WARNING ][12941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:19:36,380 [salt.loaded.ext.module.maas:92  ][INFO    ][12941] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=grc7fe architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:19:37,598 [salt.loaded.ext.module.maas:412 ][WARNING ][12941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:19:37,598 [salt.loaded.ext.module.maas:92  ][INFO    ][12941] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=myr4rf architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:19:38,776 [salt.loaded.ext.module.maas:412 ][WARNING ][12941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:19:38,777 [salt.loaded.ext.module.maas:92  ][INFO    ][12941] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=pwracg architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:19:40,064 [salt.loaded.ext.module.maas:412 ][WARNING ][12941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:19:40,065 [salt.loaded.ext.module.maas:92  ][INFO    ][12941] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:19:41,496 [salt.loaded.ext.module.maas:412 ][WARNING ][12941] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-09 06:19:41,497 [salt.loaded.ext.module.maas:92  ][INFO    ][12941] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=ncwcww architecture=amd64/generic power_parameters_power_user=admin
2019-05-09 06:19:42,489 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509061942476478
2019-05-09 06:19:42,512 [salt.minion      :1432][INFO    ][13205] Starting a new job with PID 13205
2019-05-09 06:19:42,536 [salt.minion      :1711][INFO    ][13205] Returning information for job: 20190509061942476478
2019-05-09 06:19:43,308 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1489.46458101s left)
2019-05-09 06:20:12,536 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062012523427
2019-05-09 06:20:12,558 [salt.minion      :1432][INFO    ][13232] Starting a new job with PID 13232
2019-05-09 06:20:12,583 [salt.minion      :1711][INFO    ][13232] Returning information for job: 20190509062012523427
2019-05-09 06:20:16,267 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1456.50542188s left)
2019-05-09 06:20:42,626 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062042613201
2019-05-09 06:20:42,647 [salt.minion      :1432][INFO    ][13308] Starting a new job with PID 13308
2019-05-09 06:20:42,670 [salt.minion      :1711][INFO    ][13308] Returning information for job: 20190509062042613201
2019-05-09 06:20:48,969 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1423.80395389s left)
2019-05-09 06:21:12,669 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062112656392
2019-05-09 06:21:12,692 [salt.minion      :1432][INFO    ][13329] Starting a new job with PID 13329
2019-05-09 06:21:12,717 [salt.minion      :1711][INFO    ][13329] Returning information for job: 20190509062112656392
2019-05-09 06:21:21,436 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1391.33633184s left)
2019-05-09 06:21:42,711 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062142699446
2019-05-09 06:21:42,733 [salt.minion      :1432][INFO    ][13447] Starting a new job with PID 13447
2019-05-09 06:21:42,754 [salt.minion      :1711][INFO    ][13447] Returning information for job: 20190509062142699446
2019-05-09 06:21:53,994 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1358.7786119s left)
2019-05-09 06:22:12,764 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062212751107
2019-05-09 06:22:12,787 [salt.minion      :1432][INFO    ][13495] Starting a new job with PID 13495
2019-05-09 06:22:12,810 [salt.minion      :1711][INFO    ][13495] Returning information for job: 20190509062212751107
2019-05-09 06:22:26,674 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1326.09847689s left)
2019-05-09 06:22:42,820 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062242807540
2019-05-09 06:22:42,843 [salt.minion      :1432][INFO    ][13665] Starting a new job with PID 13665
2019-05-09 06:22:42,868 [salt.minion      :1711][INFO    ][13665] Returning information for job: 20190509062242807540
2019-05-09 06:22:59,553 [salt.loaded.ext.module.maas:1023][INFO    ][12941] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1293.219666s left)
2019-05-09 06:23:12,885 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062312870430
2019-05-09 06:23:12,907 [salt.minion      :1432][INFO    ][13726] Starting a new job with PID 13726
2019-05-09 06:23:12,930 [salt.minion      :1711][INFO    ][13726] Returning information for job: 20190509062312870430
2019-05-09 06:23:32,554 [salt.state       :300 ][INFO    ][12941] {'ret': True}
2019-05-09 06:23:32,555 [salt.state       :1951][INFO    ][12941] Completed state [maas.wait_for_machine_status] at time 06:23:32.554998 duration_in_ms=239787.277
2019-05-09 06:23:32,558 [salt.minion      :1711][INFO    ][12941] Returning information for job: 20190509061927417791
2019-05-09 06:23:33,190 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509062333180868
2019-05-09 06:23:33,212 [salt.minion      :1432][INFO    ][13796] Starting a new job with PID 13796
2019-05-09 06:23:36,918 [salt.state       :915 ][INFO    ][13796] Loading fresh modules for state activity
2019-05-09 06:23:36,959 [salt.fileclient  :1219][INFO    ][13796] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-09 06:23:37,027 [salt.state       :1780][INFO    ][13796] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:23:37.027120
2019-05-09 06:23:37,027 [salt.state       :1813][INFO    ][13796] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:23:37,028 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13796] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:23:38,239 [salt.state       :300 ][INFO    ][13796] {'pid': 13803, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:23:38,239 [salt.state       :1951][INFO    ][13796] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:23:38.239658 duration_in_ms=1212.538
2019-05-09 06:23:38,240 [salt.state       :1780][INFO    ][13796] Running state [maas_machines_storage_cmp002_lvm] at time 06:23:38.240899
2019-05-09 06:23:38,241 [salt.state       :1813][INFO    ][13796] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-09 06:23:39,037 [salt.loaded.ext.module.maasng:610 ][INFO    ][13796] grc7fe
2019-05-09 06:23:39,037 [salt.loaded.ext.module.maasng:626 ][INFO    ][13796] sda
2019-05-09 06:23:39,589 [salt.loaded.ext.module.maasng:361 ][INFO    ][13796] grc7fe
2019-05-09 06:23:39,698 [salt.loaded.ext.module.maasng:367 ][INFO    ][13796] [{u'size': 2397998940160, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'38f461fd-5a84-4bb4-a80c-76f044610fc1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'grc7fe', u'device_id': 2, u'filesystem': {u'uuid': u'098e03b7-42e6-4919-8a5f-b134f240d683', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/partition/2'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'grc7fe', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'type': u'physical', u'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/'}, {u'size': 2397988454400, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'uuid': u'ae1ca148-ae7b-4490-8484-d77991196a40', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'grc7fe', u'partition_table_type': None, u'filesystem': {u'uuid': u'4a079697-f141-4bdd-bc18-2d3eb761416d', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'type': u'virtual', u'id': 7, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/7/'}]
2019-05-09 06:23:39,699 [salt.loaded.ext.module.maasng:632 ][INFO    ][13796] vgroot
2019-05-09 06:23:39,699 [salt.loaded.ext.module.maasng:635 ][INFO    ][13796] lvroot
2019-05-09 06:23:39,699 [salt.loaded.ext.module.maasng:639 ][INFO    ][13796] 107374182400
2019-05-09 06:23:40,221 [salt.loaded.ext.module.maasng:645 ][INFO    ][13796] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [], u'storage_test_status_name': u'Passed', u'owner_data': {}, u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'126bc7b8-92fd-4bca-91e9-28c725beea64', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'grc7fe', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'743e5ce4-e44f-4adc-bb6a-f3d4cde96757', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'grc7fe', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/', u'type': u'physical', u'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'20b55f25-b0a9-490c-9b96-ed5421edee03', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'30d14009-aef0-4c34-a7d2-61ae4791c865', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'grc7fe', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/12/', u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'grc7fe', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'block_size': 4096, u'uuid': u'20b55f25-b0a9-490c-9b96-ed5421edee03', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'30d14009-aef0-4c34-a7d2-61ae4791c865', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'grc7fe', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/12/', u'type': u'virtual', u'id': 12, u'serial': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'126bc7b8-92fd-4bca-91e9-28c725beea64', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'grc7fe', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'743e5ce4-e44f-4adc-bb6a-f3d4cde96757', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'grc7fe', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/', u'type': u'physical', u'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'grc7fe', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'126bc7b8-92fd-4bca-91e9-28c725beea64', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'grc7fe', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'743e5ce4-e44f-4adc-bb6a-f3d4cde96757', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/partition/6'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'grc7fe', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/blockdevices/2/', u'type': u'physical', u'id': 2, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'gwcp8d', 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'dhcp', u'id': 23}], u'tags': [], u'enabled': True, 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'gwcp8d', 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'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'system_id': u'grc7fe', u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 24}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 12, u'discovered': None, u'parents': [], u'system_id': u'grc7fe', u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/interfaces/12/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 25}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 13, u'discovered': None, u'parents': [], u'system_id': u'grc7fe', u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/interfaces/13/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 26}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 14, u'discovered': None, u'parents': [], u'system_id': u'grc7fe', u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/interfaces/14/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'gwcp8d', 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'dhcp', u'id': 23}], u'tags': [], u'enabled': True, 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'gwcp8d', 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'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'system_id': u'grc7fe', u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/grc7fe/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/grc7fe/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-05-09 06:23:40,223 [salt.state       :300 ][INFO    ][13796] {'new': {'storage_layout': 'lvm'}}
2019-05-09 06:23:40,224 [salt.state       :1951][INFO    ][13796] Completed state [maas_machines_storage_cmp002_lvm] at time 06:23:40.223992 duration_in_ms=1983.091
2019-05-09 06:23:40,224 [salt.state       :1780][INFO    ][13796] Running state [maas_machines_storage_cmp001_lvm] at time 06:23:40.224580
2019-05-09 06:23:40,225 [salt.state       :1813][INFO    ][13796] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-09 06:23:41,321 [salt.loaded.ext.module.maasng:610 ][INFO    ][13796] myr4rf
2019-05-09 06:23:41,322 [salt.loaded.ext.module.maasng:626 ][INFO    ][13796] sda
2019-05-09 06:23:41,834 [salt.loaded.ext.module.maasng:361 ][INFO    ][13796] myr4rf
2019-05-09 06:23:41,951 [salt.loaded.ext.module.maasng:367 ][INFO    ][13796] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'74de07e2-3b65-44d1-a4b5-57c62b1cc224', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myr4rf', u'device_id': 1, u'filesystem': {u'uuid': u'f3764c0f-574a-4a0b-8443-0e1f87fa1144', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'size': 2397992648704}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'myr4rf', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'size': 2397998940160}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'uuid': u'257bf46f-17fc-46ab-a7e5-bbbdaa682874', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'uuid': u'afe13df2-a784-4fc1-ad2e-57ab57512252', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'myr4rf', 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'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/6/', u'used_size': 2397988454400, u'id': 6, u'size': 2397988454400}]
2019-05-09 06:23:41,951 [salt.loaded.ext.module.maasng:632 ][INFO    ][13796] vgroot
2019-05-09 06:23:41,952 [salt.loaded.ext.module.maasng:635 ][INFO    ][13796] lvroot
2019-05-09 06:23:41,952 [salt.loaded.ext.module.maasng:639 ][INFO    ][13796] 107374182400
2019-05-09 06:23:42,336 [salt.loaded.ext.module.maasng:645 ][INFO    ][13796] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [], u'storage_test_status_name': u'Passed', u'owner_data': {}, u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'4aa84906-52b2-4936-aba0-7b03eac7c0bb', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myr4rf', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'd79e1ea4-1b56-46cc-ab86-cd1b451db4a6', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'myr4rf', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/', u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, {u'block_size': 4096, u'uuid': u'9d1099ff-03ba-4e61-a3f5-339022a326cd', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'2fdd90e1-39c5-4bf6-9a77-b0a95568780d', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'myr4rf', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/13/', u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'myr4rf', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'block_size': 4096, u'uuid': u'9d1099ff-03ba-4e61-a3f5-339022a326cd', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'2fdd90e1-39c5-4bf6-9a77-b0a95568780d', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'myr4rf', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/13/', u'type': u'virtual', u'id': 13, u'serial': None, u'size': 107374182400}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'4aa84906-52b2-4936-aba0-7b03eac7c0bb', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myr4rf', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'd79e1ea4-1b56-46cc-ab86-cd1b451db4a6', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'myr4rf', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/', u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'myr4rf', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'4aa84906-52b2-4936-aba0-7b03eac7c0bb', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'myr4rf', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'd79e1ea4-1b56-46cc-ab86-cd1b451db4a6', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/partition/7'}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'myr4rf', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/blockdevices/1/', u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'gwcp8d', 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'dhcp', u'id': 15}], u'tags': [], u'enabled': True, 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'gwcp8d', 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'effective_mtu': 1500, u'id': 5, u'discovered': [], u'parents': [], u'system_id': u'myr4rf', u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 16}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 9, u'discovered': None, u'parents': [], u'system_id': u'myr4rf', u'mac_address': u'00:25:b5:a0:00:5b', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 17}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 10, u'discovered': None, u'parents': [], u'system_id': u'myr4rf', u'mac_address': u'00:25:b5:a0:00:5c', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/interfaces/10/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'enabled': True, 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': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'parents': [], u'system_id': u'myr4rf', u'mac_address': u'00:25:b5:a0:00:5d', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/interfaces/11/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'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'gwcp8d', 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'dhcp', u'id': 15}], u'tags': [], u'enabled': True, 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'gwcp8d', 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'effective_mtu': 1500, u'id': 5, u'discovered': [], u'parents': [], u'system_id': u'myr4rf', u'mac_address': u'00:25:b5:a0:00:5a', u'params': u'', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/myr4rf/interfaces/5/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/myr4rf/', u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-05-09 06:23:42,338 [salt.state       :300 ][INFO    ][13796] {'new': {'storage_layout': 'lvm'}}
2019-05-09 06:23:42,338 [salt.state       :1951][INFO    ][13796] Completed state [maas_machines_storage_cmp001_lvm] at time 06:23:42.338685 duration_in_ms=2114.105
2019-05-09 06:23:42,342 [salt.minion      :1711][INFO    ][13796] Returning information for job: 20190509062333180868
2019-05-09 06:23:42,953 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509062342943233
2019-05-09 06:23:42,974 [salt.minion      :1432][INFO    ][13821] Starting a new job with PID 13821
2019-05-09 06:23:43,725 [salt.state       :915 ][INFO    ][13821] Loading fresh modules for state activity
2019-05-09 06:23:43,778 [salt.fileclient  :1219][INFO    ][13821] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-09 06:23:43,824 [salt.state       :1780][INFO    ][13821] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:23:43.824512
2019-05-09 06:23:43,824 [salt.state       :1813][INFO    ][13821] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:23:43,827 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13821] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:23:45,113 [salt.state       :300 ][INFO    ][13821] {'pid': 13833, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:23:45,113 [salt.state       :1951][INFO    ][13821] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:23:45.113820 duration_in_ms=1289.31
2019-05-09 06:23:45,114 [salt.state       :1780][INFO    ][13821] Running state [maas.deploy_machines] at time 06:23:45.114896
2019-05-09 06:23:45,115 [salt.state       :1813][INFO    ][13821] Executing state module.run for [maas.deploy_machines]
2019-05-09 06:23:45,115 [salt.utils.decorators:613 ][WARNING ][13821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:23:45,726 [salt.loaded.ext.module.maas:684 ][INFO    ][13821] deploymachines hwe_kernel=ga-16.04 system_id=grc7fe distro_series=xenial
2019-05-09 06:23:48,444 [salt.loaded.ext.module.maas:684 ][INFO    ][13821] deploymachines hwe_kernel=ga-16.04 system_id=myr4rf distro_series=xenial
2019-05-09 06:23:51,043 [salt.loaded.ext.module.maas:684 ][INFO    ][13821] deploymachines hwe_kernel=ga-16.04 system_id=pwracg distro_series=xenial
2019-05-09 06:23:53,511 [salt.loaded.ext.module.maas:684 ][INFO    ][13821] deploymachines hwe_kernel=ga-16.04 system_id=sw6qex distro_series=xenial
2019-05-09 06:23:55,725 [salt.loaded.ext.module.maas:684 ][INFO    ][13821] deploymachines hwe_kernel=ga-16.04 system_id=ncwcww distro_series=xenial
2019-05-09 06:23:58,001 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062357988622
2019-05-09 06:23:58,023 [salt.minion      :1432][INFO    ][14097] Starting a new job with PID 14097
2019-05-09 06:23:58,046 [salt.minion      :1711][INFO    ][14097] Returning information for job: 20190509062357988622
2019-05-09 06:23:58,172 [salt.state       :300 ][INFO    ][13821] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-09 06:23:58,172 [salt.state       :1951][INFO    ][13821] Completed state [maas.deploy_machines] at time 06:23:58.172466 duration_in_ms=13057.568
2019-05-09 06:23:58,176 [salt.minion      :1711][INFO    ][13821] Returning information for job: 20190509062342943233
2019-05-09 06:23:58,800 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command state.apply with jid 20190509062358787406
2019-05-09 06:23:58,821 [salt.minion      :1432][INFO    ][14111] Starting a new job with PID 14111
2019-05-09 06:24:02,541 [salt.state       :915 ][INFO    ][14111] Loading fresh modules for state activity
2019-05-09 06:24:02,592 [salt.fileclient  :1219][INFO    ][14111] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-09 06:24:02,633 [salt.state       :1780][INFO    ][14111] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:24:02.633035
2019-05-09 06:24:02,633 [salt.state       :1813][INFO    ][14111] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-09 06:24:02,635 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14111] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-09 06:24:04,047 [salt.state       :300 ][INFO    ][14111] {'pid': 14126, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-09 06:24:04,048 [salt.state       :1951][INFO    ][14111] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 06:24:04.048219 duration_in_ms=1415.185
2019-05-09 06:24:04,049 [salt.state       :1780][INFO    ][14111] Running state [maas.wait_for_machine_status] at time 06:24:04.049749
2019-05-09 06:24:04,049 [salt.state       :1813][INFO    ][14111] Executing state module.run for [maas.wait_for_machine_status]
2019-05-09 06:24:04,050 [salt.utils.decorators:613 ][WARNING ][14111] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-09 06:24:07,020 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.03449583s left)
2019-05-09 06:24:13,827 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062413815704
2019-05-09 06:24:13,850 [salt.minion      :1432][INFO    ][14147] Starting a new job with PID 14147
2019-05-09 06:24:13,871 [salt.minion      :1711][INFO    ][14147] Returning information for job: 20190509062413815704
2019-05-09 06:24:40,109 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.94502187s left)
2019-05-09 06:24:43,876 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062443865034
2019-05-09 06:24:43,894 [salt.minion      :1432][INFO    ][14198] Starting a new job with PID 14198
2019-05-09 06:24:43,914 [salt.minion      :1711][INFO    ][14198] Returning information for job: 20190509062443865034
2019-05-09 06:25:13,039 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2181.01526904s left)
2019-05-09 06:25:13,964 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062513951479
2019-05-09 06:25:13,985 [salt.minion      :1432][INFO    ][14303] Starting a new job with PID 14303
2019-05-09 06:25:14,009 [salt.minion      :1711][INFO    ][14303] Returning information for job: 20190509062513951479
2019-05-09 06:25:44,008 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062544001224
2019-05-09 06:25:44,027 [salt.minion      :1432][INFO    ][14468] Starting a new job with PID 14468
2019-05-09 06:25:44,041 [salt.minion      :1711][INFO    ][14468] Returning information for job: 20190509062544001224
2019-05-09 06:25:45,477 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2148.57750297s left)
2019-05-09 06:26:14,047 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062614034757
2019-05-09 06:26:14,069 [salt.minion      :1432][INFO    ][14638] Starting a new job with PID 14638
2019-05-09 06:26:14,093 [salt.minion      :1711][INFO    ][14638] Returning information for job: 20190509062614034757
2019-05-09 06:26:19,040 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2115.01406693s left)
2019-05-09 06:26:44,102 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062644088024
2019-05-09 06:26:44,124 [salt.minion      :1432][INFO    ][15257] Starting a new job with PID 15257
2019-05-09 06:26:44,145 [salt.minion      :1711][INFO    ][15257] Returning information for job: 20190509062644088024
2019-05-09 06:26:52,160 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.89460182s left)
2019-05-09 06:27:14,155 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062714143242
2019-05-09 06:27:14,177 [salt.minion      :1432][INFO    ][15289] Starting a new job with PID 15289
2019-05-09 06:27:14,200 [salt.minion      :1711][INFO    ][15289] Returning information for job: 20190509062714143242
2019-05-09 06:27:25,589 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2048.46595097s left)
2019-05-09 06:27:44,220 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062744207415
2019-05-09 06:27:44,243 [salt.minion      :1432][INFO    ][15513] Starting a new job with PID 15513
2019-05-09 06:27:44,268 [salt.minion      :1711][INFO    ][15513] Returning information for job: 20190509062744207415
2019-05-09 06:27:58,507 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2015.54702091s left)
2019-05-09 06:28:14,281 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062814268943
2019-05-09 06:28:14,303 [salt.minion      :1432][INFO    ][15553] Starting a new job with PID 15553
2019-05-09 06:28:14,329 [salt.minion      :1711][INFO    ][15553] Returning information for job: 20190509062814268943
2019-05-09 06:28:31,805 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1982.24903202s left)
2019-05-09 06:28:44,356 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062844344270
2019-05-09 06:28:44,378 [salt.minion      :1432][INFO    ][15812] Starting a new job with PID 15812
2019-05-09 06:28:44,402 [salt.minion      :1711][INFO    ][15812] Returning information for job: 20190509062844344270
2019-05-09 06:29:04,991 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1949.06374192s left)
2019-05-09 06:29:14,429 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062914414867
2019-05-09 06:29:14,451 [salt.minion      :1432][INFO    ][15843] Starting a new job with PID 15843
2019-05-09 06:29:14,471 [salt.minion      :1711][INFO    ][15843] Returning information for job: 20190509062914414867
2019-05-09 06:29:38,585 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1915.46934795s left)
2019-05-09 06:29:44,503 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509062944490549
2019-05-09 06:29:44,526 [salt.minion      :1432][INFO    ][16171] Starting a new job with PID 16171
2019-05-09 06:29:44,547 [salt.minion      :1711][INFO    ][16171] Returning information for job: 20190509062944490549
2019-05-09 06:30:12,424 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.63054705s left)
2019-05-09 06:30:14,584 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063014571012
2019-05-09 06:30:14,607 [salt.minion      :1432][INFO    ][16213] Starting a new job with PID 16213
2019-05-09 06:30:14,630 [salt.minion      :1711][INFO    ][16213] Returning information for job: 20190509063014571012
2019-05-09 06:30:44,670 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063044657246
2019-05-09 06:30:44,688 [salt.minion      :1432][INFO    ][16648] Starting a new job with PID 16648
2019-05-09 06:30:44,711 [salt.minion      :1711][INFO    ][16648] Returning information for job: 20190509063044657246
2019-05-09 06:30:45,912 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1848.14277983s left)
2019-05-09 06:31:14,761 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063114748225
2019-05-09 06:31:14,784 [salt.minion      :1432][INFO    ][16680] Starting a new job with PID 16680
2019-05-09 06:31:14,808 [salt.minion      :1711][INFO    ][16680] Returning information for job: 20190509063114748225
2019-05-09 06:31:19,325 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.72981787s left)
2019-05-09 06:31:44,865 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063144853055
2019-05-09 06:31:44,889 [salt.minion      :1432][INFO    ][16792] Starting a new job with PID 16792
2019-05-09 06:31:44,912 [salt.minion      :1711][INFO    ][16792] Returning information for job: 20190509063144853055
2019-05-09 06:31:52,584 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1781.47060585s left)
2019-05-09 06:32:14,978 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063214966334
2019-05-09 06:32:15,000 [salt.minion      :1432][INFO    ][16925] Starting a new job with PID 16925
2019-05-09 06:32:15,022 [salt.minion      :1711][INFO    ][16925] Returning information for job: 20190509063214966334
2019-05-09 06:32:26,131 [salt.loaded.ext.module.maas:1023][INFO    ][14111] Waiting status:Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:2250s (1747.92381787s left)
2019-05-09 06:32:45,058 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command saltutil.find_job with jid 20190509063245045175
2019-05-09 06:32:45,080 [salt.minion      :1432][INFO    ][17183] Starting a new job with PID 17183
2019-05-09 06:32:45,104 [salt.minion      :1711][INFO    ][17183] Returning information for job: 20190509063245045175
2019-05-09 06:32:59,789 [salt.state       :300 ][INFO    ][14111] {'ret': True}
2019-05-09 06:32:59,790 [salt.state       :1951][INFO    ][14111] Completed state [maas.wait_for_machine_status] at time 06:32:59.790232 duration_in_ms=535740.48
2019-05-09 06:32:59,794 [salt.minion      :1711][INFO    ][14111] Returning information for job: 20190509062358787406
2019-05-09 07:08:41,356 [salt.utils.schedule:1377][INFO    ][9675] Running scheduled job: __mine_interval
2019-05-09 08:06:05,361 [salt.minion      :1308][INFO    ][9675] User sudo_ubuntu Executing command cp.push_dir with jid 20190509080605348442
2019-05-09 08:06:05,386 [salt.minion      :1432][INFO    ][23970] Starting a new job with PID 23970
