2019-06-30 06:14:29,460 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-30 06:15:19,510 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-30 06:16:09,555 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-30 06:16:59,595 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-30 06:17:49,632 [salt.minion      :870 ][ERROR   ][362] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-30 06:19:57,356 [salt.utils.decorators:613 ][WARNING ][2703] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 06:19:57,936 [salt.utils.decorators:613 ][WARNING ][2703] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 06:20:00,102 [salt.loaded.int.states.file:2298][WARNING ][2849] 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-06-30 06:20:05,854 [salt.state       :2022][WARNING ][2961] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-30 06:20:08,443 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 06:35:17,215 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:03:51,144 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:18:55,668 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:18:59,661 [salt.loaded.ext.module.maasng:1008][WARNING ][2961] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-30 07:18:59,661 [salt.loaded.ext.module.maasng:1011][WARNING ][2961] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-30 07:19:00,326 [salt.loaded.ext.module.maasng:1235][WARNING ][2961] Ignoring parameter vlan:0
2019-06-30 07:19:01,249 [salt.utils.decorators:613 ][WARNING ][2961] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:19:03,622 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11420] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-30 07:19:03,652 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11420] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-30 07:19:03,671 [salt.utils.parsers:1051][WARNING ][362] Minion received a SIGTERM. Exiting.
2019-06-30 07:19:04,630 [salt.cli.daemons :293 ][INFO    ][11479] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-06-30 07:19:04,720 [salt.cli.daemons :82  ][INFO    ][11479] Starting up the Salt Minion
2019-06-30 07:19:04,721 [salt.utils.event :1017][INFO    ][11479] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-06-30 07:19:05,496 [salt.minion      :976 ][INFO    ][11479] Creating minion process manager
2019-06-30 07:19:06,777 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][11479] Executing command ['date', '+%z'] in directory '/root'
2019-06-30 07:19:06,795 [salt.utils.schedule:568 ][INFO    ][11479] Updating job settings for scheduled job: __mine_interval
2019-06-30 07:19:06,797 [salt.minion      :1108][INFO    ][11479] Added mine.update to scheduler
2019-06-30 07:19:06,801 [salt.minion      :1975][INFO    ][11479] Minion is starting as user 'root'
2019-06-30 07:19:06,810 [salt.minion      :2336][INFO    ][11479] Minion is ready to receive requests!
2019-06-30 07:19:06,959 [salt.utils.decorators:613 ][WARNING ][11411] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:19:07,034 [salt.loaded.ext.module.maas:412 ][WARNING ][11411] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:19:11,933 [salt.loaded.ext.module.maas:412 ][WARNING ][11411] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:19:15,776 [salt.loaded.ext.module.maas:412 ][WARNING ][11411] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:19:17,121 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630071917108475
2019-06-30 07:19:17,140 [salt.minion      :1432][INFO    ][11741] Starting a new job with PID 11741
2019-06-30 07:19:17,166 [salt.minion      :1711][INFO    ][11741] Returning information for job: 20190630071917108475
2019-06-30 07:19:19,249 [salt.loaded.ext.module.maas:412 ][WARNING ][11411] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:19:23,856 [salt.loaded.ext.module.maas:412 ][WARNING ][11411] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:19:59,675 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630071959661776
2019-06-30 07:19:59,698 [salt.minion      :1432][INFO    ][11899] Starting a new job with PID 11899
2019-06-30 07:20:03,462 [salt.state       :915 ][INFO    ][11899] Loading fresh modules for state activity
2019-06-30 07:20:03,510 [salt.fileclient  :1219][INFO    ][11899] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-30 07:20:03,559 [salt.state       :1780][INFO    ][11899] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:20:03.559071
2019-06-30 07:20:03,559 [salt.state       :1813][INFO    ][11899] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:20:03,561 [salt.loaded.int.module.cmdmod:395 ][INFO    ][11899] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:20:04,914 [salt.state       :300 ][INFO    ][11899] {'pid': 11929, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:20:04,915 [salt.state       :1951][INFO    ][11899] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:20:04.915161 duration_in_ms=1356.091
2019-06-30 07:20:04,917 [salt.state       :1780][INFO    ][11899] Running state [maas.wait_for_machine_status] at time 07:20:04.917586
2019-06-30 07:20:04,917 [salt.state       :1813][INFO    ][11899] Executing state module.run for [maas.wait_for_machine_status]
2019-06-30 07:20:04,918 [salt.utils.decorators:613 ][WARNING ][11899] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:20:05,816 [salt.loaded.ext.module.maas:1023][INFO    ][11899] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.11005688s left)
2019-06-30 07:20:14,750 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072014734355
2019-06-30 07:20:14,771 [salt.minion      :1432][INFO    ][12000] Starting a new job with PID 12000
2019-06-30 07:20:14,793 [salt.minion      :1711][INFO    ][12000] Returning information for job: 20190630072014734355
2019-06-30 07:20:44,818 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072044806992
2019-06-30 07:20:44,837 [salt.minion      :1432][INFO    ][12245] Starting a new job with PID 12245
2019-06-30 07:20:44,856 [salt.minion      :1711][INFO    ][12245] Returning information for job: 20190630072044806992
2019-06-30 07:21:14,876 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072114863562
2019-06-30 07:21:14,898 [salt.minion      :1432][INFO    ][12464] Starting a new job with PID 12464
2019-06-30 07:21:14,920 [salt.minion      :1711][INFO    ][12464] Returning information for job: 20190630072114863562
2019-06-30 07:21:44,951 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072144939290
2019-06-30 07:21:44,975 [salt.minion      :1432][INFO    ][12554] Starting a new job with PID 12554
2019-06-30 07:21:44,996 [salt.minion      :1711][INFO    ][12554] Returning information for job: 20190630072144939290
2019-06-30 07:22:15,027 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072215017261
2019-06-30 07:22:15,048 [salt.minion      :1432][INFO    ][12626] Starting a new job with PID 12626
2019-06-30 07:22:15,062 [salt.minion      :1711][INFO    ][12626] Returning information for job: 20190630072215017261
2019-06-30 07:22:45,095 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072245084294
2019-06-30 07:22:45,117 [salt.minion      :1432][INFO    ][12676] Starting a new job with PID 12676
2019-06-30 07:22:45,136 [salt.minion      :1711][INFO    ][12676] Returning information for job: 20190630072245084294
2019-06-30 07:23:15,173 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072315159964
2019-06-30 07:23:15,195 [salt.minion      :1432][INFO    ][12797] Starting a new job with PID 12797
2019-06-30 07:23:15,218 [salt.minion      :1711][INFO    ][12797] Returning information for job: 20190630072315159964
2019-06-30 07:23:45,252 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072345242221
2019-06-30 07:23:45,273 [salt.minion      :1432][INFO    ][12873] Starting a new job with PID 12873
2019-06-30 07:23:45,298 [salt.minion      :1711][INFO    ][12873] Returning information for job: 20190630072345242221
2019-06-30 07:24:15,338 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072415322631
2019-06-30 07:24:15,358 [salt.minion      :1432][INFO    ][12926] Starting a new job with PID 12926
2019-06-30 07:24:15,376 [salt.minion      :1711][INFO    ][12926] Returning information for job: 20190630072415322631
2019-06-30 07:24:45,431 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072445421304
2019-06-30 07:24:45,451 [salt.minion      :1432][INFO    ][12963] Starting a new job with PID 12963
2019-06-30 07:24:45,474 [salt.minion      :1711][INFO    ][12963] Returning information for job: 20190630072445421304
2019-06-30 07:25:15,518 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072515505030
2019-06-30 07:25:15,542 [salt.minion      :1432][INFO    ][13014] Starting a new job with PID 13014
2019-06-30 07:25:15,563 [salt.minion      :1711][INFO    ][13014] Returning information for job: 20190630072515505030
2019-06-30 07:25:45,622 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072545609873
2019-06-30 07:25:45,646 [salt.minion      :1432][INFO    ][13033] Starting a new job with PID 13033
2019-06-30 07:25:45,670 [salt.minion      :1711][INFO    ][13033] Returning information for job: 20190630072545609873
2019-06-30 07:26:15,720 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072615709520
2019-06-30 07:26:15,742 [salt.minion      :1432][INFO    ][13074] Starting a new job with PID 13074
2019-06-30 07:26:15,766 [salt.minion      :1711][INFO    ][13074] Returning information for job: 20190630072615709520
2019-06-30 07:26:36,861 [salt.state       :302 ][ERROR   ][11899] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-06-30 07:26:36,861 [salt.state       :1951][INFO    ][11899] Completed state [maas.wait_for_machine_status] at time 07:26:36.861582 duration_in_ms=391943.994
2019-06-30 07:26:36,865 [salt.minion      :1711][INFO    ][11899] Returning information for job: 20190630071959661776
2019-06-30 07:26:47,622 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command pillar.get with jid 20190630072647609914
2019-06-30 07:26:47,644 [salt.minion      :1432][INFO    ][13372] Starting a new job with PID 13372
2019-06-30 07:26:47,653 [salt.minion      :1711][INFO    ][13372] Returning information for job: 20190630072647609914
2019-06-30 07:26:48,138 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command service.status with jid 20190630072648126266
2019-06-30 07:26:48,159 [salt.minion      :1432][INFO    ][13378] Starting a new job with PID 13378
2019-06-30 07:26:48,551 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13378] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-30 07:26:48,581 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13378] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-30 07:26:48,595 [salt.minion      :1711][INFO    ][13378] Returning information for job: 20190630072648126266
2019-06-30 07:26:49,093 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630072649080370
2019-06-30 07:26:49,112 [salt.minion      :1432][INFO    ][13389] Starting a new job with PID 13389
2019-06-30 07:26:52,707 [salt.state       :915 ][INFO    ][13389] Loading fresh modules for state activity
2019-06-30 07:26:53,134 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:26:53,480 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:26:54,305 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:26:54,660 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:26:56,022 [salt.state       :1780][INFO    ][13389] Running state [salt-minion] at time 07:26:56.022381
2019-06-30 07:26:56,022 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [salt-minion]
2019-06-30 07:26:56,023 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:26:56,105 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,106 [salt.state       :1951][INFO    ][13389] Completed state [salt-minion] at time 07:26:56.106124 duration_in_ms=83.743
2019-06-30 07:26:56,106 [salt.state       :1780][INFO    ][13389] Running state [salt_minion_dependency_packages] at time 07:26:56.106396
2019-06-30 07:26:56,106 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-30 07:26:56,111 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,112 [salt.state       :1951][INFO    ][13389] Completed state [salt_minion_dependency_packages] at time 07:26:56.112039 duration_in_ms=5.642
2019-06-30 07:26:56,114 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/minion.d/minion.conf] at time 07:26:56.114641
2019-06-30 07:26:56,114 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-30 07:26:56,288 [salt.state       :300 ][INFO    ][13389] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-30 07:26:56,288 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/minion.d/minion.conf] at time 07:26:56.288808 duration_in_ms=174.168
2019-06-30 07:26:56,289 [salt.state       :1780][INFO    ][13389] Running state [python-netaddr] at time 07:26:56.289001
2019-06-30 07:26:56,289 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [python-netaddr]
2019-06-30 07:26:56,294 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,294 [salt.state       :1951][INFO    ][13389] Completed state [python-netaddr] at time 07:26:56.294250 duration_in_ms=5.249
2019-06-30 07:26:56,296 [salt.state       :1780][INFO    ][13389] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 07:26:56.296535
2019-06-30 07:26:56,296 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-30 07:26:56,306 [salt.state       :300 ][INFO    ][13389] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-30 07:26:56,306 [salt.state       :1951][INFO    ][13389] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 07:26:56.306372 duration_in_ms=9.836
2019-06-30 07:26:56,307 [salt.state       :1780][INFO    ][13389] Running state [salt-minion] at time 07:26:56.307095
2019-06-30 07:26:56,307 [salt.state       :1813][INFO    ][13389] Executing state service.running for [salt-minion]
2019-06-30 07:26:56,307 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-30 07:26:56,343 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-30 07:26:56,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-30 07:26:56,377 [salt.state       :300 ][INFO    ][13389] The service salt-minion is already running
2019-06-30 07:26:56,377 [salt.state       :1951][INFO    ][13389] Completed state [salt-minion] at time 07:26:56.377805 duration_in_ms=70.708
2019-06-30 07:26:56,379 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains.d] at time 07:26:56.379290
2019-06-30 07:26:56,379 [salt.state       :1813][INFO    ][13389] Executing state file.directory for [/etc/salt/grains.d]
2019-06-30 07:26:56,380 [salt.state       :300 ][INFO    ][13389] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-30 07:26:56,380 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains.d] at time 07:26:56.380807 duration_in_ms=1.517
2019-06-30 07:26:56,381 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains] at time 07:26:56.381451
2019-06-30 07:26:56,381 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/grains]
2019-06-30 07:26:56,382 [salt.state       :300 ][INFO    ][13389] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-30 07:26:56,382 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains] at time 07:26:56.382547 duration_in_ms=1.096
2019-06-30 07:26:56,383 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains.d/placeholder] at time 07:26:56.382998
2019-06-30 07:26:56,383 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-30 07:26:56,383 [salt.state       :300 ][INFO    ][13389] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-30 07:26:56,384 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains.d/placeholder] at time 07:26:56.384016 duration_in_ms=1.018
2019-06-30 07:26:56,384 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains.d/sphinx] at time 07:26:56.384470
2019-06-30 07:26:56,384 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-30 07:26:56,396 [salt.state       :300 ][INFO    ][13389] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-30 07:26:56,396 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains.d/sphinx] at time 07:26:56.396712 duration_in_ms=12.242
2019-06-30 07:26:56,399 [salt.state       :1780][INFO    ][13389] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.398955
2019-06-30 07:26:56,399 [salt.state       :1813][INFO    ][13389] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:26:56,399 [salt.state       :300 ][INFO    ][13389] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:26:56,399 [salt.state       :1951][INFO    ][13389] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.399842 duration_in_ms=0.888
2019-06-30 07:26:56,400 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains.d/dns_records] at time 07:26:56.400311
2019-06-30 07:26:56,400 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-30 07:26:56,414 [salt.state       :300 ][INFO    ][13389] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-30 07:26:56,414 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains.d/dns_records] at time 07:26:56.414382 duration_in_ms=14.071
2019-06-30 07:26:56,415 [salt.state       :1780][INFO    ][13389] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.415257
2019-06-30 07:26:56,415 [salt.state       :1813][INFO    ][13389] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:26:56,415 [salt.state       :300 ][INFO    ][13389] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:26:56,416 [salt.state       :1951][INFO    ][13389] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.416088 duration_in_ms=0.831
2019-06-30 07:26:56,416 [salt.state       :1780][INFO    ][13389] Running state [/etc/salt/grains.d/salt] at time 07:26:56.416544
2019-06-30 07:26:56,416 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-30 07:26:56,426 [salt.state       :300 ][INFO    ][13389] File /etc/salt/grains.d/salt is in the correct state
2019-06-30 07:26:56,426 [salt.state       :1951][INFO    ][13389] Completed state [/etc/salt/grains.d/salt] at time 07:26:56.426335 duration_in_ms=9.79
2019-06-30 07:26:56,427 [salt.state       :1780][INFO    ][13389] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.427222
2019-06-30 07:26:56,427 [salt.state       :1813][INFO    ][13389] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:26:56,427 [salt.state       :300 ][INFO    ][13389] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:26:56,428 [salt.state       :1951][INFO    ][13389] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 07:26:56.428061 duration_in_ms=0.839
2019-06-30 07:26:56,429 [salt.state       :1780][INFO    ][13389] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 07:26:56.429845
2019-06-30 07:26:56,430 [salt.state       :1813][INFO    ][13389] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-30 07:26:56,430 [salt.state       :300 ][INFO    ][13389] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-30 07:26:56,430 [salt.state       :1951][INFO    ][13389] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 07:26:56.430699 duration_in_ms=0.854
2019-06-30 07:26:56,431 [salt.state       :1780][INFO    ][13389] Running state [mine.update] at time 07:26:56.431330
2019-06-30 07:26:56,431 [salt.state       :1813][INFO    ][13389] Executing state module.wait for [mine.update]
2019-06-30 07:26:56,431 [salt.state       :300 ][INFO    ][13389] No changes made for mine.update
2019-06-30 07:26:56,432 [salt.state       :1951][INFO    ][13389] Completed state [mine.update] at time 07:26:56.432115 duration_in_ms=0.785
2019-06-30 07:26:56,432 [salt.state       :1780][INFO    ][13389] Running state [ca-certificates] at time 07:26:56.432354
2019-06-30 07:26:56,432 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [ca-certificates]
2019-06-30 07:26:56,439 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,439 [salt.state       :1951][INFO    ][13389] Completed state [ca-certificates] at time 07:26:56.439620 duration_in_ms=7.266
2019-06-30 07:26:56,440 [salt.state       :1780][INFO    ][13389] Running state [update-ca-certificates] at time 07:26:56.440233
2019-06-30 07:26:56,440 [salt.state       :1813][INFO    ][13389] Executing state cmd.wait for [update-ca-certificates]
2019-06-30 07:26:56,440 [salt.state       :300 ][INFO    ][13389] No changes made for update-ca-certificates
2019-06-30 07:26:56,441 [salt.state       :1951][INFO    ][13389] Completed state [update-ca-certificates] at time 07:26:56.441002 duration_in_ms=0.769
2019-06-30 07:26:56,441 [salt.state       :1780][INFO    ][13389] Running state [iptables] at time 07:26:56.441225
2019-06-30 07:26:56,441 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [iptables]
2019-06-30 07:26:56,447 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,447 [salt.state       :1951][INFO    ][13389] Completed state [iptables] at time 07:26:56.447852 duration_in_ms=6.627
2019-06-30 07:26:56,448 [salt.state       :1780][INFO    ][13389] Running state [iptables-persistent] at time 07:26:56.448086
2019-06-30 07:26:56,448 [salt.state       :1813][INFO    ][13389] Executing state pkg.installed for [iptables-persistent]
2019-06-30 07:26:56,454 [salt.state       :300 ][INFO    ][13389] All specified packages are already installed
2019-06-30 07:26:56,454 [salt.state       :1951][INFO    ][13389] Completed state [iptables-persistent] at time 07:26:56.454537 duration_in_ms=6.45
2019-06-30 07:26:56,455 [salt.state       :1780][INFO    ][13389] Running state [iptables_modules_v4_load] at time 07:26:56.455427
2019-06-30 07:26:56,455 [salt.state       :1813][INFO    ][13389] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-30 07:26:56,456 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'lsmod' in directory '/root'
2019-06-30 07:26:56,478 [salt.state       :300 ][INFO    ][13389] Kernel modules iptable_filter, ip_tables are already present
2019-06-30 07:26:56,478 [salt.state       :1951][INFO    ][13389] Completed state [iptables_modules_v4_load] at time 07:26:56.478661 duration_in_ms=23.234
2019-06-30 07:26:56,479 [salt.state       :1780][INFO    ][13389] Running state [/etc/iptables/rules.v4] at time 07:26:56.479272
2019-06-30 07:26:56,479 [salt.state       :1813][INFO    ][13389] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-30 07:26:56,558 [salt.state       :300 ][INFO    ][13389] File /etc/iptables/rules.v4 is in the correct state
2019-06-30 07:26:56,558 [salt.state       :1951][INFO    ][13389] Completed state [/etc/iptables/rules.v4] at time 07:26:56.558200 duration_in_ms=78.928
2019-06-30 07:26:56,558 [salt.state       :1780][INFO    ][13389] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 07:26:56.558944
2019-06-30 07:26:56,559 [salt.state       :1813][INFO    ][13389] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-30 07:26:56,559 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-30 07:26:56,577 [salt.state       :300 ][INFO    ][13389] onlyif execution failed
2019-06-30 07:26:56,577 [salt.state       :1951][INFO    ][13389] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 07:26:56.577606 duration_in_ms=18.661
2019-06-30 07:26:56,578 [salt.state       :1780][INFO    ][13389] Running state [netfilter-persistent] at time 07:26:56.578293
2019-06-30 07:26:56,578 [salt.state       :1813][INFO    ][13389] Executing state service.running for [netfilter-persistent]
2019-06-30 07:26:56,579 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-30 07:26:56,597 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-30 07:26:56,613 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-30 07:26:56,628 [salt.state       :300 ][INFO    ][13389] The service netfilter-persistent is already running
2019-06-30 07:26:56,629 [salt.state       :1951][INFO    ][13389] Completed state [netfilter-persistent] at time 07:26:56.629112 duration_in_ms=50.82
2019-06-30 07:26:56,629 [salt.state       :1780][INFO    ][13389] Running state [iptables_extra.remove_stale_tables] at time 07:26:56.629748
2019-06-30 07:26:56,630 [salt.state       :1813][INFO    ][13389] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-30 07:26:56,630 [salt.state       :300 ][INFO    ][13389] No changes made for iptables_extra.remove_stale_tables
2019-06-30 07:26:56,630 [salt.state       :1951][INFO    ][13389] Completed state [iptables_extra.remove_stale_tables] at time 07:26:56.630457 duration_in_ms=0.709
2019-06-30 07:26:56,630 [salt.state       :1780][INFO    ][13389] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 07:26:56.630676
2019-06-30 07:26:56,630 [salt.state       :1813][INFO    ][13389] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-30 07:26:56,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13389] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-30 07:26:56,644 [salt.state       :300 ][INFO    ][13389] onlyif execution failed
2019-06-30 07:26:56,644 [salt.state       :1951][INFO    ][13389] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 07:26:56.644574 duration_in_ms=13.898
2019-06-30 07:26:56,645 [salt.state       :1780][INFO    ][13389] Running state [/etc/iptables/rules.v6] at time 07:26:56.645309
2019-06-30 07:26:56,645 [salt.state       :1813][INFO    ][13389] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-30 07:26:56,645 [salt.state       :300 ][INFO    ][13389] File /etc/iptables/rules.v6 is not present
2019-06-30 07:26:56,646 [salt.state       :1951][INFO    ][13389] Completed state [/etc/iptables/rules.v6] at time 07:26:56.646143 duration_in_ms=0.834
2019-06-30 07:26:56,646 [salt.state       :1780][INFO    ][13389] Running state [iptables_extra.flush_all] at time 07:26:56.646658
2019-06-30 07:26:56,646 [salt.state       :1813][INFO    ][13389] Executing state module.wait for [iptables_extra.flush_all]
2019-06-30 07:26:56,647 [salt.state       :300 ][INFO    ][13389] No changes made for iptables_extra.flush_all
2019-06-30 07:26:56,647 [salt.state       :1951][INFO    ][13389] Completed state [iptables_extra.flush_all] at time 07:26:56.647303 duration_in_ms=0.645
2019-06-30 07:26:56,649 [salt.minion      :1711][INFO    ][13389] Returning information for job: 20190630072649080370
2019-06-30 07:26:57,252 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630072657243022
2019-06-30 07:26:57,274 [salt.minion      :1432][INFO    ][13469] Starting a new job with PID 13469
2019-06-30 07:26:58,035 [salt.state       :915 ][INFO    ][13469] Loading fresh modules for state activity
2019-06-30 07:26:58,603 [salt.state       :1780][INFO    ][13469] Running state [maas-rack-controller] at time 07:26:58.603392
2019-06-30 07:26:58,603 [salt.state       :1813][INFO    ][13469] Executing state pkg.installed for [maas-rack-controller]
2019-06-30 07:26:58,604 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13469] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:26:58,755 [salt.state       :300 ][INFO    ][13469] All specified packages are already installed
2019-06-30 07:26:58,756 [salt.state       :1951][INFO    ][13469] Completed state [maas-rack-controller] at time 07:26:58.756084 duration_in_ms=152.693
2019-06-30 07:26:58,756 [salt.state       :1780][INFO    ][13469] Running state [ipmitool] at time 07:26:58.756360
2019-06-30 07:26:58,756 [salt.state       :1813][INFO    ][13469] Executing state pkg.installed for [ipmitool]
2019-06-30 07:26:58,761 [salt.state       :300 ][INFO    ][13469] All specified packages are already installed
2019-06-30 07:26:58,761 [salt.state       :1951][INFO    ][13469] Completed state [ipmitool] at time 07:26:58.761395 duration_in_ms=5.035
2019-06-30 07:26:58,764 [salt.state       :1780][INFO    ][13469] Running state [/etc/maas/rackd.conf] at time 07:26:58.764135
2019-06-30 07:26:58,764 [salt.state       :1813][INFO    ][13469] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-30 07:26:58,765 [salt.state       :300 ][INFO    ][13469] No changes needed to be made
2019-06-30 07:26:58,765 [salt.state       :1951][INFO    ][13469] Completed state [/etc/maas/rackd.conf] at time 07:26:58.765264 duration_in_ms=1.129
2019-06-30 07:26:58,765 [salt.state       :1780][INFO    ][13469] Running state [/etc/maas/rackd.conf] at time 07:26:58.765450
2019-06-30 07:26:58,765 [salt.state       :1813][INFO    ][13469] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-30 07:26:58,765 [salt.loaded.int.states.file:2298][WARNING ][13469] 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-06-30 07:26:58,766 [salt.state       :300 ][INFO    ][13469] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-30 07:26:58,766 [salt.state       :1951][INFO    ][13469] Completed state [/etc/maas/rackd.conf] at time 07:26:58.766472 duration_in_ms=1.022
2019-06-30 07:26:58,767 [salt.state       :1780][INFO    ][13469] Running state [maas-rackd] at time 07:26:58.767231
2019-06-30 07:26:58,767 [salt.state       :1813][INFO    ][13469] Executing state service.running for [maas-rackd]
2019-06-30 07:26:58,767 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13469] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-30 07:26:58,801 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13469] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-30 07:26:58,817 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13469] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-30 07:26:58,832 [salt.state       :300 ][INFO    ][13469] The service maas-rackd is already running
2019-06-30 07:26:58,833 [salt.state       :1951][INFO    ][13469] Completed state [maas-rackd] at time 07:26:58.833086 duration_in_ms=65.855
2019-06-30 07:26:58,834 [salt.minion      :1711][INFO    ][13469] Returning information for job: 20190630072657243022
2019-06-30 07:26:59,443 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630072659430580
2019-06-30 07:26:59,463 [salt.minion      :1432][INFO    ][13498] Starting a new job with PID 13498
2019-06-30 07:27:00,181 [salt.state       :915 ][INFO    ][13498] Loading fresh modules for state activity
2019-06-30 07:27:00,837 [salt.state       :1780][INFO    ][13498] Running state [maas-region-controller] at time 07:27:00.837141
2019-06-30 07:27:00,837 [salt.state       :1813][INFO    ][13498] Executing state pkg.installed for [maas-region-controller]
2019-06-30 07:27:00,837 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:27:00,938 [salt.state       :300 ][INFO    ][13498] All specified packages are already installed
2019-06-30 07:27:00,939 [salt.state       :1951][INFO    ][13498] Completed state [maas-region-controller] at time 07:27:00.939246 duration_in_ms=102.105
2019-06-30 07:27:00,939 [salt.state       :1780][INFO    ][13498] Running state [python-oauth] at time 07:27:00.939664
2019-06-30 07:27:00,940 [salt.state       :1813][INFO    ][13498] Executing state pkg.installed for [python-oauth]
2019-06-30 07:27:00,947 [salt.state       :300 ][INFO    ][13498] All specified packages are already installed
2019-06-30 07:27:00,948 [salt.state       :1951][INFO    ][13498] Completed state [python-oauth] at time 07:27:00.948215 duration_in_ms=8.55
2019-06-30 07:27:00,951 [salt.state       :1780][INFO    ][13498] Running state [/etc/maas/regiond.conf] at time 07:27:00.951916
2019-06-30 07:27:00,952 [salt.state       :1813][INFO    ][13498] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-30 07:27:00,996 [salt.state       :300 ][INFO    ][13498] No changes needed to be made
2019-06-30 07:27:00,996 [salt.state       :1951][INFO    ][13498] Completed state [/etc/maas/regiond.conf] at time 07:27:00.996417 duration_in_ms=44.501
2019-06-30 07:27:00,996 [salt.state       :1780][INFO    ][13498] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 07:27:00.996935
2019-06-30 07:27:00,997 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-30 07:27:01,061 [salt.state       :300 ][INFO    ][13498] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-30 07:27:01,061 [salt.state       :1951][INFO    ][13498] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 07:27:01.061471 duration_in_ms=64.537
2019-06-30 07:27:01,062 [salt.state       :1780][INFO    ][13498] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:27:01.061973
2019-06-30 07:27:01,062 [salt.state       :1813][INFO    ][13498] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-30 07:27:01,074 [salt.state       :300 ][INFO    ][13498] No changes needed to be made
2019-06-30 07:27:01,074 [salt.state       :1951][INFO    ][13498] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:27:01.074736 duration_in_ms=12.763
2019-06-30 07:27:01,075 [salt.state       :1780][INFO    ][13498] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:27:01.075176
2019-06-30 07:27:01,075 [salt.state       :1813][INFO    ][13498] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-30 07:27:01,117 [salt.state       :300 ][INFO    ][13498] No changes needed to be made
2019-06-30 07:27:01,118 [salt.state       :1951][INFO    ][13498] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:27:01.118312 duration_in_ms=43.135
2019-06-30 07:27:01,119 [salt.state       :1780][INFO    ][13498] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 07:27:01.119157
2019-06-30 07:27:01,119 [salt.state       :1813][INFO    ][13498] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-30 07:27:01,155 [salt.state       :300 ][INFO    ][13498] No changes needed to be made
2019-06-30 07:27:01,156 [salt.state       :1951][INFO    ][13498] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 07:27:01.156221 duration_in_ms=37.064
2019-06-30 07:27:01,156 [salt.state       :1780][INFO    ][13498] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 07:27:01.156899
2019-06-30 07:27:01,157 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-30 07:27:01,170 [salt.state       :300 ][INFO    ][13498] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-30 07:27:01,170 [salt.state       :1951][INFO    ][13498] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 07:27:01.170858 duration_in_ms=13.958
2019-06-30 07:27:01,172 [salt.state       :1780][INFO    ][13498] Running state [a2enmod headers] at time 07:27:01.172308
2019-06-30 07:27:01,172 [salt.state       :1813][INFO    ][13498] Executing state cmd.run for [a2enmod headers]
2019-06-30 07:27:01,173 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command 'a2enmod headers' in directory '/root'
2019-06-30 07:27:01,249 [salt.state       :300 ][INFO    ][13498] {'pid': 13520, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-30 07:27:01,250 [salt.state       :1951][INFO    ][13498] Completed state [a2enmod headers] at time 07:27:01.249930 duration_in_ms=77.62
2019-06-30 07:27:01,250 [salt.state       :1780][INFO    ][13498] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 07:27:01.250650
2019-06-30 07:27:01,251 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-30 07:27:01,269 [salt.state       :300 ][INFO    ][13498] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-30 07:27:01,270 [salt.state       :1951][INFO    ][13498] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 07:27:01.270180 duration_in_ms=19.531
2019-06-30 07:27:01,271 [salt.state       :1780][INFO    ][13498] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 07:27:01.271012
2019-06-30 07:27:01,271 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-30 07:27:01,356 [salt.state       :300 ][INFO    ][13498] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-30 07:27:01,357 [salt.state       :1951][INFO    ][13498] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 07:27:01.357058 duration_in_ms=86.036
2019-06-30 07:27:01,358 [salt.state       :1780][INFO    ][13498] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 07:27:01.357971
2019-06-30 07:27:01,358 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-30 07:27:01,426 [salt.state       :300 ][INFO    ][13498] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-30 07:27:01,426 [salt.state       :1951][INFO    ][13498] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 07:27:01.426873 duration_in_ms=68.903
2019-06-30 07:27:01,427 [salt.state       :1780][INFO    ][13498] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 07:27:01.427344
2019-06-30 07:27:01,427 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-30 07:27:01,523 [salt.state       :300 ][INFO    ][13498] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-30 07:27:01,523 [salt.state       :1951][INFO    ][13498] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 07:27:01.523674 duration_in_ms=96.328
2019-06-30 07:27:01,524 [salt.state       :1780][INFO    ][13498] Running state [/root/.pgpass] at time 07:27:01.524134
2019-06-30 07:27:01,524 [salt.state       :1813][INFO    ][13498] Executing state file.managed for [/root/.pgpass]
2019-06-30 07:27:01,582 [salt.state       :300 ][INFO    ][13498] File /root/.pgpass is in the correct state
2019-06-30 07:27:01,583 [salt.state       :1951][INFO    ][13498] Completed state [/root/.pgpass] at time 07:27:01.583232 duration_in_ms=59.097
2019-06-30 07:27:01,589 [salt.state       :1780][INFO    ][13498] Running state [maas-region syncdb --noinput] at time 07:27:01.589771
2019-06-30 07:27:01,590 [salt.state       :1813][INFO    ][13498] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-30 07:27:01,591 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-30 07:27:03,660 [salt.state       :300 ][INFO    ][13498] {'pid': 13553, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: contenttypes, piston3, auth, metadataserver, sessions, sites, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-30 07:27:03,660 [salt.state       :1951][INFO    ][13498] Completed state [maas-region syncdb --noinput] at time 07:27:03.660602 duration_in_ms=2070.831
2019-06-30 07:27:03,661 [salt.state       :2022][WARNING ][13498] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-30 07:27:03,663 [salt.state       :1780][INFO    ][13498] Running state [maas-regiond] at time 07:27:03.663776
2019-06-30 07:27:03,664 [salt.state       :1813][INFO    ][13498] Executing state service.running for [maas-regiond]
2019-06-30 07:27:03,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-30 07:27:03,706 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-30 07:27:03,725 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-30 07:27:03,741 [salt.state       :300 ][INFO    ][13498] The service maas-regiond is already running
2019-06-30 07:27:03,742 [salt.state       :1951][INFO    ][13498] Completed state [maas-regiond] at time 07:27:03.742382 duration_in_ms=78.606
2019-06-30 07:27:03,744 [salt.state       :1780][INFO    ][13498] Running state [bind9] at time 07:27:03.744677
2019-06-30 07:27:03,745 [salt.state       :1813][INFO    ][13498] Executing state service.running for [bind9]
2019-06-30 07:27:03,746 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-30 07:27:03,762 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-30 07:27:03,778 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-30 07:27:03,793 [salt.state       :300 ][INFO    ][13498] The service bind9 is already running
2019-06-30 07:27:03,794 [salt.state       :1951][INFO    ][13498] Completed state [bind9] at time 07:27:03.794279 duration_in_ms=49.601
2019-06-30 07:27:03,796 [salt.state       :1780][INFO    ][13498] Running state [apache2] at time 07:27:03.796498
2019-06-30 07:27:03,796 [salt.state       :1813][INFO    ][13498] Executing state service.running for [apache2]
2019-06-30 07:27:03,797 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-30 07:27:03,814 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-30 07:27:03,830 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-30 07:27:03,850 [salt.state       :300 ][INFO    ][13498] The service apache2 is already running
2019-06-30 07:27:03,850 [salt.state       :1951][INFO    ][13498] Completed state [apache2] at time 07:27:03.850762 duration_in_ms=54.263
2019-06-30 07:27:03,853 [salt.state       :1780][INFO    ][13498] Running state [maasng.wait_for_http_code] at time 07:27:03.853306
2019-06-30 07:27:03,853 [salt.state       :1813][INFO    ][13498] Executing state module.run for [maasng.wait_for_http_code]
2019-06-30 07:27:03,854 [salt.utils.decorators:613 ][WARNING ][13498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:03,980 [salt.state       :300 ][INFO    ][13498] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-30 07:27:03,981 [salt.state       :1951][INFO    ][13498] Completed state [maasng.wait_for_http_code] at time 07:27:03.981269 duration_in_ms=127.962
2019-06-30 07:27:03,982 [salt.state       :1780][INFO    ][13498] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 07:27:03.982566
2019-06-30 07:27:03,983 [salt.state       :1813][INFO    ][13498] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-30 07:27:03,983 [salt.state       :300 ][INFO    ][13498] /var/lib/maas/.setup_admin exists
2019-06-30 07:27:03,984 [salt.state       :1951][INFO    ][13498] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 07:27:03.984045 duration_in_ms=1.479
2019-06-30 07:27:03,985 [salt.state       :1780][INFO    ][13498] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:27:03.985065
2019-06-30 07:27:03,985 [salt.state       :1813][INFO    ][13498] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:27:03,986 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13498] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:27:05,486 [salt.state       :300 ][INFO    ][13498] {'pid': 13575, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:27:05,487 [salt.state       :1951][INFO    ][13498] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:27:05.487139 duration_in_ms=1502.073
2019-06-30 07:27:05,498 [salt.state       :1780][INFO    ][13498] Running state [maas_region_boot_source_resources_mirror] at time 07:27:05.498631
2019-06-30 07:27:05,499 [salt.state       :1813][INFO    ][13498] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-30 07:27:05,617 [salt.state       :300 ][INFO    ][13498] {'changes': {}}
2019-06-30 07:27:05,618 [salt.state       :1951][INFO    ][13498] Completed state [maas_region_boot_source_resources_mirror] at time 07:27:05.618120 duration_in_ms=119.488
2019-06-30 07:27:05,619 [salt.state       :1780][INFO    ][13498] Running state [maasng.boot_resources_import] at time 07:27:05.619345
2019-06-30 07:27:05,619 [salt.state       :1813][INFO    ][13498] Executing state module.run for [maasng.boot_resources_import]
2019-06-30 07:27:05,620 [salt.utils.decorators:613 ][WARNING ][13498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:05,771 [salt.loaded.ext.module.maasng:1600][INFO    ][13498] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-30 07:27:10,813 [salt.loaded.ext.module.maasng:1600][INFO    ][13498] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-30 07:27:14,567 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072714554594
2019-06-30 07:27:14,589 [salt.minion      :1432][INFO    ][13957] Starting a new job with PID 13957
2019-06-30 07:27:14,613 [salt.minion      :1711][INFO    ][13957] Returning information for job: 20190630072714554594
2019-06-30 07:27:15,869 [salt.loaded.ext.module.maasng:1600][INFO    ][13498] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-30 07:27:20,978 [salt.state       :300 ][INFO    ][13498] {'ret': True}
2019-06-30 07:27:20,978 [salt.state       :1951][INFO    ][13498] Completed state [maasng.boot_resources_import] at time 07:27:20.978568 duration_in_ms=15359.223
2019-06-30 07:27:20,979 [salt.state       :1780][INFO    ][13498] Running state [maas_region_boot_sources_selection_xenial] at time 07:27:20.979802
2019-06-30 07:27:20,980 [salt.state       :1813][INFO    ][13498] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-30 07:27:21,194 [salt.state       :300 ][INFO    ][13498] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-30 07:27:21,195 [salt.state       :1951][INFO    ][13498] Completed state [maas_region_boot_sources_selection_xenial] at time 07:27:21.195196 duration_in_ms=215.395
2019-06-30 07:27:21,196 [salt.state       :1780][INFO    ][13498] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 07:27:21.196269
2019-06-30 07:27:21,196 [salt.state       :1813][INFO    ][13498] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-30 07:27:21,197 [salt.utils.decorators:613 ][WARNING ][13498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:21,197 [salt.loaded.ext.module.maasng:1771][INFO    ][13498] boot-sources sync initiated for ALL Rack's
2019-06-30 07:27:22,200 [salt.state       :300 ][INFO    ][13498] {'ret': True}
2019-06-30 07:27:22,200 [salt.state       :1951][INFO    ][13498] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 07:27:22.200813 duration_in_ms=1004.542
2019-06-30 07:27:22,203 [salt.state       :1780][INFO    ][13498] Running state [maas.process_maas_config] at time 07:27:22.203005
2019-06-30 07:27:22,203 [salt.state       :1813][INFO    ][13498] Executing state module.run for [maas.process_maas_config]
2019-06-30 07:27:22,204 [salt.utils.decorators:613 ][WARNING ][13498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:22,205 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=enable_http_proxy value=True
2019-06-30 07:27:22,268 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=upstream_dns value=8.8.8.8
2019-06-30 07:27:22,332 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=commissioning_distro_series value=xenial
2019-06-30 07:27:25,180 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=default_osystem value=ubuntu
2019-06-30 07:27:25,249 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=active_discovery_interval value=600
2019-06-30 07:27:25,315 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=dnssec_validation value=no
2019-06-30 07:27:25,387 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=maas_name value=mas01
2019-06-30 07:27:25,463 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=network_discovery value=enabled
2019-06-30 07:27:25,582 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=enable_third_party_drivers value=True
2019-06-30 07:27:25,637 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=default_storage_layout value=lvm
2019-06-30 07:27:25,700 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=ntp_external_only value=True
2019-06-30 07:27:25,740 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-30 07:27:25,782 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=default_distro_series value=xenial
2019-06-30 07:27:25,841 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-30 07:27:25,951 [salt.state       :300 ][INFO    ][13498] {'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-06-30 07:27:25,951 [salt.state       :1951][INFO    ][13498] Completed state [maas.process_maas_config] at time 07:27:25.951436 duration_in_ms=3748.43
2019-06-30 07:27:25,952 [salt.state       :1780][INFO    ][13498] Running state [pxe_admin] at time 07:27:25.952380
2019-06-30 07:27:25,952 [salt.state       :1813][INFO    ][13498] Executing state maasng.fabric_present for [pxe_admin]
2019-06-30 07:27:26,008 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-30 07:27:26,075 [salt.loaded.ext.module.maasng:1008][WARNING ][13498] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-30 07:27:26,075 [salt.loaded.ext.module.maasng:1011][WARNING ][13498] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-30 07:27:26,127 [salt.state       :300 ][INFO    ][13498] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-30 07:27:26,128 [salt.state       :1951][INFO    ][13498] Completed state [pxe_admin] at time 07:27:26.128142 duration_in_ms=175.761
2019-06-30 07:27:26,128 [salt.state       :1780][INFO    ][13498] Running state [vlan 0] at time 07:27:26.128433
2019-06-30 07:27:26,128 [salt.state       :1813][INFO    ][13498] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-30 07:27:26,175 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-30 07:27:26,297 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wr8cxf', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:27:26,590 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:27:26,685 [salt.state       :300 ][INFO    ][13498] {'new': 'Vlan untagged was updated'}
2019-06-30 07:27:26,686 [salt.state       :1951][INFO    ][13498] Completed state [vlan 0] at time 07:27:26.686004 duration_in_ms=557.57
2019-06-30 07:27:26,687 [salt.state       :1780][INFO    ][13498] Running state [192.168.11.0/24] at time 07:27:26.687348
2019-06-30 07:27:26,687 [salt.state       :1813][INFO    ][13498] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-30 07:27:26,908 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wr8cxf', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:27:26,908 [salt.loaded.ext.module.maasng:1235][WARNING ][13498] Ignoring parameter vlan:0
2019-06-30 07:27:26,991 [salt.state       :300 ][INFO    ][13498] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-30 07:27:26,991 [salt.state       :1951][INFO    ][13498] Completed state [192.168.11.0/24] at time 07:27:26.991565 duration_in_ms=304.216
2019-06-30 07:27:26,992 [salt.state       :1780][INFO    ][13498] Running state [maas_create_iprange_1] at time 07:27:26.992893
2019-06-30 07:27:26,993 [salt.state       :1813][INFO    ][13498] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-30 07:27:27,051 [salt.state       :300 ][INFO    ][13498] Iprange maas_create_iprange_1 already exist.
2019-06-30 07:27:27,051 [salt.state       :1951][INFO    ][13498] Completed state [maas_create_iprange_1] at time 07:27:27.051905 duration_in_ms=59.012
2019-06-30 07:27:27,052 [salt.state       :1780][INFO    ][13498] Running state [vlan 0] at time 07:27:27.052279
2019-06-30 07:27:27,052 [salt.state       :1813][INFO    ][13498] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-30 07:27:27,099 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:27:27,183 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:27:27,457 [salt.loaded.ext.module.maasng:945 ][INFO    ][13498] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-30 07:27:27,554 [salt.state       :300 ][INFO    ][13498] {'new': 'Vlan untagged was updated'}
2019-06-30 07:27:27,554 [salt.state       :1951][INFO    ][13498] Completed state [vlan 0] at time 07:27:27.554737 duration_in_ms=502.457
2019-06-30 07:27:27,555 [salt.state       :1780][INFO    ][13498] Running state [opnfv] at time 07:27:27.555498
2019-06-30 07:27:27,555 [salt.state       :1813][INFO    ][13498] Executing state maasng.sshkey_present for [opnfv]
2019-06-30 07:27:27,608 [salt.loaded.ext.module.maasng:1903][INFO    ][13498] [{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-06-30 07:27:27,608 [salt.state       :300 ][INFO    ][13498] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-30 07:27:27,609 [salt.state       :1951][INFO    ][13498] Completed state [opnfv] at time 07:27:27.609216 duration_in_ms=53.717
2019-06-30 07:27:27,610 [salt.state       :1780][INFO    ][13498] Running state [maas.process_tags] at time 07:27:27.609938
2019-06-30 07:27:27,610 [salt.state       :1813][INFO    ][13498] Executing state module.run for [maas.process_tags]
2019-06-30 07:27:27,610 [salt.utils.decorators:613 ][WARNING ][13498] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:27,657 [salt.loaded.ext.module.maas:92  ][INFO    ][13498] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-30 07:27:27,711 [salt.state       :300 ][INFO    ][13498] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-30 07:27:27,711 [salt.state       :1951][INFO    ][13498] Completed state [maas.process_tags] at time 07:27:27.711555 duration_in_ms=101.615
2019-06-30 07:27:27,714 [salt.minion      :1711][INFO    ][13498] Returning information for job: 20190630072659430580
2019-06-30 07:27:28,381 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630072728368516
2019-06-30 07:27:28,400 [salt.minion      :1432][INFO    ][14333] Starting a new job with PID 14333
2019-06-30 07:27:32,093 [salt.state       :915 ][INFO    ][14333] Loading fresh modules for state activity
2019-06-30 07:27:32,187 [salt.state       :1780][INFO    ][14333] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:27:32.187376
2019-06-30 07:27:32,187 [salt.state       :1813][INFO    ][14333] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:27:32,189 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14333] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:27:33,597 [salt.state       :300 ][INFO    ][14333] {'pid': 14363, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:27:33,598 [salt.state       :1951][INFO    ][14333] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:27:33.598174 duration_in_ms=1410.799
2019-06-30 07:27:33,599 [salt.state       :1780][INFO    ][14333] Running state [maas.process_machines] at time 07:27:33.599253
2019-06-30 07:27:33,599 [salt.state       :1813][INFO    ][14333] Executing state module.run for [maas.process_machines]
2019-06-30 07:27:33,600 [salt.utils.decorators:613 ][WARNING ][14333] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:27:33,947 [salt.loaded.ext.module.maas:412 ][WARNING ][14333] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:27:33,947 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] machine hostname=cmp002 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=yfxpre architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:27:35,004 [salt.loaded.ext.module.maas:412 ][WARNING ][14333] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:27:35,005 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] machine hostname=cmp001 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=8aqah8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:27:36,078 [salt.loaded.ext.module.maas:412 ][WARNING ][14333] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:27:36,079 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] machine hostname=kvm01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=sm8fr7 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:27:37,017 [salt.loaded.ext.module.maas:412 ][WARNING ][14333] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:27:37,018 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] machine hostname=kvm03 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=dtn7s4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:27:38,060 [salt.loaded.ext.module.maas:412 ][WARNING ][14333] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:27:38,061 [salt.loaded.ext.module.maas:92  ][INFO    ][14333] machine hostname=kvm02 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=sq4ne7 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:27:39,006 [salt.state       :300 ][INFO    ][14333] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-30 07:27:39,007 [salt.state       :1951][INFO    ][14333] Completed state [maas.process_machines] at time 07:27:39.007274 duration_in_ms=5408.019
2019-06-30 07:27:39,011 [salt.minion      :1711][INFO    ][14333] Returning information for job: 20190630072728368516
2019-06-30 07:28:10,040 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630072810026771
2019-06-30 07:28:10,064 [salt.minion      :1432][INFO    ][14626] Starting a new job with PID 14626
2019-06-30 07:28:13,727 [salt.state       :915 ][INFO    ][14626] Loading fresh modules for state activity
2019-06-30 07:28:13,780 [salt.state       :1780][INFO    ][14626] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:28:13.780165
2019-06-30 07:28:13,780 [salt.state       :1813][INFO    ][14626] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:28:13,781 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14626] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:28:15,277 [salt.state       :300 ][INFO    ][14626] {'pid': 14662, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:28:15,278 [salt.state       :1951][INFO    ][14626] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:28:15.278080 duration_in_ms=1497.913
2019-06-30 07:28:15,281 [salt.state       :1780][INFO    ][14626] Running state [maas.wait_for_machine_status] at time 07:28:15.281458
2019-06-30 07:28:15,282 [salt.state       :1813][INFO    ][14626] Executing state module.run for [maas.wait_for_machine_status]
2019-06-30 07:28:15,282 [salt.utils.decorators:613 ][WARNING ][14626] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:28:17,947 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1497.34649706s left)
2019-06-30 07:28:25,130 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072825117106
2019-06-30 07:28:25,153 [salt.minion      :1432][INFO    ][14747] Starting a new job with PID 14747
2019-06-30 07:28:25,177 [salt.minion      :1711][INFO    ][14747] Returning information for job: 20190630072825117106
2019-06-30 07:28:50,553 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1464.74050212s left)
2019-06-30 07:28:55,182 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072855169988
2019-06-30 07:28:55,205 [salt.minion      :1432][INFO    ][14795] Starting a new job with PID 14795
2019-06-30 07:28:55,229 [salt.minion      :1711][INFO    ][14795] Returning information for job: 20190630072855169988
2019-06-30 07:29:23,328 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1431.96487999s left)
2019-06-30 07:29:25,265 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072925252253
2019-06-30 07:29:25,284 [salt.minion      :1432][INFO    ][14893] Starting a new job with PID 14893
2019-06-30 07:29:25,307 [salt.minion      :1711][INFO    ][14893] Returning information for job: 20190630072925252253
2019-06-30 07:29:55,296 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630072955284414
2019-06-30 07:29:55,318 [salt.minion      :1432][INFO    ][14913] Starting a new job with PID 14913
2019-06-30 07:29:55,341 [salt.minion      :1711][INFO    ][14913] Returning information for job: 20190630072955284414
2019-06-30 07:29:56,035 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1399.25827217s left)
2019-06-30 07:30:25,342 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073025329079
2019-06-30 07:30:25,365 [salt.minion      :1432][INFO    ][14986] Starting a new job with PID 14986
2019-06-30 07:30:25,389 [salt.minion      :1711][INFO    ][14986] Returning information for job: 20190630073025329079
2019-06-30 07:30:27,774 [salt.loaded.ext.module.maas:981 ][INFO    ][14626] Machine sm8fr7 deleted
2019-06-30 07:30:28,317 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:28,318 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=yfxpre architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:29,262 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:29,263 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=8aqah8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:30,429 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:30,429 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:31,872 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:31,873 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=dtn7s4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:33,118 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:33,119 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] machine hostname=kvm02 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=sq4ne7 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:35,152 [salt.loaded.ext.module.maas:981 ][INFO    ][14626] Machine sq4ne7 deleted
2019-06-30 07:30:35,863 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:35,864 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=yfxpre architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:37,094 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:37,095 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=8aqah8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:38,418 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:38,419 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] machine hostname=kvm01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=gxwwcp architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:39,304 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:39,305 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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=dtn7s4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:40,610 [salt.loaded.ext.module.maas:412 ][WARNING ][14626] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:30:40,611 [salt.loaded.ext.module.maas:92  ][INFO    ][14626] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:30:42,071 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1353.22185516s left)
2019-06-30 07:30:55,400 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073055387747
2019-06-30 07:30:55,423 [salt.minion      :1432][INFO    ][15475] Starting a new job with PID 15475
2019-06-30 07:30:55,447 [salt.minion      :1711][INFO    ][15475] Returning information for job: 20190630073055387747
2019-06-30 07:31:14,446 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1320.84741807s left)
2019-06-30 07:31:25,459 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073125446986
2019-06-30 07:31:25,482 [salt.minion      :1432][INFO    ][15546] Starting a new job with PID 15546
2019-06-30 07:31:25,503 [salt.minion      :1711][INFO    ][15546] Returning information for job: 20190630073125446986
2019-06-30 07:31:46,727 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1288.56598806s left)
2019-06-30 07:31:55,515 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073155502630
2019-06-30 07:31:55,538 [salt.minion      :1432][INFO    ][15572] Starting a new job with PID 15572
2019-06-30 07:31:55,561 [salt.minion      :1711][INFO    ][15572] Returning information for job: 20190630073155502630
2019-06-30 07:32:19,074 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1256.21926618s left)
2019-06-30 07:32:25,580 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073225568598
2019-06-30 07:32:25,599 [salt.minion      :1432][INFO    ][15659] Starting a new job with PID 15659
2019-06-30 07:32:25,622 [salt.minion      :1711][INFO    ][15659] Returning information for job: 20190630073225568598
2019-06-30 07:32:51,459 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1223.83375812s left)
2019-06-30 07:32:55,642 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073255630432
2019-06-30 07:32:55,666 [salt.minion      :1432][INFO    ][15718] Starting a new job with PID 15718
2019-06-30 07:32:55,690 [salt.minion      :1711][INFO    ][15718] Returning information for job: 20190630073255630432
2019-06-30 07:33:24,233 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1191.05986905s left)
2019-06-30 07:33:25,718 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073325705728
2019-06-30 07:33:25,740 [salt.minion      :1432][INFO    ][16009] Starting a new job with PID 16009
2019-06-30 07:33:25,762 [salt.minion      :1711][INFO    ][16009] Returning information for job: 20190630073325705728
2019-06-30 07:33:55,791 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073355778392
2019-06-30 07:33:55,813 [salt.minion      :1432][INFO    ][16042] Starting a new job with PID 16042
2019-06-30 07:33:55,835 [salt.minion      :1711][INFO    ][16042] Returning information for job: 20190630073355778392
2019-06-30 07:33:56,766 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm02']
sleep for:30s Timeout:1500s (1158.52703118s left)
2019-06-30 07:34:25,875 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073425862912
2019-06-30 07:34:25,898 [salt.minion      :1432][INFO    ][16186] Starting a new job with PID 16186
2019-06-30 07:34:25,922 [salt.minion      :1711][INFO    ][16186] Returning information for job: 20190630073425862912
2019-06-30 07:34:29,631 [salt.loaded.ext.module.maas:1023][INFO    ][14626] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1125.662287s left)
2019-06-30 07:34:55,967 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073455955247
2019-06-30 07:34:55,990 [salt.minion      :1432][INFO    ][16268] Starting a new job with PID 16268
2019-06-30 07:34:56,012 [salt.minion      :1711][INFO    ][16268] Returning information for job: 20190630073455955247
2019-06-30 07:35:02,955 [salt.state       :300 ][INFO    ][14626] {'ret': True}
2019-06-30 07:35:02,956 [salt.state       :1951][INFO    ][14626] Completed state [maas.wait_for_machine_status] at time 07:35:02.956291 duration_in_ms=407674.83
2019-06-30 07:35:02,960 [salt.minion      :1711][INFO    ][14626] Returning information for job: 20190630072810026771
2019-06-30 07:35:03,604 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630073503591731
2019-06-30 07:35:03,626 [salt.minion      :1432][INFO    ][16297] Starting a new job with PID 16297
2019-06-30 07:35:07,377 [salt.state       :915 ][INFO    ][16297] Loading fresh modules for state activity
2019-06-30 07:35:07,428 [salt.fileclient  :1219][INFO    ][16297] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-30 07:35:07,518 [salt.state       :1780][INFO    ][16297] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:07.518284
2019-06-30 07:35:07,518 [salt.state       :1813][INFO    ][16297] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:35:07,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16297] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:35:08,912 [salt.state       :300 ][INFO    ][16297] {'pid': 16304, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:35:08,913 [salt.state       :1951][INFO    ][16297] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:08.913355 duration_in_ms=1395.071
2019-06-30 07:35:08,916 [salt.state       :1780][INFO    ][16297] Running state [maas_machines_storage_cmp002_lvm] at time 07:35:08.916377
2019-06-30 07:35:08,916 [salt.state       :1813][INFO    ][16297] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-30 07:35:10,248 [salt.loaded.ext.module.maasng:610 ][INFO    ][16297] yfxpre
2019-06-30 07:35:10,249 [salt.loaded.ext.module.maasng:626 ][INFO    ][16297] sda
2019-06-30 07:35:10,895 [salt.loaded.ext.module.maasng:361 ][INFO    ][16297] yfxpre
2019-06-30 07:35:11,034 [salt.loaded.ext.module.maasng:367 ][INFO    ][16297] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yfxpre', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 2, u'partitions': [{u'size': 2397992648704, u'uuid': u'6ed39e39-7689-421f-b61a-39a588145ce1', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yfxpre', u'filesystem': {u'uuid': u'a8c96950-407c-4d31-b5b8-909839aa72ba', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/partition/3'}]}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/6/', u'type': u'virtual', u'tags': [], u'uuid': u'b083dbf5-75e5-434b-8783-282d3f53a76b', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'yfxpre', u'partition_table_type': None, u'filesystem': {u'uuid': u'3f936c60-8b23-49e2-867f-1f12997dbd3c', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 2397988454400, u'used_size': 2397988454400, u'id': 6, u'partitions': []}]
2019-06-30 07:35:11,035 [salt.loaded.ext.module.maasng:632 ][INFO    ][16297] vgroot
2019-06-30 07:35:11,036 [salt.loaded.ext.module.maasng:635 ][INFO    ][16297] lvroot
2019-06-30 07:35:11,036 [salt.loaded.ext.module.maasng:639 ][INFO    ][16297] 107374182400
2019-06-30 07:35:11,712 [salt.loaded.ext.module.maasng:645 ][INFO    ][16297] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'fqdn': u'cmp002.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'e53702f4-6021-4051-b4f9-6bf64b14ece4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yfxpre', u'filesystem': {u'uuid': u'2a7e4ae5-d51d-493e-a0a1-586c556fad68', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/partition/7'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yfxpre', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/', u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}, u'zone': {u'description': u'', u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'id': 1}, u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'yfxpre', 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'owner_data': {}, u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yfxpre', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 2, u'partitions': [{u'size': 2397992648704, u'uuid': u'e53702f4-6021-4051-b4f9-6bf64b14ece4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yfxpre', u'filesystem': {u'uuid': u'2a7e4ae5-d51d-493e-a0a1-586c556fad68', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/partition/7'}]}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'90851b88-6ec0-4872-b2c6-e55367cc5b23', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'yfxpre', u'partition_table_type': None, u'filesystem': {u'uuid': u'cf175fd6-60c8-439c-bca9-9dc91cc44b20', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'e53702f4-6021-4051-b4f9-6bf64b14ece4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'yfxpre', u'filesystem': {u'uuid': u'2a7e4ae5-d51d-493e-a0a1-586c556fad68', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/partition/7'}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'yfxpre', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/2/', u'used_size': 2397998940160, u'id': 2, u'size': 2397998940160}], u'ip_addresses': [], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'yfxpre', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 25}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'yfxpre', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 15, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'system_id': u'yfxpre', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/interfaces/15/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 29}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 16, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'system_id': u'yfxpre', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/interfaces/16/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 32}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 17, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'system_id': u'yfxpre', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/interfaces/17/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'90851b88-6ec0-4872-b2c6-e55367cc5b23', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'yfxpre', u'partition_table_type': None, u'filesystem': {u'uuid': u'cf175fd6-60c8-439c-bca9-9dc91cc44b20', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/blockdevices/12/', u'used_size': 107374182400, u'id': 12, u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 25}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'yfxpre', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/yfxpre/interfaces/4/'}, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/yfxpre/'}
2019-06-30 07:35:11,714 [salt.state       :300 ][INFO    ][16297] {'new': {'storage_layout': 'lvm'}}
2019-06-30 07:35:11,715 [salt.state       :1951][INFO    ][16297] Completed state [maas_machines_storage_cmp002_lvm] at time 07:35:11.715065 duration_in_ms=2798.686
2019-06-30 07:35:11,715 [salt.state       :1780][INFO    ][16297] Running state [maas_machines_storage_cmp001_lvm] at time 07:35:11.715659
2019-06-30 07:35:11,716 [salt.state       :1813][INFO    ][16297] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-30 07:35:12,961 [salt.loaded.ext.module.maasng:610 ][INFO    ][16297] 8aqah8
2019-06-30 07:35:12,961 [salt.loaded.ext.module.maasng:626 ][INFO    ][16297] sda
2019-06-30 07:35:13,624 [salt.loaded.ext.module.maasng:361 ][INFO    ][16297] 8aqah8
2019-06-30 07:35:13,757 [salt.loaded.ext.module.maasng:367 ][INFO    ][16297] [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'93be16d6-ec2d-4254-bd47-d192ab517009', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8aqah8', u'device_id': 3, u'filesystem': {u'mount_options': None, u'uuid': u'd06a72ae-38b5-4e3b-bfff-3152fa0e300f', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/partition/4', u'type': u'partition', u'id': 4, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'8aqah8', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 3, u'size': 2397998940160}, {u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/7/', u'uuid': u'9db5e747-2958-4d06-921d-ed06f9d40a3d', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'8aqah8', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'6ff0e644-6eb3-43dc-aed5-9b376279083d', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 7, u'size': 2397988454400}]
2019-06-30 07:35:13,757 [salt.loaded.ext.module.maasng:632 ][INFO    ][16297] vgroot
2019-06-30 07:35:13,758 [salt.loaded.ext.module.maasng:635 ][INFO    ][16297] lvroot
2019-06-30 07:35:13,758 [salt.loaded.ext.module.maasng:639 ][INFO    ][16297] 107374182400
2019-06-30 07:35:14,471 [salt.loaded.ext.module.maasng:645 ][INFO    ][16297] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'ip_addresses': [], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/8aqah8/', u'disable_ipv4': False, u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'8aqah8', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8aqah8', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 3, u'partitions': [{u'uuid': u'157e466a-ff6f-4005-9d56-219baa1dea1f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8aqah8', u'device_id': 3, u'filesystem': {u'uuid': u'a2763647-1447-4e45-baff-ba1ccc843ad5', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}]}], u'blockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'tags': [u'rotary'], u'id': 3, u'system_id': u'8aqah8', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'157e466a-ff6f-4005-9d56-219baa1dea1f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8aqah8', u'device_id': 3, u'filesystem': {u'uuid': u'a2763647-1447-4e45-baff-ba1ccc843ad5', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}]}, {u'block_size': 4096, u'available_size': 0, u'uuid': u'3b139de4-2b43-4e11-ad83-79a7d79819b8', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/13/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'tags': [], u'id': 13, u'system_id': u'8aqah8', u'partition_table_type': None, u'filesystem': {u'uuid': u'1fd5aff5-5ac7-4f5e-acc3-6a3377ba270f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'serial': None, u'partitions': []}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'8aqah8', u'id': 8}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', 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'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 26}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': [], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'8aqah8', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/interfaces/5/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 28}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'8aqah8', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/interfaces/14/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 30}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'8aqah8', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/interfaces/12/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 31}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'8aqah8', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/interfaces/13/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/13/', u'type': u'virtual', u'tags': [], u'filesystem': {u'uuid': u'1fd5aff5-5ac7-4f5e-acc3-6a3377ba270f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'uuid': u'3b139de4-2b43-4e11-ad83-79a7d79819b8', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'8aqah8', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'id': 13, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 26}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'children': [], u'discovered': [], u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'8aqah8', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/interfaces/5/'}, u'current_commissioning_result_id': 4, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/', u'type': u'physical', u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'8aqah8', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 3, u'partitions': [{u'uuid': u'157e466a-ff6f-4005-9d56-219baa1dea1f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8aqah8', u'device_id': 3, u'filesystem': {u'uuid': u'a2763647-1447-4e45-baff-ba1ccc843ad5', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8aqah8/blockdevices/3/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}]}}
2019-06-30 07:35:14,473 [salt.state       :300 ][INFO    ][16297] {'new': {'storage_layout': 'lvm'}}
2019-06-30 07:35:14,473 [salt.state       :1951][INFO    ][16297] Completed state [maas_machines_storage_cmp001_lvm] at time 07:35:14.473518 duration_in_ms=2757.859
2019-06-30 07:35:14,477 [salt.minion      :1711][INFO    ][16297] Returning information for job: 20190630073503591731
2019-06-30 07:35:15,116 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630073515103365
2019-06-30 07:35:15,138 [salt.minion      :1432][INFO    ][16388] Starting a new job with PID 16388
2019-06-30 07:35:15,896 [salt.state       :915 ][INFO    ][16388] Loading fresh modules for state activity
2019-06-30 07:35:15,950 [salt.fileclient  :1219][INFO    ][16388] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-30 07:35:15,987 [salt.state       :1780][INFO    ][16388] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:15.987450
2019-06-30 07:35:15,987 [salt.state       :1813][INFO    ][16388] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:35:15,989 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16388] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:35:17,425 [salt.state       :300 ][INFO    ][16388] {'pid': 16395, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:35:17,425 [salt.state       :1951][INFO    ][16388] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:17.425496 duration_in_ms=1438.047
2019-06-30 07:35:17,426 [salt.state       :1780][INFO    ][16388] Running state [maas.deploy_machines] at time 07:35:17.426689
2019-06-30 07:35:17,426 [salt.state       :1813][INFO    ][16388] Executing state module.run for [maas.deploy_machines]
2019-06-30 07:35:17,427 [salt.utils.decorators:613 ][WARNING ][16388] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:35:17,953 [salt.loaded.ext.module.maas:684 ][INFO    ][16388] deploymachines hwe_kernel=hwe-16.04 system_id=yfxpre distro_series=xenial
2019-06-30 07:35:20,668 [salt.loaded.ext.module.maas:684 ][INFO    ][16388] deploymachines hwe_kernel=hwe-16.04 system_id=8aqah8 distro_series=xenial
2019-06-30 07:35:23,346 [salt.loaded.ext.module.maas:684 ][INFO    ][16388] deploymachines hwe_kernel=hwe-16.04 system_id=gxwwcp distro_series=xenial
2019-06-30 07:35:25,968 [salt.loaded.ext.module.maas:684 ][INFO    ][16388] deploymachines hwe_kernel=hwe-16.04 system_id=dtn7s4 distro_series=xenial
2019-06-30 07:35:28,659 [salt.loaded.ext.module.maas:684 ][INFO    ][16388] deploymachines hwe_kernel=hwe-16.04 system_id=8qd4tk distro_series=xenial
2019-06-30 07:35:30,168 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073530155431
2019-06-30 07:35:30,190 [salt.minion      :1432][INFO    ][16654] Starting a new job with PID 16654
2019-06-30 07:35:30,214 [salt.minion      :1711][INFO    ][16654] Returning information for job: 20190630073530155431
2019-06-30 07:35:31,258 [salt.state       :300 ][INFO    ][16388] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-30 07:35:31,259 [salt.state       :1951][INFO    ][16388] Completed state [maas.deploy_machines] at time 07:35:31.259258 duration_in_ms=13832.566
2019-06-30 07:35:31,262 [salt.minion      :1711][INFO    ][16388] Returning information for job: 20190630073515103365
2019-06-30 07:35:31,867 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630073531857938
2019-06-30 07:35:31,889 [salt.minion      :1432][INFO    ][16678] Starting a new job with PID 16678
2019-06-30 07:35:35,637 [salt.state       :915 ][INFO    ][16678] Loading fresh modules for state activity
2019-06-30 07:35:35,686 [salt.fileclient  :1219][INFO    ][16678] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-30 07:35:35,730 [salt.state       :1780][INFO    ][16678] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:35.730697
2019-06-30 07:35:35,731 [salt.state       :1813][INFO    ][16678] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:35:35,733 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16678] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:35:37,155 [salt.state       :300 ][INFO    ][16678] {'pid': 16694, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:35:37,155 [salt.state       :1951][INFO    ][16678] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:35:37.155665 duration_in_ms=1424.969
2019-06-30 07:35:37,157 [salt.state       :1780][INFO    ][16678] Running state [maas.wait_for_machine_status] at time 07:35:37.157087
2019-06-30 07:35:37,157 [salt.state       :1813][INFO    ][16678] Executing state module.run for [maas.wait_for_machine_status]
2019-06-30 07:35:37,157 [salt.utils.decorators:613 ][WARNING ][16678] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:35:40,483 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.67799497s left)
2019-06-30 07:35:46,928 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073546912404
2019-06-30 07:35:46,950 [salt.minion      :1432][INFO    ][16706] Starting a new job with PID 16706
2019-06-30 07:35:46,973 [salt.minion      :1711][INFO    ][16706] Returning information for job: 20190630073546912404
2019-06-30 07:36:13,489 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.67284894s left)
2019-06-30 07:36:16,970 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073616957126
2019-06-30 07:36:16,993 [salt.minion      :1432][INFO    ][16763] Starting a new job with PID 16763
2019-06-30 07:36:17,018 [salt.minion      :1711][INFO    ][16763] Returning information for job: 20190630073616957126
2019-06-30 07:36:46,818 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2180.34301996s left)
2019-06-30 07:36:47,046 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073647033015
2019-06-30 07:36:47,069 [salt.minion      :1432][INFO    ][16782] Starting a new job with PID 16782
2019-06-30 07:36:47,094 [salt.minion      :1711][INFO    ][16782] Returning information for job: 20190630073647033015
2019-06-30 07:37:17,086 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073717073936
2019-06-30 07:37:17,101 [salt.minion      :1432][INFO    ][16943] Starting a new job with PID 16943
2019-06-30 07:37:17,114 [salt.minion      :1711][INFO    ][16943] Returning information for job: 20190630073717073936
2019-06-30 07:37:19,448 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.71303797s left)
2019-06-30 07:37:47,130 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073747117182
2019-06-30 07:37:47,153 [salt.minion      :1432][INFO    ][17106] Starting a new job with PID 17106
2019-06-30 07:37:47,174 [salt.minion      :1711][INFO    ][17106] Returning information for job: 20190630073747117182
2019-06-30 07:37:52,520 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2114.64090705s left)
2019-06-30 07:38:17,182 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073817169585
2019-06-30 07:38:17,204 [salt.minion      :1432][INFO    ][17919] Starting a new job with PID 17919
2019-06-30 07:38:17,227 [salt.minion      :1711][INFO    ][17919] Returning information for job: 20190630073817169585
2019-06-30 07:38:25,837 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2081.32401896s left)
2019-06-30 07:38:47,237 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073847224907
2019-06-30 07:38:47,260 [salt.minion      :1432][INFO    ][17939] Starting a new job with PID 17939
2019-06-30 07:38:47,284 [salt.minion      :1711][INFO    ][17939] Returning information for job: 20190630073847224907
2019-06-30 07:38:59,454 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.70707989s left)
2019-06-30 07:39:17,301 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073917288296
2019-06-30 07:39:17,324 [salt.minion      :1432][INFO    ][18071] Starting a new job with PID 18071
2019-06-30 07:39:17,346 [salt.minion      :1711][INFO    ][18071] Returning information for job: 20190630073917288296
2019-06-30 07:39:32,967 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2014.19452882s left)
2019-06-30 07:39:47,362 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630073947349261
2019-06-30 07:39:47,384 [salt.minion      :1432][INFO    ][18099] Starting a new job with PID 18099
2019-06-30 07:39:47,408 [salt.minion      :1711][INFO    ][18099] Returning information for job: 20190630073947349261
2019-06-30 07:40:05,883 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1981.27867389s left)
2019-06-30 07:40:17,428 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074017415763
2019-06-30 07:40:17,452 [salt.minion      :1432][INFO    ][18722] Starting a new job with PID 18722
2019-06-30 07:40:17,475 [salt.minion      :1711][INFO    ][18722] Returning information for job: 20190630074017415763
2019-06-30 07:40:39,373 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.78868103s left)
2019-06-30 07:40:47,502 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074047491571
2019-06-30 07:40:47,524 [salt.minion      :1432][INFO    ][18759] Starting a new job with PID 18759
2019-06-30 07:40:47,547 [salt.minion      :1711][INFO    ][18759] Returning information for job: 20190630074047491571
2019-06-30 07:41:11,944 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1915.21709704s left)
2019-06-30 07:41:17,573 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074117560374
2019-06-30 07:41:17,596 [salt.minion      :1432][INFO    ][19168] Starting a new job with PID 19168
2019-06-30 07:41:17,621 [salt.minion      :1711][INFO    ][19168] Returning information for job: 20190630074117560374
2019-06-30 07:41:45,285 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1881.87616992s left)
2019-06-30 07:41:47,659 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074147646079
2019-06-30 07:41:47,683 [salt.minion      :1432][INFO    ][19188] Starting a new job with PID 19188
2019-06-30 07:41:47,707 [salt.minion      :1711][INFO    ][19188] Returning information for job: 20190630074147646079
2019-06-30 07:42:17,746 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074217733437
2019-06-30 07:42:17,770 [salt.minion      :1432][INFO    ][19244] Starting a new job with PID 19244
2019-06-30 07:42:17,794 [salt.minion      :1711][INFO    ][19244] Returning information for job: 20190630074217733437
2019-06-30 07:42:18,920 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1848.24156785s left)
2019-06-30 07:42:47,840 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074247828157
2019-06-30 07:42:47,863 [salt.minion      :1432][INFO    ][19383] Starting a new job with PID 19383
2019-06-30 07:42:47,887 [salt.minion      :1711][INFO    ][19383] Returning information for job: 20190630074247828157
2019-06-30 07:42:52,503 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.65861487s left)
2019-06-30 07:43:18,023 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074318011679
2019-06-30 07:43:18,043 [salt.minion      :1432][INFO    ][19779] Starting a new job with PID 19779
2019-06-30 07:43:18,064 [salt.minion      :1711][INFO    ][19779] Returning information for job: 20190630074318011679
2019-06-30 07:43:26,107 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1781.05474091s left)
2019-06-30 07:43:48,120 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074348107455
2019-06-30 07:43:48,143 [salt.minion      :1432][INFO    ][19824] Starting a new job with PID 19824
2019-06-30 07:43:48,169 [salt.minion      :1711][INFO    ][19824] Returning information for job: 20190630074348107455
2019-06-30 07:43:59,657 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1747.50414395s left)
2019-06-30 07:44:18,234 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074418220956
2019-06-30 07:44:18,256 [salt.minion      :1432][INFO    ][20073] Starting a new job with PID 20073
2019-06-30 07:44:18,281 [salt.minion      :1711][INFO    ][20073] Returning information for job: 20190630074418220956
2019-06-30 07:44:33,144 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1714.01776004s left)
2019-06-30 07:44:48,352 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074448339457
2019-06-30 07:44:48,376 [salt.minion      :1432][INFO    ][20093] Starting a new job with PID 20093
2019-06-30 07:44:48,402 [salt.minion      :1711][INFO    ][20093] Returning information for job: 20190630074448339457
2019-06-30 07:45:06,712 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1680.4489069s left)
2019-06-30 07:45:18,490 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074518477249
2019-06-30 07:45:18,513 [salt.minion      :1432][INFO    ][20274] Starting a new job with PID 20274
2019-06-30 07:45:18,538 [salt.minion      :1711][INFO    ][20274] Returning information for job: 20190630074518477249
2019-06-30 07:45:40,024 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1647.13699198s left)
2019-06-30 07:45:48,618 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074548606926
2019-06-30 07:45:48,641 [salt.minion      :1432][INFO    ][20294] Starting a new job with PID 20294
2019-06-30 07:45:48,666 [salt.minion      :1711][INFO    ][20294] Returning information for job: 20190630074548606926
2019-06-30 07:46:13,521 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1613.64021683s left)
2019-06-30 07:46:18,764 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074618752502
2019-06-30 07:46:18,788 [salt.minion      :1432][INFO    ][20349] Starting a new job with PID 20349
2019-06-30 07:46:18,813 [salt.minion      :1711][INFO    ][20349] Returning information for job: 20190630074618752502
2019-06-30 07:46:46,739 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1580.42250896s left)
2019-06-30 07:46:48,920 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074648907135
2019-06-30 07:46:48,942 [salt.minion      :1432][INFO    ][20368] Starting a new job with PID 20368
2019-06-30 07:46:48,967 [salt.minion      :1711][INFO    ][20368] Returning information for job: 20190630074648907135
2019-06-30 07:47:19,085 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074719072027
2019-06-30 07:47:19,107 [salt.minion      :1432][INFO    ][20429] Starting a new job with PID 20429
2019-06-30 07:47:19,127 [salt.minion      :1711][INFO    ][20429] Returning information for job: 20190630074719072027
2019-06-30 07:47:20,590 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1546.57142186s left)
2019-06-30 07:47:49,230 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074749217983
2019-06-30 07:47:49,253 [salt.minion      :1432][INFO    ][20455] Starting a new job with PID 20455
2019-06-30 07:47:49,278 [salt.minion      :1711][INFO    ][20455] Returning information for job: 20190630074749217983
2019-06-30 07:47:53,908 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1513.25335884s left)
2019-06-30 07:48:19,416 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074819403087
2019-06-30 07:48:19,438 [salt.minion      :1432][INFO    ][20512] Starting a new job with PID 20512
2019-06-30 07:48:19,464 [salt.minion      :1711][INFO    ][20512] Returning information for job: 20190630074819403087
2019-06-30 07:48:27,255 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1479.90597701s left)
2019-06-30 07:48:49,604 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074849590987
2019-06-30 07:48:49,627 [salt.minion      :1432][INFO    ][20530] Starting a new job with PID 20530
2019-06-30 07:48:49,651 [salt.minion      :1711][INFO    ][20530] Returning information for job: 20190630074849590987
2019-06-30 07:49:00,652 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1446.50928283s left)
2019-06-30 07:49:19,812 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074919800120
2019-06-30 07:49:19,835 [salt.minion      :1432][INFO    ][20585] Starting a new job with PID 20585
2019-06-30 07:49:19,858 [salt.minion      :1711][INFO    ][20585] Returning information for job: 20190630074919800120
2019-06-30 07:49:33,898 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1413.263623s left)
2019-06-30 07:49:50,011 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630074949998431
2019-06-30 07:49:50,034 [salt.minion      :1432][INFO    ][20605] Starting a new job with PID 20605
2019-06-30 07:49:50,060 [salt.minion      :1711][INFO    ][20605] Returning information for job: 20190630074949998431
2019-06-30 07:50:07,807 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1379.35394287s left)
2019-06-30 07:50:20,027 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075020014940
2019-06-30 07:50:20,050 [salt.minion      :1432][INFO    ][20675] Starting a new job with PID 20675
2019-06-30 07:50:20,074 [salt.minion      :1711][INFO    ][20675] Returning information for job: 20190630075020014940
2019-06-30 07:50:41,174 [salt.loaded.ext.module.maas:1023][INFO    ][16678] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1345.98735905s left)
2019-06-30 07:50:50,046 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075050038222
2019-06-30 07:50:50,062 [salt.minion      :1432][INFO    ][20702] Starting a new job with PID 20702
2019-06-30 07:50:50,084 [salt.minion      :1711][INFO    ][20702] Returning information for job: 20190630075050038222
2019-06-30 07:51:14,642 [salt.loaded.ext.module.maas:993 ][INFO    ][16678] Machine 8qd4tk mark broken
2019-06-30 07:51:15,387 [salt.loaded.ext.module.maas:996 ][INFO    ][16678] Machine 8qd4tk mark fixed
2019-06-30 07:51:16,515 [salt.loaded.ext.module.maas:684 ][INFO    ][16678] deploymachines hwe_kernel=hwe-16.04 system_id=8qd4tk distro_series=xenial
2019-06-30 07:51:19,114 [salt.loaded.ext.module.maas:160 ][ERROR   ][16678] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-06-30 07:51:19,116 [salt.state       :302 ][ERROR   ][16678] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-06-30 07:51:19,116 [salt.state       :1951][INFO    ][16678] Completed state [maas.wait_for_machine_status] at time 07:51:19.116794 duration_in_ms=941959.7
2019-06-30 07:51:19,122 [salt.minion      :1711][INFO    ][16678] Returning information for job: 20190630073531857938
2019-06-30 07:51:29,874 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command pillar.get with jid 20190630075129861715
2019-06-30 07:51:29,895 [salt.minion      :1432][INFO    ][20838] Starting a new job with PID 20838
2019-06-30 07:51:29,904 [salt.minion      :1711][INFO    ][20838] Returning information for job: 20190630075129861715
2019-06-30 07:51:30,404 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command service.status with jid 20190630075130391346
2019-06-30 07:51:30,426 [salt.minion      :1432][INFO    ][20843] Starting a new job with PID 20843
2019-06-30 07:51:30,823 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][20843] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:30,857 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][20843] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-30 07:51:30,872 [salt.minion      :1711][INFO    ][20843] Returning information for job: 20190630075130391346
2019-06-30 07:51:31,386 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630075131374237
2019-06-30 07:51:31,407 [salt.minion      :1432][INFO    ][20854] Starting a new job with PID 20854
2019-06-30 07:51:35,064 [salt.state       :915 ][INFO    ][20854] Loading fresh modules for state activity
2019-06-30 07:51:35,482 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:51:35,832 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:51:36,780 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:51:37,136 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'salt-minion --version' in directory '/root'
2019-06-30 07:51:38,568 [salt.state       :1780][INFO    ][20854] Running state [salt-minion] at time 07:51:38.568705
2019-06-30 07:51:38,569 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [salt-minion]
2019-06-30 07:51:38,569 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:51:38,653 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:38,653 [salt.state       :1951][INFO    ][20854] Completed state [salt-minion] at time 07:51:38.653297 duration_in_ms=84.593
2019-06-30 07:51:38,653 [salt.state       :1780][INFO    ][20854] Running state [salt_minion_dependency_packages] at time 07:51:38.653619
2019-06-30 07:51:38,653 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-30 07:51:38,659 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:38,659 [salt.state       :1951][INFO    ][20854] Completed state [salt_minion_dependency_packages] at time 07:51:38.659868 duration_in_ms=6.249
2019-06-30 07:51:38,662 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/minion.d/minion.conf] at time 07:51:38.662700
2019-06-30 07:51:38,662 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-30 07:51:38,844 [salt.state       :300 ][INFO    ][20854] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-30 07:51:38,844 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/minion.d/minion.conf] at time 07:51:38.844330 duration_in_ms=181.63
2019-06-30 07:51:38,844 [salt.state       :1780][INFO    ][20854] Running state [python-netaddr] at time 07:51:38.844514
2019-06-30 07:51:38,844 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [python-netaddr]
2019-06-30 07:51:38,848 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:38,849 [salt.state       :1951][INFO    ][20854] Completed state [python-netaddr] at time 07:51:38.849074 duration_in_ms=4.559
2019-06-30 07:51:38,851 [salt.state       :1780][INFO    ][20854] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 07:51:38.851061
2019-06-30 07:51:38,851 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-30 07:51:38,860 [salt.state       :300 ][INFO    ][20854] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-30 07:51:38,860 [salt.state       :1951][INFO    ][20854] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 07:51:38.860632 duration_in_ms=9.571
2019-06-30 07:51:38,861 [salt.state       :1780][INFO    ][20854] Running state [salt-minion] at time 07:51:38.861254
2019-06-30 07:51:38,861 [salt.state       :1813][INFO    ][20854] Executing state service.running for [salt-minion]
2019-06-30 07:51:38,861 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:38,899 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-30 07:51:38,918 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-30 07:51:38,937 [salt.state       :300 ][INFO    ][20854] The service salt-minion is already running
2019-06-30 07:51:38,938 [salt.state       :1951][INFO    ][20854] Completed state [salt-minion] at time 07:51:38.938188 duration_in_ms=76.933
2019-06-30 07:51:38,939 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains.d] at time 07:51:38.939648
2019-06-30 07:51:38,940 [salt.state       :1813][INFO    ][20854] Executing state file.directory for [/etc/salt/grains.d]
2019-06-30 07:51:38,940 [salt.state       :300 ][INFO    ][20854] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-30 07:51:38,941 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains.d] at time 07:51:38.941123 duration_in_ms=1.475
2019-06-30 07:51:38,941 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains] at time 07:51:38.941779
2019-06-30 07:51:38,942 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/grains]
2019-06-30 07:51:38,942 [salt.state       :300 ][INFO    ][20854] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-30 07:51:38,942 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains] at time 07:51:38.942813 duration_in_ms=1.034
2019-06-30 07:51:38,943 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains.d/placeholder] at time 07:51:38.943254
2019-06-30 07:51:38,943 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-30 07:51:38,944 [salt.state       :300 ][INFO    ][20854] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-30 07:51:38,944 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains.d/placeholder] at time 07:51:38.944238 duration_in_ms=0.984
2019-06-30 07:51:38,944 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains.d/sphinx] at time 07:51:38.944687
2019-06-30 07:51:38,944 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-30 07:51:38,957 [salt.state       :300 ][INFO    ][20854] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-30 07:51:38,958 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains.d/sphinx] at time 07:51:38.958074 duration_in_ms=13.387
2019-06-30 07:51:38,960 [salt.state       :1780][INFO    ][20854] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.960248
2019-06-30 07:51:38,960 [salt.state       :1813][INFO    ][20854] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:51:38,960 [salt.state       :300 ][INFO    ][20854] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:51:38,961 [salt.state       :1951][INFO    ][20854] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.961097 duration_in_ms=0.849
2019-06-30 07:51:38,961 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains.d/dns_records] at time 07:51:38.961554
2019-06-30 07:51:38,961 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-30 07:51:38,975 [salt.state       :300 ][INFO    ][20854] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-30 07:51:38,975 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains.d/dns_records] at time 07:51:38.975927 duration_in_ms=14.373
2019-06-30 07:51:38,976 [salt.state       :1780][INFO    ][20854] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.976818
2019-06-30 07:51:38,977 [salt.state       :1813][INFO    ][20854] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:51:38,977 [salt.state       :300 ][INFO    ][20854] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:51:38,977 [salt.state       :1951][INFO    ][20854] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.977692 duration_in_ms=0.874
2019-06-30 07:51:38,978 [salt.state       :1780][INFO    ][20854] Running state [/etc/salt/grains.d/salt] at time 07:51:38.978154
2019-06-30 07:51:38,978 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-30 07:51:38,987 [salt.state       :300 ][INFO    ][20854] File /etc/salt/grains.d/salt is in the correct state
2019-06-30 07:51:38,988 [salt.state       :1951][INFO    ][20854] Completed state [/etc/salt/grains.d/salt] at time 07:51:38.988051 duration_in_ms=9.897
2019-06-30 07:51:38,988 [salt.state       :1780][INFO    ][20854] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.988912
2019-06-30 07:51:38,989 [salt.state       :1813][INFO    ][20854] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-30 07:51:38,989 [salt.state       :300 ][INFO    ][20854] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-30 07:51:38,989 [salt.state       :1951][INFO    ][20854] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 07:51:38.989792 duration_in_ms=0.879
2019-06-30 07:51:38,991 [salt.state       :1780][INFO    ][20854] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 07:51:38.991623
2019-06-30 07:51:38,991 [salt.state       :1813][INFO    ][20854] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-30 07:51:38,992 [salt.state       :300 ][INFO    ][20854] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-30 07:51:38,992 [salt.state       :1951][INFO    ][20854] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 07:51:38.992472 duration_in_ms=0.849
2019-06-30 07:51:38,993 [salt.state       :1780][INFO    ][20854] Running state [mine.update] at time 07:51:38.993141
2019-06-30 07:51:38,993 [salt.state       :1813][INFO    ][20854] Executing state module.wait for [mine.update]
2019-06-30 07:51:38,993 [salt.state       :300 ][INFO    ][20854] No changes made for mine.update
2019-06-30 07:51:38,993 [salt.state       :1951][INFO    ][20854] Completed state [mine.update] at time 07:51:38.993942 duration_in_ms=0.801
2019-06-30 07:51:38,994 [salt.state       :1780][INFO    ][20854] Running state [ca-certificates] at time 07:51:38.994189
2019-06-30 07:51:38,994 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [ca-certificates]
2019-06-30 07:51:39,001 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:39,001 [salt.state       :1951][INFO    ][20854] Completed state [ca-certificates] at time 07:51:39.001748 duration_in_ms=7.558
2019-06-30 07:51:39,002 [salt.state       :1780][INFO    ][20854] Running state [update-ca-certificates] at time 07:51:39.002401
2019-06-30 07:51:39,002 [salt.state       :1813][INFO    ][20854] Executing state cmd.wait for [update-ca-certificates]
2019-06-30 07:51:39,003 [salt.state       :300 ][INFO    ][20854] No changes made for update-ca-certificates
2019-06-30 07:51:39,003 [salt.state       :1951][INFO    ][20854] Completed state [update-ca-certificates] at time 07:51:39.003201 duration_in_ms=0.8
2019-06-30 07:51:39,003 [salt.state       :1780][INFO    ][20854] Running state [iptables] at time 07:51:39.003435
2019-06-30 07:51:39,003 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [iptables]
2019-06-30 07:51:39,010 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:39,010 [salt.state       :1951][INFO    ][20854] Completed state [iptables] at time 07:51:39.010312 duration_in_ms=6.876
2019-06-30 07:51:39,010 [salt.state       :1780][INFO    ][20854] Running state [iptables-persistent] at time 07:51:39.010571
2019-06-30 07:51:39,010 [salt.state       :1813][INFO    ][20854] Executing state pkg.installed for [iptables-persistent]
2019-06-30 07:51:39,017 [salt.state       :300 ][INFO    ][20854] All specified packages are already installed
2019-06-30 07:51:39,017 [salt.state       :1951][INFO    ][20854] Completed state [iptables-persistent] at time 07:51:39.017325 duration_in_ms=6.754
2019-06-30 07:51:39,018 [salt.state       :1780][INFO    ][20854] Running state [iptables_modules_v4_load] at time 07:51:39.018251
2019-06-30 07:51:39,018 [salt.state       :1813][INFO    ][20854] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-30 07:51:39,019 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'lsmod' in directory '/root'
2019-06-30 07:51:39,043 [salt.state       :300 ][INFO    ][20854] Kernel modules iptable_filter, ip_tables are already present
2019-06-30 07:51:39,044 [salt.state       :1951][INFO    ][20854] Completed state [iptables_modules_v4_load] at time 07:51:39.044015 duration_in_ms=25.763
2019-06-30 07:51:39,044 [salt.state       :1780][INFO    ][20854] Running state [/etc/iptables/rules.v4] at time 07:51:39.044681
2019-06-30 07:51:39,045 [salt.state       :1813][INFO    ][20854] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-30 07:51:39,137 [salt.state       :300 ][INFO    ][20854] File /etc/iptables/rules.v4 is in the correct state
2019-06-30 07:51:39,137 [salt.state       :1951][INFO    ][20854] Completed state [/etc/iptables/rules.v4] at time 07:51:39.137938 duration_in_ms=93.257
2019-06-30 07:51:39,138 [salt.state       :1780][INFO    ][20854] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 07:51:39.138838
2019-06-30 07:51:39,139 [salt.state       :1813][INFO    ][20854] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-30 07:51:39,139 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-30 07:51:39,158 [salt.state       :300 ][INFO    ][20854] onlyif execution failed
2019-06-30 07:51:39,159 [salt.state       :1951][INFO    ][20854] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 07:51:39.159163 duration_in_ms=20.324
2019-06-30 07:51:39,160 [salt.state       :1780][INFO    ][20854] Running state [netfilter-persistent] at time 07:51:39.160808
2019-06-30 07:51:39,161 [salt.state       :1813][INFO    ][20854] Executing state service.running for [netfilter-persistent]
2019-06-30 07:51:39,162 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:39,183 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-30 07:51:39,202 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-30 07:51:39,220 [salt.state       :300 ][INFO    ][20854] The service netfilter-persistent is already running
2019-06-30 07:51:39,221 [salt.state       :1951][INFO    ][20854] Completed state [netfilter-persistent] at time 07:51:39.221226 duration_in_ms=60.418
2019-06-30 07:51:39,222 [salt.state       :1780][INFO    ][20854] Running state [iptables_extra.remove_stale_tables] at time 07:51:39.222539
2019-06-30 07:51:39,223 [salt.state       :1813][INFO    ][20854] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-30 07:51:39,223 [salt.state       :300 ][INFO    ][20854] No changes made for iptables_extra.remove_stale_tables
2019-06-30 07:51:39,223 [salt.state       :1951][INFO    ][20854] Completed state [iptables_extra.remove_stale_tables] at time 07:51:39.223917 duration_in_ms=1.378
2019-06-30 07:51:39,224 [salt.state       :1780][INFO    ][20854] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 07:51:39.224280
2019-06-30 07:51:39,224 [salt.state       :1813][INFO    ][20854] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-30 07:51:39,225 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20854] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-30 07:51:39,241 [salt.state       :300 ][INFO    ][20854] onlyif execution failed
2019-06-30 07:51:39,241 [salt.state       :1951][INFO    ][20854] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 07:51:39.241753 duration_in_ms=17.472
2019-06-30 07:51:39,243 [salt.state       :1780][INFO    ][20854] Running state [/etc/iptables/rules.v6] at time 07:51:39.243258
2019-06-30 07:51:39,243 [salt.state       :1813][INFO    ][20854] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-30 07:51:39,244 [salt.state       :300 ][INFO    ][20854] File /etc/iptables/rules.v6 is not present
2019-06-30 07:51:39,244 [salt.state       :1951][INFO    ][20854] Completed state [/etc/iptables/rules.v6] at time 07:51:39.244807 duration_in_ms=1.55
2019-06-30 07:51:39,245 [salt.state       :1780][INFO    ][20854] Running state [iptables_extra.flush_all] at time 07:51:39.245853
2019-06-30 07:51:39,246 [salt.state       :1813][INFO    ][20854] Executing state module.wait for [iptables_extra.flush_all]
2019-06-30 07:51:39,246 [salt.state       :300 ][INFO    ][20854] No changes made for iptables_extra.flush_all
2019-06-30 07:51:39,247 [salt.state       :1951][INFO    ][20854] Completed state [iptables_extra.flush_all] at time 07:51:39.247042 duration_in_ms=1.19
2019-06-30 07:51:39,251 [salt.minion      :1711][INFO    ][20854] Returning information for job: 20190630075131374237
2019-06-30 07:51:39,898 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630075139882783
2019-06-30 07:51:39,920 [salt.minion      :1432][INFO    ][20937] Starting a new job with PID 20937
2019-06-30 07:51:40,700 [salt.state       :915 ][INFO    ][20937] Loading fresh modules for state activity
2019-06-30 07:51:41,323 [salt.state       :1780][INFO    ][20937] Running state [maas-rack-controller] at time 07:51:41.323744
2019-06-30 07:51:41,324 [salt.state       :1813][INFO    ][20937] Executing state pkg.installed for [maas-rack-controller]
2019-06-30 07:51:41,324 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20937] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:51:41,424 [salt.state       :300 ][INFO    ][20937] All specified packages are already installed
2019-06-30 07:51:41,424 [salt.state       :1951][INFO    ][20937] Completed state [maas-rack-controller] at time 07:51:41.424849 duration_in_ms=101.106
2019-06-30 07:51:41,425 [salt.state       :1780][INFO    ][20937] Running state [ipmitool] at time 07:51:41.425211
2019-06-30 07:51:41,425 [salt.state       :1813][INFO    ][20937] Executing state pkg.installed for [ipmitool]
2019-06-30 07:51:41,432 [salt.state       :300 ][INFO    ][20937] All specified packages are already installed
2019-06-30 07:51:41,432 [salt.state       :1951][INFO    ][20937] Completed state [ipmitool] at time 07:51:41.432741 duration_in_ms=7.529
2019-06-30 07:51:41,435 [salt.state       :1780][INFO    ][20937] Running state [/etc/maas/rackd.conf] at time 07:51:41.435929
2019-06-30 07:51:41,436 [salt.state       :1813][INFO    ][20937] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-30 07:51:41,437 [salt.state       :300 ][INFO    ][20937] No changes needed to be made
2019-06-30 07:51:41,437 [salt.state       :1951][INFO    ][20937] Completed state [/etc/maas/rackd.conf] at time 07:51:41.437458 duration_in_ms=1.529
2019-06-30 07:51:41,437 [salt.state       :1780][INFO    ][20937] Running state [/etc/maas/rackd.conf] at time 07:51:41.437722
2019-06-30 07:51:41,437 [salt.state       :1813][INFO    ][20937] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-30 07:51:41,438 [salt.loaded.int.states.file:2298][WARNING ][20937] 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-06-30 07:51:41,439 [salt.state       :300 ][INFO    ][20937] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-30 07:51:41,439 [salt.state       :1951][INFO    ][20937] Completed state [/etc/maas/rackd.conf] at time 07:51:41.439248 duration_in_ms=1.526
2019-06-30 07:51:41,440 [salt.state       :1780][INFO    ][20937] Running state [maas-rackd] at time 07:51:41.440253
2019-06-30 07:51:41,440 [salt.state       :1813][INFO    ][20937] Executing state service.running for [maas-rackd]
2019-06-30 07:51:41,441 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20937] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:41,476 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20937] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-30 07:51:41,494 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20937] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-30 07:51:41,510 [salt.state       :300 ][INFO    ][20937] The service maas-rackd is already running
2019-06-30 07:51:41,511 [salt.state       :1951][INFO    ][20937] Completed state [maas-rackd] at time 07:51:41.511134 duration_in_ms=70.88
2019-06-30 07:51:41,512 [salt.minion      :1711][INFO    ][20937] Returning information for job: 20190630075139882783
2019-06-30 07:51:42,068 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630075142054213
2019-06-30 07:51:42,089 [salt.minion      :1432][INFO    ][20960] Starting a new job with PID 20960
2019-06-30 07:51:42,841 [salt.state       :915 ][INFO    ][20960] Loading fresh modules for state activity
2019-06-30 07:51:43,447 [salt.state       :1780][INFO    ][20960] Running state [maas-region-controller] at time 07:51:43.446971
2019-06-30 07:51:43,447 [salt.state       :1813][INFO    ][20960] Executing state pkg.installed for [maas-region-controller]
2019-06-30 07:51:43,447 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-30 07:51:43,519 [salt.state       :300 ][INFO    ][20960] All specified packages are already installed
2019-06-30 07:51:43,519 [salt.state       :1951][INFO    ][20960] Completed state [maas-region-controller] at time 07:51:43.519355 duration_in_ms=72.384
2019-06-30 07:51:43,519 [salt.state       :1780][INFO    ][20960] Running state [python-oauth] at time 07:51:43.519609
2019-06-30 07:51:43,519 [salt.state       :1813][INFO    ][20960] Executing state pkg.installed for [python-oauth]
2019-06-30 07:51:43,524 [salt.state       :300 ][INFO    ][20960] All specified packages are already installed
2019-06-30 07:51:43,524 [salt.state       :1951][INFO    ][20960] Completed state [python-oauth] at time 07:51:43.524391 duration_in_ms=4.782
2019-06-30 07:51:43,526 [salt.state       :1780][INFO    ][20960] Running state [/etc/maas/regiond.conf] at time 07:51:43.526732
2019-06-30 07:51:43,526 [salt.state       :1813][INFO    ][20960] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-30 07:51:43,569 [salt.state       :300 ][INFO    ][20960] No changes needed to be made
2019-06-30 07:51:43,569 [salt.state       :1951][INFO    ][20960] Completed state [/etc/maas/regiond.conf] at time 07:51:43.569704 duration_in_ms=42.972
2019-06-30 07:51:43,570 [salt.state       :1780][INFO    ][20960] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 07:51:43.570137
2019-06-30 07:51:43,570 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-30 07:51:43,628 [salt.state       :300 ][INFO    ][20960] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-30 07:51:43,628 [salt.state       :1951][INFO    ][20960] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 07:51:43.628855 duration_in_ms=58.718
2019-06-30 07:51:43,629 [salt.state       :1780][INFO    ][20960] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:51:43.629265
2019-06-30 07:51:43,629 [salt.state       :1813][INFO    ][20960] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-30 07:51:43,641 [salt.state       :300 ][INFO    ][20960] No changes needed to be made
2019-06-30 07:51:43,642 [salt.state       :1951][INFO    ][20960] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:51:43.642125 duration_in_ms=12.86
2019-06-30 07:51:43,642 [salt.state       :1780][INFO    ][20960] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:51:43.642552
2019-06-30 07:51:43,642 [salt.state       :1813][INFO    ][20960] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-30 07:51:43,671 [salt.state       :300 ][INFO    ][20960] No changes needed to be made
2019-06-30 07:51:43,672 [salt.state       :1951][INFO    ][20960] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 07:51:43.672128 duration_in_ms=29.576
2019-06-30 07:51:43,672 [salt.state       :1780][INFO    ][20960] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 07:51:43.672562
2019-06-30 07:51:43,672 [salt.state       :1813][INFO    ][20960] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-30 07:51:43,693 [salt.state       :300 ][INFO    ][20960] No changes needed to be made
2019-06-30 07:51:43,693 [salt.state       :1951][INFO    ][20960] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 07:51:43.693851 duration_in_ms=21.289
2019-06-30 07:51:43,694 [salt.state       :1780][INFO    ][20960] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 07:51:43.694250
2019-06-30 07:51:43,694 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-30 07:51:43,704 [salt.state       :300 ][INFO    ][20960] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-30 07:51:43,704 [salt.state       :1951][INFO    ][20960] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 07:51:43.704947 duration_in_ms=10.697
2019-06-30 07:51:43,706 [salt.state       :1780][INFO    ][20960] Running state [a2enmod headers] at time 07:51:43.706007
2019-06-30 07:51:43,706 [salt.state       :1813][INFO    ][20960] Executing state cmd.run for [a2enmod headers]
2019-06-30 07:51:43,706 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command 'a2enmod headers' in directory '/root'
2019-06-30 07:51:43,777 [salt.state       :300 ][INFO    ][20960] {'pid': 20979, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-30 07:51:43,778 [salt.state       :1951][INFO    ][20960] Completed state [a2enmod headers] at time 07:51:43.778180 duration_in_ms=72.172
2019-06-30 07:51:43,778 [salt.state       :1780][INFO    ][20960] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 07:51:43.778805
2019-06-30 07:51:43,779 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-30 07:51:43,798 [salt.state       :300 ][INFO    ][20960] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-30 07:51:43,799 [salt.state       :1951][INFO    ][20960] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 07:51:43.799003 duration_in_ms=20.199
2019-06-30 07:51:43,799 [salt.state       :1780][INFO    ][20960] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 07:51:43.799856
2019-06-30 07:51:43,800 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-30 07:51:43,880 [salt.state       :300 ][INFO    ][20960] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-30 07:51:43,881 [salt.state       :1951][INFO    ][20960] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 07:51:43.880952 duration_in_ms=81.097
2019-06-30 07:51:43,881 [salt.state       :1780][INFO    ][20960] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 07:51:43.881553
2019-06-30 07:51:43,881 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-30 07:51:43,946 [salt.state       :300 ][INFO    ][20960] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-30 07:51:43,946 [salt.state       :1951][INFO    ][20960] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 07:51:43.946857 duration_in_ms=65.305
2019-06-30 07:51:43,947 [salt.state       :1780][INFO    ][20960] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 07:51:43.947519
2019-06-30 07:51:43,947 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-30 07:51:44,018 [salt.state       :300 ][INFO    ][20960] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-30 07:51:44,019 [salt.state       :1951][INFO    ][20960] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 07:51:44.019529 duration_in_ms=72.009
2019-06-30 07:51:44,020 [salt.state       :1780][INFO    ][20960] Running state [/root/.pgpass] at time 07:51:44.019977
2019-06-30 07:51:44,020 [salt.state       :1813][INFO    ][20960] Executing state file.managed for [/root/.pgpass]
2019-06-30 07:51:44,072 [salt.state       :300 ][INFO    ][20960] File /root/.pgpass is in the correct state
2019-06-30 07:51:44,072 [salt.state       :1951][INFO    ][20960] Completed state [/root/.pgpass] at time 07:51:44.072272 duration_in_ms=52.295
2019-06-30 07:51:44,077 [salt.state       :1780][INFO    ][20960] Running state [maas-region syncdb --noinput] at time 07:51:44.077281
2019-06-30 07:51:44,077 [salt.state       :1813][INFO    ][20960] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-30 07:51:44,078 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-30 07:51:45,957 [salt.state       :300 ][INFO    ][20960] {'pid': 20992, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: metadataserver, piston3, sites, contenttypes, sessions, maasserver, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-30 07:51:45,957 [salt.state       :1951][INFO    ][20960] Completed state [maas-region syncdb --noinput] at time 07:51:45.957944 duration_in_ms=1880.663
2019-06-30 07:51:45,958 [salt.state       :2022][WARNING ][20960] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-30 07:51:45,959 [salt.state       :1780][INFO    ][20960] Running state [maas-regiond] at time 07:51:45.959125
2019-06-30 07:51:45,959 [salt.state       :1813][INFO    ][20960] Executing state service.running for [maas-regiond]
2019-06-30 07:51:45,959 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:45,992 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-30 07:51:46,008 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-30 07:51:46,023 [salt.state       :300 ][INFO    ][20960] The service maas-regiond is already running
2019-06-30 07:51:46,023 [salt.state       :1951][INFO    ][20960] Completed state [maas-regiond] at time 07:51:46.023355 duration_in_ms=64.23
2019-06-30 07:51:46,024 [salt.state       :1780][INFO    ][20960] Running state [bind9] at time 07:51:46.024346
2019-06-30 07:51:46,024 [salt.state       :1813][INFO    ][20960] Executing state service.running for [bind9]
2019-06-30 07:51:46,024 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:46,040 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-30 07:51:46,054 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-30 07:51:46,068 [salt.state       :300 ][INFO    ][20960] The service bind9 is already running
2019-06-30 07:51:46,068 [salt.state       :1951][INFO    ][20960] Completed state [bind9] at time 07:51:46.068573 duration_in_ms=44.227
2019-06-30 07:51:46,069 [salt.state       :1780][INFO    ][20960] Running state [apache2] at time 07:51:46.069531
2019-06-30 07:51:46,069 [salt.state       :1813][INFO    ][20960] Executing state service.running for [apache2]
2019-06-30 07:51:46,070 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-30 07:51:46,085 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-30 07:51:46,099 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-30 07:51:46,116 [salt.state       :300 ][INFO    ][20960] The service apache2 is already running
2019-06-30 07:51:46,116 [salt.state       :1951][INFO    ][20960] Completed state [apache2] at time 07:51:46.116928 duration_in_ms=47.396
2019-06-30 07:51:46,117 [salt.state       :1780][INFO    ][20960] Running state [maasng.wait_for_http_code] at time 07:51:46.117760
2019-06-30 07:51:46,117 [salt.state       :1813][INFO    ][20960] Executing state module.run for [maasng.wait_for_http_code]
2019-06-30 07:51:46,118 [salt.utils.decorators:613 ][WARNING ][20960] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:51:46,124 [salt.state       :300 ][INFO    ][20960] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-30 07:51:46,124 [salt.state       :1951][INFO    ][20960] Completed state [maasng.wait_for_http_code] at time 07:51:46.124622 duration_in_ms=6.861
2019-06-30 07:51:46,126 [salt.state       :1780][INFO    ][20960] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 07:51:46.126005
2019-06-30 07:51:46,126 [salt.state       :1813][INFO    ][20960] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-30 07:51:46,127 [salt.state       :300 ][INFO    ][20960] /var/lib/maas/.setup_admin exists
2019-06-30 07:51:46,127 [salt.state       :1951][INFO    ][20960] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 07:51:46.127641 duration_in_ms=1.636
2019-06-30 07:51:46,128 [salt.state       :1780][INFO    ][20960] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:51:46.128799
2019-06-30 07:51:46,129 [salt.state       :1813][INFO    ][20960] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:51:46,130 [salt.loaded.int.module.cmdmod:395 ][INFO    ][20960] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:51:47,577 [salt.state       :300 ][INFO    ][20960] {'pid': 21011, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:51:47,577 [salt.state       :1951][INFO    ][20960] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:51:47.577838 duration_in_ms=1449.039
2019-06-30 07:51:47,582 [salt.state       :1780][INFO    ][20960] Running state [maas_region_boot_source_resources_mirror] at time 07:51:47.582631
2019-06-30 07:51:47,582 [salt.state       :1813][INFO    ][20960] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-30 07:51:47,683 [salt.state       :300 ][INFO    ][20960] {'changes': {}}
2019-06-30 07:51:47,684 [salt.state       :1951][INFO    ][20960] Completed state [maas_region_boot_source_resources_mirror] at time 07:51:47.684075 duration_in_ms=101.443
2019-06-30 07:51:47,685 [salt.state       :1780][INFO    ][20960] Running state [maasng.boot_resources_import] at time 07:51:47.684946
2019-06-30 07:51:47,685 [salt.state       :1813][INFO    ][20960] Executing state module.run for [maasng.boot_resources_import]
2019-06-30 07:51:47,685 [salt.utils.decorators:613 ][WARNING ][20960] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:51:47,804 [salt.loaded.ext.module.maasng:1600][INFO    ][20960] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-30 07:51:52,878 [salt.loaded.ext.module.maasng:1600][INFO    ][20960] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-30 07:51:57,130 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075157110701
2019-06-30 07:51:57,155 [salt.minion      :1432][INFO    ][21043] Starting a new job with PID 21043
2019-06-30 07:51:57,180 [salt.minion      :1711][INFO    ][21043] Returning information for job: 20190630075157110701
2019-06-30 07:51:57,937 [salt.loaded.ext.module.maasng:1600][INFO    ][20960] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-30 07:52:03,057 [salt.state       :300 ][INFO    ][20960] {'ret': True}
2019-06-30 07:52:03,058 [salt.state       :1951][INFO    ][20960] Completed state [maasng.boot_resources_import] at time 07:52:03.058359 duration_in_ms=15373.413
2019-06-30 07:52:03,059 [salt.state       :1780][INFO    ][20960] Running state [maas_region_boot_sources_selection_xenial] at time 07:52:03.059674
2019-06-30 07:52:03,060 [salt.state       :1813][INFO    ][20960] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-30 07:52:03,273 [salt.state       :300 ][INFO    ][20960] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-30 07:52:03,273 [salt.state       :1951][INFO    ][20960] Completed state [maas_region_boot_sources_selection_xenial] at time 07:52:03.273403 duration_in_ms=213.73
2019-06-30 07:52:03,274 [salt.state       :1780][INFO    ][20960] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 07:52:03.274789
2019-06-30 07:52:03,275 [salt.state       :1813][INFO    ][20960] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-30 07:52:03,275 [salt.utils.decorators:613 ][WARNING ][20960] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:52:03,276 [salt.loaded.ext.module.maasng:1771][INFO    ][20960] boot-sources sync initiated for ALL Rack's
2019-06-30 07:52:04,273 [salt.state       :300 ][INFO    ][20960] {'ret': True}
2019-06-30 07:52:04,274 [salt.state       :1951][INFO    ][20960] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 07:52:04.273930 duration_in_ms=999.141
2019-06-30 07:52:04,276 [salt.state       :1780][INFO    ][20960] Running state [maas.process_maas_config] at time 07:52:04.275983
2019-06-30 07:52:04,276 [salt.state       :1813][INFO    ][20960] Executing state module.run for [maas.process_maas_config]
2019-06-30 07:52:04,277 [salt.utils.decorators:613 ][WARNING ][20960] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:52:04,278 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=enable_http_proxy value=True
2019-06-30 07:52:04,340 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=upstream_dns value=8.8.8.8
2019-06-30 07:52:04,405 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=commissioning_distro_series value=xenial
2019-06-30 07:52:04,470 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=default_osystem value=ubuntu
2019-06-30 07:52:04,530 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=active_discovery_interval value=600
2019-06-30 07:52:04,578 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=dnssec_validation value=no
2019-06-30 07:52:04,638 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=maas_name value=mas01
2019-06-30 07:52:04,704 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=network_discovery value=enabled
2019-06-30 07:52:04,824 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=enable_third_party_drivers value=True
2019-06-30 07:52:07,532 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=default_storage_layout value=lvm
2019-06-30 07:52:07,610 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=ntp_external_only value=True
2019-06-30 07:52:07,669 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-30 07:52:07,743 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=default_distro_series value=xenial
2019-06-30 07:52:07,868 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-30 07:52:08,084 [salt.state       :300 ][INFO    ][20960] {'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-06-30 07:52:08,085 [salt.state       :1951][INFO    ][20960] Completed state [maas.process_maas_config] at time 07:52:08.085232 duration_in_ms=3809.247
2019-06-30 07:52:08,086 [salt.state       :1780][INFO    ][20960] Running state [pxe_admin] at time 07:52:08.086401
2019-06-30 07:52:08,086 [salt.state       :1813][INFO    ][20960] Executing state maasng.fabric_present for [pxe_admin]
2019-06-30 07:52:08,185 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:52:08,261 [salt.loaded.ext.module.maasng:1008][WARNING ][20960] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-30 07:52:08,262 [salt.loaded.ext.module.maasng:1011][WARNING ][20960] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-30 07:52:08,327 [salt.state       :300 ][INFO    ][20960] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-30 07:52:08,327 [salt.state       :1951][INFO    ][20960] Completed state [pxe_admin] at time 07:52:08.327713 duration_in_ms=241.312
2019-06-30 07:52:08,328 [salt.state       :1780][INFO    ][20960] Running state [vlan 0] at time 07:52:08.328055
2019-06-30 07:52:08,328 [salt.state       :1813][INFO    ][20960] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-30 07:52:08,399 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wr8cxf', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:52:08,507 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-30 07:52:08,764 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-30 07:52:08,870 [salt.state       :300 ][INFO    ][20960] {'new': 'Vlan untagged was updated'}
2019-06-30 07:52:08,871 [salt.state       :1951][INFO    ][20960] Completed state [vlan 0] at time 07:52:08.871147 duration_in_ms=543.09
2019-06-30 07:52:08,872 [salt.state       :1780][INFO    ][20960] Running state [192.168.11.0/24] at time 07:52:08.872677
2019-06-30 07:52:08,873 [salt.state       :1813][INFO    ][20960] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-30 07:52:09,082 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wr8cxf', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:52:09,083 [salt.loaded.ext.module.maasng:1235][WARNING ][20960] Ignoring parameter vlan:0
2019-06-30 07:52:09,129 [salt.state       :300 ][INFO    ][20960] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-30 07:52:09,129 [salt.state       :1951][INFO    ][20960] Completed state [192.168.11.0/24] at time 07:52:09.129739 duration_in_ms=257.062
2019-06-30 07:52:09,130 [salt.state       :1780][INFO    ][20960] Running state [maas_create_iprange_1] at time 07:52:09.130836
2019-06-30 07:52:09,131 [salt.state       :1813][INFO    ][20960] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-30 07:52:09,183 [salt.state       :300 ][INFO    ][20960] Iprange maas_create_iprange_1 already exist.
2019-06-30 07:52:09,183 [salt.state       :1951][INFO    ][20960] Completed state [maas_create_iprange_1] at time 07:52:09.183645 duration_in_ms=52.809
2019-06-30 07:52:09,183 [salt.state       :1780][INFO    ][20960] Running state [vlan 0] at time 07:52:09.183941
2019-06-30 07:52:09,184 [salt.state       :1813][INFO    ][20960] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-30 07:52:09,244 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'id': 0, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'wr8cxf', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:52:09,352 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-06-30 07:52:09,580 [salt.loaded.ext.module.maasng:945 ][INFO    ][20960] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'wr8cxf', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-30 07:52:09,683 [salt.state       :300 ][INFO    ][20960] {'new': 'Vlan untagged was updated'}
2019-06-30 07:52:09,684 [salt.state       :1951][INFO    ][20960] Completed state [vlan 0] at time 07:52:09.683990 duration_in_ms=500.048
2019-06-30 07:52:09,684 [salt.state       :1780][INFO    ][20960] Running state [opnfv] at time 07:52:09.684516
2019-06-30 07:52:09,684 [salt.state       :1813][INFO    ][20960] Executing state maasng.sshkey_present for [opnfv]
2019-06-30 07:52:09,729 [salt.loaded.ext.module.maasng:1903][INFO    ][20960] [{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-06-30 07:52:09,730 [salt.state       :300 ][INFO    ][20960] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-30 07:52:09,730 [salt.state       :1951][INFO    ][20960] Completed state [opnfv] at time 07:52:09.730707 duration_in_ms=46.189
2019-06-30 07:52:09,731 [salt.state       :1780][INFO    ][20960] Running state [maas.process_tags] at time 07:52:09.731669
2019-06-30 07:52:09,732 [salt.state       :1813][INFO    ][20960] Executing state module.run for [maas.process_tags]
2019-06-30 07:52:09,732 [salt.utils.decorators:613 ][WARNING ][20960] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:52:09,771 [salt.loaded.ext.module.maas:92  ][INFO    ][20960] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-30 07:52:09,843 [salt.state       :300 ][INFO    ][20960] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-30 07:52:09,844 [salt.state       :1951][INFO    ][20960] Completed state [maas.process_tags] at time 07:52:09.844017 duration_in_ms=112.348
2019-06-30 07:52:09,865 [salt.minion      :1711][INFO    ][20960] Returning information for job: 20190630075142054213
2019-06-30 07:52:10,386 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630075210373676
2019-06-30 07:52:10,404 [salt.minion      :1432][INFO    ][21438] Starting a new job with PID 21438
2019-06-30 07:52:14,078 [salt.state       :915 ][INFO    ][21438] Loading fresh modules for state activity
2019-06-30 07:52:14,154 [salt.state       :1780][INFO    ][21438] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:52:14.154473
2019-06-30 07:52:14,154 [salt.state       :1813][INFO    ][21438] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:52:14,156 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21438] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:52:15,616 [salt.state       :300 ][INFO    ][21438] {'pid': 21464, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:52:15,617 [salt.state       :1951][INFO    ][21438] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:52:15.617253 duration_in_ms=1462.781
2019-06-30 07:52:15,618 [salt.state       :1780][INFO    ][21438] Running state [maas.process_machines] at time 07:52:15.618462
2019-06-30 07:52:15,618 [salt.state       :1813][INFO    ][21438] Executing state module.run for [maas.process_machines]
2019-06-30 07:52:15,619 [salt.utils.decorators:613 ][WARNING ][21438] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:52:16,329 [salt.loaded.ext.module.maas:412 ][WARNING ][21438] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:52:16,330 [salt.loaded.ext.module.maas:92  ][INFO    ][21438] 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=yfxpre architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:52:17,835 [salt.loaded.ext.module.maas:412 ][WARNING ][21438] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:52:17,835 [salt.loaded.ext.module.maas:92  ][INFO    ][21438] 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=8aqah8 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:52:19,163 [salt.loaded.ext.module.maas:412 ][WARNING ][21438] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:52:19,164 [salt.loaded.ext.module.maas:92  ][INFO    ][21438] 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=gxwwcp architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:52:20,474 [salt.loaded.ext.module.maas:412 ][WARNING ][21438] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:52:20,475 [salt.loaded.ext.module.maas:92  ][INFO    ][21438] 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=dtn7s4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:52:21,773 [salt.loaded.ext.module.maas:412 ][WARNING ][21438] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-30 07:52:21,774 [salt.loaded.ext.module.maas:92  ][INFO    ][21438] 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=8qd4tk architecture=amd64/generic power_parameters_power_user=admin
2019-06-30 07:52:23,055 [salt.state       :300 ][INFO    ][21438] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-30 07:52:23,056 [salt.state       :1951][INFO    ][21438] Completed state [maas.process_machines] at time 07:52:23.055957 duration_in_ms=7437.492
2019-06-30 07:52:23,059 [salt.minion      :1711][INFO    ][21438] Returning information for job: 20190630075210373676
2019-06-30 07:52:55,690 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630075255675500
2019-06-30 07:52:55,706 [salt.minion      :1432][INFO    ][21691] Starting a new job with PID 21691
2019-06-30 07:52:59,178 [salt.state       :915 ][INFO    ][21691] Loading fresh modules for state activity
2019-06-30 07:52:59,228 [salt.state       :1780][INFO    ][21691] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:52:59.228287
2019-06-30 07:52:59,228 [salt.state       :1813][INFO    ][21691] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 07:52:59,230 [salt.loaded.int.module.cmdmod:395 ][INFO    ][21691] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 07:53:00,676 [salt.state       :300 ][INFO    ][21691] {'pid': 21698, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 07:53:00,677 [salt.state       :1951][INFO    ][21691] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 07:53:00.677384 duration_in_ms=1449.096
2019-06-30 07:53:00,680 [salt.state       :1780][INFO    ][21691] Running state [maas.wait_for_machine_status] at time 07:53:00.680614
2019-06-30 07:53:00,681 [salt.state       :1813][INFO    ][21691] Executing state module.run for [maas.wait_for_machine_status]
2019-06-30 07:53:00,681 [salt.utils.decorators:613 ][WARNING ][21691] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 07:53:03,976 [salt.loaded.ext.module.maas:993 ][INFO    ][21691] Machine 8qd4tk mark broken
2019-06-30 07:53:04,594 [salt.loaded.ext.module.maas:996 ][INFO    ][21691] Machine 8qd4tk mark fixed
2019-06-30 07:53:05,694 [salt.loaded.ext.module.maas:684 ][INFO    ][21691] deploymachines hwe_kernel=hwe-16.04 system_id=8qd4tk distro_series=xenial
2019-06-30 07:53:08,433 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1492.26402497s left)
2019-06-30 07:53:10,754 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075310691091
2019-06-30 07:53:10,777 [salt.minion      :1432][INFO    ][21811] Starting a new job with PID 21811
2019-06-30 07:53:10,806 [salt.minion      :1711][INFO    ][21811] Returning information for job: 20190630075310691091
2019-06-30 07:53:40,805 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075340790540
2019-06-30 07:53:40,828 [salt.minion      :1432][INFO    ][21835] Starting a new job with PID 21835
2019-06-30 07:53:40,855 [salt.minion      :1711][INFO    ][21835] Returning information for job: 20190630075340790540
2019-06-30 07:53:41,906 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1458.79064894s left)
2019-06-30 07:54:10,890 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075410878419
2019-06-30 07:54:10,912 [salt.minion      :1432][INFO    ][21883] Starting a new job with PID 21883
2019-06-30 07:54:10,941 [salt.minion      :1711][INFO    ][21883] Returning information for job: 20190630075410878419
2019-06-30 07:54:15,378 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1425.31889486s left)
2019-06-30 07:54:40,942 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075440929258
2019-06-30 07:54:40,967 [salt.minion      :1432][INFO    ][21902] Starting a new job with PID 21902
2019-06-30 07:54:40,994 [salt.minion      :1711][INFO    ][21902] Returning information for job: 20190630075440929258
2019-06-30 07:54:48,190 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1392.50719786s left)
2019-06-30 07:55:11,003 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075510990993
2019-06-30 07:55:11,027 [salt.minion      :1432][INFO    ][22066] Starting a new job with PID 22066
2019-06-30 07:55:11,055 [salt.minion      :1711][INFO    ][22066] Returning information for job: 20190630075510990993
2019-06-30 07:55:21,711 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1358.98591805s left)
2019-06-30 07:55:41,061 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075541048298
2019-06-30 07:55:41,084 [salt.minion      :1432][INFO    ][22092] Starting a new job with PID 22092
2019-06-30 07:55:41,118 [salt.minion      :1711][INFO    ][22092] Returning information for job: 20190630075541048298
2019-06-30 07:55:55,529 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1325.16816092s left)
2019-06-30 07:56:11,128 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075611115428
2019-06-30 07:56:11,148 [salt.minion      :1432][INFO    ][22249] Starting a new job with PID 22249
2019-06-30 07:56:11,174 [salt.minion      :1711][INFO    ][22249] Returning information for job: 20190630075611115428
2019-06-30 07:56:29,210 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1291.48684192s left)
2019-06-30 07:56:41,185 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075641172899
2019-06-30 07:56:41,209 [salt.minion      :1432][INFO    ][22269] Starting a new job with PID 22269
2019-06-30 07:56:41,237 [salt.minion      :1711][INFO    ][22269] Returning information for job: 20190630075641172899
2019-06-30 07:57:02,887 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1257.80992889s left)
2019-06-30 07:57:11,254 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075711240907
2019-06-30 07:57:11,277 [salt.minion      :1432][INFO    ][22366] Starting a new job with PID 22366
2019-06-30 07:57:11,302 [salt.minion      :1711][INFO    ][22366] Returning information for job: 20190630075711240907
2019-06-30 07:57:36,137 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1224.55944991s left)
2019-06-30 07:57:41,320 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075741307669
2019-06-30 07:57:41,343 [salt.minion      :1432][INFO    ][22390] Starting a new job with PID 22390
2019-06-30 07:57:41,370 [salt.minion      :1711][INFO    ][22390] Returning information for job: 20190630075741307669
2019-06-30 07:58:09,235 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1191.46156001s left)
2019-06-30 07:58:11,401 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075811388377
2019-06-30 07:58:11,424 [salt.minion      :1432][INFO    ][22527] Starting a new job with PID 22527
2019-06-30 07:58:11,450 [salt.minion      :1711][INFO    ][22527] Returning information for job: 20190630075811388377
2019-06-30 07:58:41,479 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075841464586
2019-06-30 07:58:41,502 [salt.minion      :1432][INFO    ][22553] Starting a new job with PID 22553
2019-06-30 07:58:41,527 [salt.minion      :1711][INFO    ][22553] Returning information for job: 20190630075841464586
2019-06-30 07:58:42,970 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1157.72735s left)
2019-06-30 07:59:11,563 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075911550310
2019-06-30 07:59:11,586 [salt.minion      :1432][INFO    ][22652] Starting a new job with PID 22652
2019-06-30 07:59:11,612 [salt.minion      :1711][INFO    ][22652] Returning information for job: 20190630075911550310
2019-06-30 07:59:16,482 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1124.21462893s left)
2019-06-30 07:59:41,651 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630075941638090
2019-06-30 07:59:41,675 [salt.minion      :1432][INFO    ][22675] Starting a new job with PID 22675
2019-06-30 07:59:41,701 [salt.minion      :1711][INFO    ][22675] Returning information for job: 20190630075941638090
2019-06-30 07:59:50,145 [salt.loaded.ext.module.maas:1023][INFO    ][21691] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1090.55212283s left)
2019-06-30 08:00:11,749 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command saltutil.find_job with jid 20190630080011736717
2019-06-30 08:00:11,773 [salt.minion      :1432][INFO    ][22762] Starting a new job with PID 22762
2019-06-30 08:00:11,800 [salt.minion      :1711][INFO    ][22762] Returning information for job: 20190630080011736717
2019-06-30 08:00:23,684 [salt.state       :300 ][INFO    ][21691] {'ret': True}
2019-06-30 08:00:23,685 [salt.state       :1951][INFO    ][21691] Completed state [maas.wait_for_machine_status] at time 08:00:23.685159 duration_in_ms=443004.543
2019-06-30 08:00:23,689 [salt.minion      :1711][INFO    ][21691] Returning information for job: 20190630075255675500
2019-06-30 08:00:24,301 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630080024288851
2019-06-30 08:00:24,324 [salt.minion      :1432][INFO    ][22798] Starting a new job with PID 22798
2019-06-30 08:00:27,930 [salt.state       :915 ][INFO    ][22798] Loading fresh modules for state activity
2019-06-30 08:00:28,001 [salt.state       :1780][INFO    ][22798] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:28.001715
2019-06-30 08:00:28,001 [salt.state       :1813][INFO    ][22798] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 08:00:28,002 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22798] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 08:00:29,137 [salt.state       :300 ][INFO    ][22798] {'pid': 22807, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 08:00:29,137 [salt.state       :1951][INFO    ][22798] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:29.137844 duration_in_ms=1136.129
2019-06-30 08:00:29,139 [salt.state       :1780][INFO    ][22798] Running state [maas_machines_storage_cmp002_lvm] at time 08:00:29.139178
2019-06-30 08:00:29,139 [salt.state       :1813][INFO    ][22798] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-30 08:00:29,876 [salt.state       :300 ][INFO    ][22798] Machine cmp002 is not in Ready state.
2019-06-30 08:00:29,877 [salt.state       :1951][INFO    ][22798] Completed state [maas_machines_storage_cmp002_lvm] at time 08:00:29.877325 duration_in_ms=738.144
2019-06-30 08:00:29,878 [salt.state       :1780][INFO    ][22798] Running state [maas_machines_storage_cmp001_lvm] at time 08:00:29.877938
2019-06-30 08:00:29,878 [salt.state       :1813][INFO    ][22798] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-30 08:00:30,618 [salt.state       :300 ][INFO    ][22798] Machine cmp001 is not in Ready state.
2019-06-30 08:00:30,619 [salt.state       :1951][INFO    ][22798] Completed state [maas_machines_storage_cmp001_lvm] at time 08:00:30.619085 duration_in_ms=741.145
2019-06-30 08:00:30,623 [salt.minion      :1711][INFO    ][22798] Returning information for job: 20190630080024288851
2019-06-30 08:00:31,127 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630080031115511
2019-06-30 08:00:31,146 [salt.minion      :1432][INFO    ][22818] Starting a new job with PID 22818
2019-06-30 08:00:31,826 [salt.state       :915 ][INFO    ][22818] Loading fresh modules for state activity
2019-06-30 08:00:31,876 [salt.state       :1780][INFO    ][22818] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:31.876417
2019-06-30 08:00:31,876 [salt.state       :1813][INFO    ][22818] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 08:00:31,878 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22818] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 08:00:33,339 [salt.state       :300 ][INFO    ][22818] {'pid': 22833, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 08:00:33,340 [salt.state       :1951][INFO    ][22818] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:33.340347 duration_in_ms=1463.928
2019-06-30 08:00:33,343 [salt.state       :1780][INFO    ][22818] Running state [maas.deploy_machines] at time 08:00:33.342963
2019-06-30 08:00:33,343 [salt.state       :1813][INFO    ][22818] Executing state module.run for [maas.deploy_machines]
2019-06-30 08:00:33,344 [salt.utils.decorators:613 ][WARNING ][22818] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 08:00:33,895 [salt.state       :300 ][INFO    ][22818] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-30 08:00:33,895 [salt.state       :1951][INFO    ][22818] Completed state [maas.deploy_machines] at time 08:00:33.895854 duration_in_ms=552.89
2019-06-30 08:00:33,899 [salt.minion      :1711][INFO    ][22818] Returning information for job: 20190630080031115511
2019-06-30 08:00:34,491 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command state.apply with jid 20190630080034479781
2019-06-30 08:00:34,514 [salt.minion      :1432][INFO    ][22843] Starting a new job with PID 22843
2019-06-30 08:00:35,241 [salt.state       :915 ][INFO    ][22843] Loading fresh modules for state activity
2019-06-30 08:00:35,333 [salt.state       :1780][INFO    ][22843] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:35.333183
2019-06-30 08:00:35,333 [salt.state       :1813][INFO    ][22843] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-30 08:00:35,335 [salt.loaded.int.module.cmdmod:395 ][INFO    ][22843] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-30 08:00:36,786 [salt.state       :300 ][INFO    ][22843] {'pid': 22850, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-30 08:00:36,787 [salt.state       :1951][INFO    ][22843] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:00:36.787001 duration_in_ms=1453.819
2019-06-30 08:00:36,788 [salt.state       :1780][INFO    ][22843] Running state [maas.wait_for_machine_status] at time 08:00:36.788495
2019-06-30 08:00:36,788 [salt.state       :1813][INFO    ][22843] Executing state module.run for [maas.wait_for_machine_status]
2019-06-30 08:00:36,789 [salt.utils.decorators:613 ][WARNING ][22843] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-30 08:00:40,013 [salt.state       :300 ][INFO    ][22843] {'ret': True}
2019-06-30 08:00:40,013 [salt.state       :1951][INFO    ][22843] Completed state [maas.wait_for_machine_status] at time 08:00:40.013386 duration_in_ms=3224.889
2019-06-30 08:00:40,016 [salt.minion      :1711][INFO    ][22843] Returning information for job: 20190630080034479781
2019-06-30 08:19:07,812 [salt.utils.schedule:1377][INFO    ][11479] Running scheduled job: __mine_interval
2019-06-30 09:19:07,812 [salt.utils.schedule:1377][INFO    ][11479] Running scheduled job: __mine_interval
2019-06-30 09:27:18,125 [salt.minion      :1308][INFO    ][11479] User sudo_ubuntu Executing command cp.push_dir with jid 20190630092718111601
2019-06-30 09:27:18,143 [salt.minion      :1432][INFO    ][29317] Starting a new job with PID 29317
