2019-11-20 12:12:47,395 [salt.utils.decorators:613 ][WARNING ][2030] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:12:47,878 [salt.utils.decorators:613 ][WARNING ][2030] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:12:50,029 [salt.loaded.int.states.file:2298][WARNING ][2334] 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-11-20 12:13:16,827 [salt.state       :2022][WARNING ][2979] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-20 12:13:20,149 [salt.utils.decorators:613 ][WARNING ][2979] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:14:08,793 [salt.utils.decorators:613 ][WARNING ][2979] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:14:44,689 [salt.utils.decorators:613 ][WARNING ][2979] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:29:44,928 [salt.utils.decorators:613 ][WARNING ][2979] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:29:48,445 [salt.loaded.ext.module.maas:160 ][ERROR   ][2979] Failed for object default_distro_series reason {"default_distro_series": ["'xenial' is not a valid release.  It should be one of: 'bionic'."]}
2019-11-20 12:29:48,548 [salt.state       :302 ][ERROR   ][2979] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'default_distro_series': '{"default_distro_series": ["\'xenial\' is not a valid release.  It should be one of: \'bionic\'."]}'}, '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_min_hwe_kernel']}
2019-11-20 12:29:48,648 [salt.loaded.ext.module.maasng:1008][WARNING ][2979] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-11-20 12:29:48,649 [salt.loaded.ext.module.maasng:1011][WARNING ][2979] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-11-20 12:29:49,230 [salt.loaded.ext.module.maasng:1235][WARNING ][2979] Ignoring parameter vlan:0
2019-11-20 12:29:50,164 [salt.utils.decorators:613 ][WARNING ][2979] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:29:53,035 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28531] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-20 12:29:53,072 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28531] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-11-20 12:29:53,097 [salt.utils.parsers:1051][WARNING ][317] Minion received a SIGTERM. Exiting.
2019-11-20 12:29:54,172 [salt.cli.daemons :293 ][INFO    ][28576] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-11-20 12:29:54,272 [salt.cli.daemons :82  ][INFO    ][28576] Starting up the Salt Minion
2019-11-20 12:29:54,272 [salt.utils.event :1017][INFO    ][28576] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-11-20 12:29:55,247 [salt.minion      :976 ][INFO    ][28576] Creating minion process manager
2019-11-20 12:29:56,726 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][28576] Executing command ['date', '+%z'] in directory '/root'
2019-11-20 12:29:56,746 [salt.utils.schedule:568 ][INFO    ][28576] Updating job settings for scheduled job: __mine_interval
2019-11-20 12:29:56,747 [salt.minion      :1108][INFO    ][28576] Added mine.update to scheduler
2019-11-20 12:29:56,750 [salt.minion      :1975][INFO    ][28576] Minion is starting as user 'root'
2019-11-20 12:29:56,762 [salt.minion      :2336][INFO    ][28576] Minion is ready to receive requests!
2019-11-20 12:30:00,963 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123000948111
2019-11-20 12:30:00,986 [salt.minion      :1432][INFO    ][28658] Starting a new job with PID 28658
2019-11-20 12:30:04,755 [salt.state       :915 ][INFO    ][28658] Loading fresh modules for state activity
2019-11-20 12:30:05,478 [salt.state       :1780][INFO    ][28658] Running state [maas-region-controller] at time 12:30:05.478101
2019-11-20 12:30:05,478 [salt.state       :1813][INFO    ][28658] Executing state pkg.installed for [maas-region-controller]
2019-11-20 12:30:05,478 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-20 12:30:05,553 [salt.state       :300 ][INFO    ][28658] All specified packages are already installed
2019-11-20 12:30:05,553 [salt.state       :1951][INFO    ][28658] Completed state [maas-region-controller] at time 12:30:05.553893 duration_in_ms=75.792
2019-11-20 12:30:05,554 [salt.state       :1780][INFO    ][28658] Running state [python-oauth] at time 12:30:05.554134
2019-11-20 12:30:05,554 [salt.state       :1813][INFO    ][28658] Executing state pkg.installed for [python-oauth]
2019-11-20 12:30:05,558 [salt.state       :300 ][INFO    ][28658] All specified packages are already installed
2019-11-20 12:30:05,558 [salt.state       :1951][INFO    ][28658] Completed state [python-oauth] at time 12:30:05.558897 duration_in_ms=4.763
2019-11-20 12:30:05,561 [salt.state       :1780][INFO    ][28658] Running state [/etc/maas/regiond.conf] at time 12:30:05.561208
2019-11-20 12:30:05,561 [salt.state       :1813][INFO    ][28658] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-20 12:30:05,611 [salt.state       :300 ][INFO    ][28658] No changes needed to be made
2019-11-20 12:30:05,611 [salt.state       :1951][INFO    ][28658] Completed state [/etc/maas/regiond.conf] at time 12:30:05.611462 duration_in_ms=50.254
2019-11-20 12:30:05,611 [salt.state       :1780][INFO    ][28658] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 12:30:05.611863
2019-11-20 12:30:05,612 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-20 12:30:05,664 [salt.state       :300 ][INFO    ][28658] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-20 12:30:05,665 [salt.state       :1951][INFO    ][28658] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 12:30:05.665103 duration_in_ms=53.24
2019-11-20 12:30:05,665 [salt.state       :1780][INFO    ][28658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:30:05.665494
2019-11-20 12:30:05,665 [salt.state       :1813][INFO    ][28658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-20 12:30:05,727 [salt.state       :300 ][INFO    ][28658] No changes needed to be made
2019-11-20 12:30:05,727 [salt.state       :1951][INFO    ][28658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:30:05.727917 duration_in_ms=62.421
2019-11-20 12:30:05,728 [salt.state       :1780][INFO    ][28658] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:30:05.728683
2019-11-20 12:30:05,729 [salt.state       :1813][INFO    ][28658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-20 12:30:05,791 [salt.state       :300 ][INFO    ][28658] No changes needed to be made
2019-11-20 12:30:05,792 [salt.state       :1951][INFO    ][28658] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:30:05.792213 duration_in_ms=63.53
2019-11-20 12:30:05,793 [salt.state       :1780][INFO    ][28658] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 12:30:05.793049
2019-11-20 12:30:05,793 [salt.state       :1813][INFO    ][28658] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-20 12:30:05,831 [salt.state       :300 ][INFO    ][28658] No changes needed to be made
2019-11-20 12:30:05,831 [salt.state       :1951][INFO    ][28658] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 12:30:05.831737 duration_in_ms=38.689
2019-11-20 12:30:05,832 [salt.state       :1780][INFO    ][28658] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 12:30:05.832407
2019-11-20 12:30:05,832 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-20 12:30:05,851 [salt.state       :300 ][INFO    ][28658] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-20 12:30:05,851 [salt.state       :1951][INFO    ][28658] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 12:30:05.851758 duration_in_ms=19.35
2019-11-20 12:30:05,855 [salt.state       :1780][INFO    ][28658] Running state [a2enmod headers] at time 12:30:05.854983
2019-11-20 12:30:05,855 [salt.state       :1813][INFO    ][28658] Executing state cmd.run for [a2enmod headers]
2019-11-20 12:30:05,856 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command 'a2enmod headers' in directory '/root'
2019-11-20 12:30:05,932 [salt.state       :300 ][INFO    ][28658] {'pid': 28678, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-20 12:30:05,933 [salt.state       :1951][INFO    ][28658] Completed state [a2enmod headers] at time 12:30:05.933311 duration_in_ms=78.328
2019-11-20 12:30:05,933 [salt.state       :1780][INFO    ][28658] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 12:30:05.933890
2019-11-20 12:30:05,934 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-20 12:30:05,954 [salt.state       :300 ][INFO    ][28658] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-20 12:30:05,954 [salt.state       :1951][INFO    ][28658] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 12:30:05.954567 duration_in_ms=20.677
2019-11-20 12:30:05,955 [salt.state       :1780][INFO    ][28658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 12:30:05.955458
2019-11-20 12:30:05,955 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-20 12:30:06,077 [salt.state       :300 ][INFO    ][28658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-20 12:30:06,077 [salt.state       :1951][INFO    ][28658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 12:30:06.077664 duration_in_ms=122.204
2019-11-20 12:30:06,078 [salt.state       :1780][INFO    ][28658] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 12:30:06.078602
2019-11-20 12:30:06,079 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-20 12:30:06,203 [salt.state       :300 ][INFO    ][28658] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-20 12:30:06,203 [salt.state       :1951][INFO    ][28658] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 12:30:06.203517 duration_in_ms=124.914
2019-11-20 12:30:06,204 [salt.state       :1780][INFO    ][28658] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 12:30:06.204411
2019-11-20 12:30:06,205 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-20 12:30:06,334 [salt.state       :300 ][INFO    ][28658] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-20 12:30:06,335 [salt.state       :1951][INFO    ][28658] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 12:30:06.335149 duration_in_ms=130.737
2019-11-20 12:30:06,335 [salt.state       :1780][INFO    ][28658] Running state [/root/.pgpass] at time 12:30:06.335660
2019-11-20 12:30:06,336 [salt.state       :1813][INFO    ][28658] Executing state file.managed for [/root/.pgpass]
2019-11-20 12:30:06,442 [salt.state       :300 ][INFO    ][28658] File /root/.pgpass is in the correct state
2019-11-20 12:30:06,443 [salt.state       :1951][INFO    ][28658] Completed state [/root/.pgpass] at time 12:30:06.443094 duration_in_ms=107.433
2019-11-20 12:30:06,452 [salt.state       :1780][INFO    ][28658] Running state [maas-region syncdb --noinput] at time 12:30:06.451930
2019-11-20 12:30:06,452 [salt.state       :1813][INFO    ][28658] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-20 12:30:06,453 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-20 12:30:08,484 [salt.state       :300 ][INFO    ][28658] {'pid': 28691, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: maasserver, sessions, metadataserver, contenttypes, sites, auth, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-20 12:30:08,485 [salt.state       :1951][INFO    ][28658] Completed state [maas-region syncdb --noinput] at time 12:30:08.485550 duration_in_ms=2033.618
2019-11-20 12:30:08,486 [salt.state       :2022][WARNING ][28658] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-20 12:30:08,489 [salt.state       :1780][INFO    ][28658] Running state [maas-regiond] at time 12:30:08.488960
2019-11-20 12:30:08,489 [salt.state       :1813][INFO    ][28658] Executing state service.running for [maas-regiond]
2019-11-20 12:30:08,491 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-20 12:30:08,530 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-20 12:30:08,549 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-20 12:30:08,566 [salt.state       :300 ][INFO    ][28658] The service maas-regiond is already running
2019-11-20 12:30:08,566 [salt.state       :1951][INFO    ][28658] Completed state [maas-regiond] at time 12:30:08.566678 duration_in_ms=77.719
2019-11-20 12:30:08,568 [salt.state       :1780][INFO    ][28658] Running state [bind9] at time 12:30:08.568694
2019-11-20 12:30:08,569 [salt.state       :1813][INFO    ][28658] Executing state service.running for [bind9]
2019-11-20 12:30:08,569 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-20 12:30:08,589 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-20 12:30:08,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-20 12:30:08,626 [salt.state       :300 ][INFO    ][28658] The service bind9 is already running
2019-11-20 12:30:08,626 [salt.state       :1951][INFO    ][28658] Completed state [bind9] at time 12:30:08.626731 duration_in_ms=58.036
2019-11-20 12:30:08,629 [salt.state       :1780][INFO    ][28658] Running state [apache2] at time 12:30:08.629451
2019-11-20 12:30:08,630 [salt.state       :1813][INFO    ][28658] Executing state service.running for [apache2]
2019-11-20 12:30:08,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-20 12:30:08,650 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-20 12:30:08,667 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-20 12:30:08,689 [salt.state       :300 ][INFO    ][28658] The service apache2 is already running
2019-11-20 12:30:08,689 [salt.state       :1951][INFO    ][28658] Completed state [apache2] at time 12:30:08.689886 duration_in_ms=60.435
2019-11-20 12:30:08,691 [salt.state       :1780][INFO    ][28658] Running state [maasng.wait_for_http_code] at time 12:30:08.691907
2019-11-20 12:30:08,692 [salt.state       :1813][INFO    ][28658] Executing state module.run for [maasng.wait_for_http_code]
2019-11-20 12:30:08,693 [salt.utils.decorators:613 ][WARNING ][28658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:08,702 [salt.state       :300 ][INFO    ][28658] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-20 12:30:08,702 [salt.state       :1951][INFO    ][28658] Completed state [maasng.wait_for_http_code] at time 12:30:08.702646 duration_in_ms=10.738
2019-11-20 12:30:08,704 [salt.state       :1780][INFO    ][28658] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 12:30:08.704000
2019-11-20 12:30:08,704 [salt.state       :1813][INFO    ][28658] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-20 12:30:08,705 [salt.state       :300 ][INFO    ][28658] /var/lib/maas/.setup_admin exists
2019-11-20 12:30:08,705 [salt.state       :1951][INFO    ][28658] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 12:30:08.705541 duration_in_ms=1.541
2019-11-20 12:30:08,706 [salt.state       :1780][INFO    ][28658] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:30:08.706641
2019-11-20 12:30:08,707 [salt.state       :1813][INFO    ][28658] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:30:08,708 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28658] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:30:10,255 [salt.state       :300 ][INFO    ][28658] {'pid': 28710, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:30:10,256 [salt.state       :1951][INFO    ][28658] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:30:10.256435 duration_in_ms=1549.795
2019-11-20 12:30:10,264 [salt.state       :1780][INFO    ][28658] Running state [maas_region_boot_source_resources_mirror] at time 12:30:10.264018
2019-11-20 12:30:10,264 [salt.state       :1813][INFO    ][28658] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-20 12:30:10,379 [salt.state       :300 ][INFO    ][28658] {'changes': {}}
2019-11-20 12:30:10,379 [salt.state       :1951][INFO    ][28658] Completed state [maas_region_boot_source_resources_mirror] at time 12:30:10.379817 duration_in_ms=115.8
2019-11-20 12:30:10,381 [salt.state       :1780][INFO    ][28658] Running state [maasng.boot_resources_import] at time 12:30:10.380934
2019-11-20 12:30:10,381 [salt.state       :1813][INFO    ][28658] Executing state module.run for [maasng.boot_resources_import]
2019-11-20 12:30:10,382 [salt.utils.decorators:613 ][WARNING ][28658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:13,487 [salt.loaded.ext.module.maasng:1600][INFO    ][28658] Waiting boot-resources import done
sleep for:5s Left:897.0/900s
2019-11-20 12:30:16,035 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123016022924
2019-11-20 12:30:16,059 [salt.minion      :1432][INFO    ][28744] Starting a new job with PID 28744
2019-11-20 12:30:16,083 [salt.minion      :1711][INFO    ][28744] Returning information for job: 20191120123016022924
2019-11-20 12:30:18,550 [salt.loaded.ext.module.maasng:1600][INFO    ][28658] Waiting boot-resources import done
sleep for:5s Left:892.0/900s
2019-11-20 12:30:23,650 [salt.state       :300 ][INFO    ][28658] {'ret': True}
2019-11-20 12:30:23,651 [salt.state       :1951][INFO    ][28658] Completed state [maasng.boot_resources_import] at time 12:30:23.651309 duration_in_ms=13270.375
2019-11-20 12:30:23,652 [salt.state       :1780][INFO    ][28658] Running state [maas_region_boot_sources_selection_xenial] at time 12:30:23.652537
2019-11-20 12:30:23,653 [salt.state       :1813][INFO    ][28658] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-11-20 12:30:23,817 [salt.state       :300 ][INFO    ][28658] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-20 12:30:23,817 [salt.state       :1951][INFO    ][28658] Completed state [maas_region_boot_sources_selection_xenial] at time 12:30:23.817875 duration_in_ms=165.338
2019-11-20 12:30:23,818 [salt.state       :1780][INFO    ][28658] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 12:30:23.818822
2019-11-20 12:30:23,819 [salt.state       :1813][INFO    ][28658] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-20 12:30:23,819 [salt.utils.decorators:613 ][WARNING ][28658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:23,820 [salt.loaded.ext.module.maasng:1771][INFO    ][28658] boot-sources sync initiated for ALL Rack's
2019-11-20 12:30:24,302 [salt.loaded.ext.module.maasng:1878][INFO    ][28658] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2019-11-20 12:30:29,532 [salt.loaded.ext.module.maasng:1878][INFO    ][28658] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:894.0/900s
2019-11-20 12:30:34,765 [salt.loaded.ext.module.maasng:1878][INFO    ][28658] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2019-11-20 12:30:40,011 [salt.loaded.ext.module.maasng:1878][INFO    ][28658] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:884.0/900s
2019-11-20 12:30:45,927 [salt.state       :300 ][INFO    ][28658] {'ret': True}
2019-11-20 12:30:45,928 [salt.state       :1951][INFO    ][28658] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 12:30:45.928241 duration_in_ms=22109.418
2019-11-20 12:30:45,930 [salt.state       :1780][INFO    ][28658] Running state [maas.process_maas_config] at time 12:30:45.930255
2019-11-20 12:30:45,930 [salt.state       :1813][INFO    ][28658] Executing state module.run for [maas.process_maas_config]
2019-11-20 12:30:45,931 [salt.utils.decorators:613 ][WARNING ][28658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:45,932 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=enable_http_proxy value=True
2019-11-20 12:30:45,995 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=upstream_dns value=8.8.8.8
2019-11-20 12:30:46,065 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=commissioning_distro_series value=xenial
2019-11-20 12:30:46,100 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123046087082
2019-11-20 12:30:46,121 [salt.minion      :1432][INFO    ][28968] Starting a new job with PID 28968
2019-11-20 12:30:46,144 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=default_osystem value=ubuntu
2019-11-20 12:30:46,145 [salt.minion      :1711][INFO    ][28968] Returning information for job: 20191120123046087082
2019-11-20 12:30:46,203 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=active_discovery_interval value=600
2019-11-20 12:30:49,231 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=dnssec_validation value=no
2019-11-20 12:30:49,297 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=maas_name value=mas01
2019-11-20 12:30:49,358 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=network_discovery value=enabled
2019-11-20 12:30:49,975 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=enable_third_party_drivers value=True
2019-11-20 12:30:50,685 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=default_storage_layout value=lvm
2019-11-20 12:30:50,749 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=ntp_external_only value=True
2019-11-20 12:30:50,818 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-20 12:30:50,889 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=default_distro_series value=xenial
2019-11-20 12:30:50,958 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-11-20 12:30:51,091 [salt.state       :300 ][INFO    ][28658] {'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-11-20 12:30:51,091 [salt.state       :1951][INFO    ][28658] Completed state [maas.process_maas_config] at time 12:30:51.091602 duration_in_ms=5161.346
2019-11-20 12:30:51,092 [salt.state       :1780][INFO    ][28658] Running state [pxe_admin] at time 12:30:51.092557
2019-11-20 12:30:51,093 [salt.state       :1813][INFO    ][28658] Executing state maasng.fabric_present for [pxe_admin]
2019-11-20 12:30:51,171 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, 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-11-20 12:30:51,269 [salt.loaded.ext.module.maasng:1008][WARNING ][28658] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-20 12:30:51,269 [salt.loaded.ext.module.maasng:1011][WARNING ][28658] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-20 12:30:51,340 [salt.state       :300 ][INFO    ][28658] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-20 12:30:51,340 [salt.state       :1951][INFO    ][28658] Completed state [pxe_admin] at time 12:30:51.340592 duration_in_ms=248.034
2019-11-20 12:30:51,341 [salt.state       :1780][INFO    ][28658] Running state [vlan 0] at time 12:30:51.341035
2019-11-20 12:30:51,341 [salt.state       :1813][INFO    ][28658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-20 12:30:51,418 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'srmw3h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-20 12:30:51,549 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-20 12:30:51,857 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'srmw3h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-20 12:30:51,952 [salt.state       :300 ][INFO    ][28658] {'new': 'Vlan untagged was updated'}
2019-11-20 12:30:51,953 [salt.state       :1951][INFO    ][28658] Completed state [vlan 0] at time 12:30:51.953165 duration_in_ms=612.128
2019-11-20 12:30:51,954 [salt.state       :1780][INFO    ][28658] Running state [192.168.11.0/24] at time 12:30:51.954755
2019-11-20 12:30:51,955 [salt.state       :1813][INFO    ][28658] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-20 12:30:52,174 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'srmw3h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-20 12:30:52,175 [salt.loaded.ext.module.maasng:1235][WARNING ][28658] Ignoring parameter vlan:0
2019-11-20 12:30:52,247 [salt.state       :300 ][INFO    ][28658] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-20 12:30:52,248 [salt.state       :1951][INFO    ][28658] Completed state [192.168.11.0/24] at time 12:30:52.247947 duration_in_ms=293.19
2019-11-20 12:30:52,250 [salt.state       :1780][INFO    ][28658] Running state [maas_create_iprange_1] at time 12:30:52.249988
2019-11-20 12:30:52,250 [salt.state       :1813][INFO    ][28658] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-20 12:30:52,311 [salt.state       :300 ][INFO    ][28658] Iprange maas_create_iprange_1 already exist.
2019-11-20 12:30:52,312 [salt.state       :1951][INFO    ][28658] Completed state [maas_create_iprange_1] at time 12:30:52.312269 duration_in_ms=62.282
2019-11-20 12:30:52,312 [salt.state       :1780][INFO    ][28658] Running state [vlan 0] at time 12:30:52.312753
2019-11-20 12:30:52,313 [salt.state       :1813][INFO    ][28658] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-20 12:30:52,365 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, 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-11-20 12:30:52,483 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'srmw3h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-20 12:30:52,699 [salt.loaded.ext.module.maasng:945 ][INFO    ][28658] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-20 12:30:52,801 [salt.state       :300 ][INFO    ][28658] {'new': 'Vlan untagged was updated'}
2019-11-20 12:30:52,802 [salt.state       :1951][INFO    ][28658] Completed state [vlan 0] at time 12:30:52.802010 duration_in_ms=489.257
2019-11-20 12:30:52,803 [salt.state       :1780][INFO    ][28658] Running state [opnfv] at time 12:30:52.803350
2019-11-20 12:30:52,804 [salt.state       :1813][INFO    ][28658] Executing state maasng.sshkey_present for [opnfv]
2019-11-20 12:30:52,854 [salt.loaded.ext.module.maasng:1903][INFO    ][28658] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-11-20 12:30:52,855 [salt.state       :300 ][INFO    ][28658] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-20 12:30:52,855 [salt.state       :1951][INFO    ][28658] Completed state [opnfv] at time 12:30:52.855427 duration_in_ms=52.078
2019-11-20 12:30:52,856 [salt.state       :1780][INFO    ][28658] Running state [maas.process_tags] at time 12:30:52.856303
2019-11-20 12:30:52,856 [salt.state       :1813][INFO    ][28658] Executing state module.run for [maas.process_tags]
2019-11-20 12:30:52,857 [salt.utils.decorators:613 ][WARNING ][28658] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:52,908 [salt.loaded.ext.module.maas:92  ][INFO    ][28658] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-11-20 12:30:52,969 [salt.state       :300 ][INFO    ][28658] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-11-20 12:30:52,969 [salt.state       :1951][INFO    ][28658] Completed state [maas.process_tags] at time 12:30:52.969535 duration_in_ms=113.231
2019-11-20 12:30:52,974 [salt.minion      :1711][INFO    ][28658] Returning information for job: 20191120123000948111
2019-11-20 12:30:53,605 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123053592890
2019-11-20 12:30:53,624 [salt.minion      :1432][INFO    ][29056] Starting a new job with PID 29056
2019-11-20 12:30:57,291 [salt.state       :915 ][INFO    ][29056] Loading fresh modules for state activity
2019-11-20 12:30:57,350 [salt.fileclient  :1219][INFO    ][29056] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-11-20 12:30:57,393 [salt.state       :1780][INFO    ][29056] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:30:57.393303
2019-11-20 12:30:57,393 [salt.state       :1813][INFO    ][29056] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:30:57,396 [salt.loaded.int.module.cmdmod:395 ][INFO    ][29056] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:30:58,829 [salt.state       :300 ][INFO    ][29056] {'pid': 29080, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:30:58,830 [salt.state       :1951][INFO    ][29056] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:30:58.829957 duration_in_ms=1436.654
2019-11-20 12:30:58,831 [salt.state       :1780][INFO    ][29056] Running state [maas.process_machines] at time 12:30:58.831174
2019-11-20 12:30:58,831 [salt.state       :1813][INFO    ][29056] Executing state module.run for [maas.process_machines]
2019-11-20 12:30:58,832 [salt.utils.decorators:613 ][WARNING ][29056] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:30:58,903 [salt.loaded.ext.module.maas:412 ][WARNING ][29056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:30:58,904 [salt.loaded.ext.module.maas:92  ][INFO    ][29056] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:31:00,364 [salt.loaded.ext.module.maas:412 ][WARNING ][29056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:31:00,365 [salt.loaded.ext.module.maas:92  ][INFO    ][29056] 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 architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:31:01,802 [salt.loaded.ext.module.maas:412 ][WARNING ][29056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:31:01,803 [salt.loaded.ext.module.maas:92  ][INFO    ][29056] 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-11-20 12:31:03,260 [salt.loaded.ext.module.maas:412 ][WARNING ][29056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:31:03,261 [salt.loaded.ext.module.maas:92  ][INFO    ][29056] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:31:04,751 [salt.loaded.ext.module.maas:412 ][WARNING ][29056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:31:04,752 [salt.loaded.ext.module.maas:92  ][INFO    ][29056] 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-11-20 12:31:06,158 [salt.state       :300 ][INFO    ][29056] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-20 12:31:06,159 [salt.state       :1951][INFO    ][29056] Completed state [maas.process_machines] at time 12:31:06.159129 duration_in_ms=7327.952
2019-11-20 12:31:06,178 [salt.minion      :1711][INFO    ][29056] Returning information for job: 20191120123053592890
2019-11-20 12:31:37,273 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123137260897
2019-11-20 12:31:37,296 [salt.minion      :1432][INFO    ][29400] Starting a new job with PID 29400
2019-11-20 12:31:40,784 [salt.state       :915 ][INFO    ][29400] Loading fresh modules for state activity
2019-11-20 12:31:40,826 [salt.fileclient  :1219][INFO    ][29400] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-11-20 12:31:40,859 [salt.state       :1780][INFO    ][29400] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:31:40.859492
2019-11-20 12:31:40,859 [salt.state       :1813][INFO    ][29400] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:31:40,861 [salt.loaded.int.module.cmdmod:395 ][INFO    ][29400] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:31:42,227 [salt.state       :300 ][INFO    ][29400] {'pid': 29419, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:31:42,228 [salt.state       :1951][INFO    ][29400] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:31:42.228777 duration_in_ms=1369.283
2019-11-20 12:31:42,231 [salt.state       :1780][INFO    ][29400] Running state [maas.wait_for_machine_status] at time 12:31:42.231853
2019-11-20 12:31:42,232 [salt.state       :1813][INFO    ][29400] Executing state module.run for [maas.wait_for_machine_status]
2019-11-20 12:31:42,233 [salt.utils.decorators:613 ][WARNING ][29400] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:31:43,145 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.09718394s left)
2019-11-20 12:31:52,402 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123152389506
2019-11-20 12:31:52,424 [salt.minion      :1432][INFO    ][29444] Starting a new job with PID 29444
2019-11-20 12:31:52,448 [salt.minion      :1711][INFO    ][29444] Returning information for job: 20191120123152389506
2019-11-20 12:32:14,109 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.13306189s left)
2019-11-20 12:32:22,456 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123222443609
2019-11-20 12:32:22,479 [salt.minion      :1432][INFO    ][29483] Starting a new job with PID 29483
2019-11-20 12:32:22,504 [salt.minion      :1711][INFO    ][29483] Returning information for job: 20191120123222443609
2019-11-20 12:32:45,045 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.19638491s left)
2019-11-20 12:32:52,525 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123252514294
2019-11-20 12:32:52,544 [salt.minion      :1432][INFO    ][29631] Starting a new job with PID 29631
2019-11-20 12:32:52,567 [salt.minion      :1711][INFO    ][29631] Returning information for job: 20191120123252514294
2019-11-20 12:33:16,442 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.79947901s left)
2019-11-20 12:33:22,568 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123322555535
2019-11-20 12:33:22,590 [salt.minion      :1432][INFO    ][30014] Starting a new job with PID 30014
2019-11-20 12:33:22,615 [salt.minion      :1711][INFO    ][30014] Returning information for job: 20191120123322555535
2019-11-20 12:33:48,021 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.22133183s left)
2019-11-20 12:33:52,621 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123352608234
2019-11-20 12:33:52,643 [salt.minion      :1432][INFO    ][30343] Starting a new job with PID 30343
2019-11-20 12:33:52,667 [salt.minion      :1711][INFO    ][30343] Returning information for job: 20191120123352608234
2019-11-20 12:34:19,814 [salt.loaded.ext.module.maas:1023][INFO    ][29400] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.42787385s left)
2019-11-20 12:34:22,678 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123422665225
2019-11-20 12:34:22,701 [salt.minion      :1432][INFO    ][30582] Starting a new job with PID 30582
2019-11-20 12:34:22,724 [salt.minion      :1711][INFO    ][30582] Returning information for job: 20191120123422665225
2019-11-20 12:34:52,738 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123452725740
2019-11-20 12:34:52,759 [salt.minion      :1432][INFO    ][30765] Starting a new job with PID 30765
2019-11-20 12:34:52,783 [salt.minion      :1711][INFO    ][30765] Returning information for job: 20191120123452725740
2019-11-20 12:34:53,391 [salt.state       :300 ][INFO    ][29400] {'ret': True}
2019-11-20 12:34:53,391 [salt.state       :1951][INFO    ][29400] Completed state [maas.wait_for_machine_status] at time 12:34:53.391513 duration_in_ms=191159.659
2019-11-20 12:34:53,395 [salt.minion      :1711][INFO    ][29400] Returning information for job: 20191120123137260897
2019-11-20 12:34:54,011 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123453998760
2019-11-20 12:34:54,034 [salt.minion      :1432][INFO    ][30772] Starting a new job with PID 30772
2019-11-20 12:34:57,827 [salt.state       :915 ][INFO    ][30772] Loading fresh modules for state activity
2019-11-20 12:34:57,880 [salt.fileclient  :1219][INFO    ][30772] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-11-20 12:34:57,971 [salt.state       :1780][INFO    ][30772] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:34:57.971900
2019-11-20 12:34:57,972 [salt.state       :1813][INFO    ][30772] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:34:57,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30772] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:34:59,432 [salt.state       :300 ][INFO    ][30772] {'pid': 30780, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:34:59,433 [salt.state       :1951][INFO    ][30772] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:34:59.433259 duration_in_ms=1461.36
2019-11-20 12:34:59,434 [salt.state       :1780][INFO    ][30772] Running state [maas_machines_storage_cmp002_lvm] at time 12:34:59.434748
2019-11-20 12:34:59,434 [salt.state       :1813][INFO    ][30772] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-20 12:35:00,946 [salt.loaded.ext.module.maasng:610 ][INFO    ][30772] rrsm4a
2019-11-20 12:35:00,946 [salt.loaded.ext.module.maasng:626 ][INFO    ][30772] sda
2019-11-20 12:35:01,780 [salt.loaded.ext.module.maasng:361 ][INFO    ][30772] rrsm4a
2019-11-20 12:35:01,906 [salt.loaded.ext.module.maasng:367 ][INFO    ][30772] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'ca585caa-318a-4afd-b1f1-8c49ab08818b', u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrsm4a', u'filesystem': {u'mount_options': None, u'uuid': u'46c3793f-d12f-4fc6-bf80-1f1cb0a5fd5d', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 5, u'size': 2397992648704}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrsm4a', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/'}, {u'size': 2397988454400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'1d135594-0e6c-41db-abc2-d3ea9683a1f6', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'uuid': u'93c529d9-9139-442f-b5a7-3dcb6855f912', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rrsm4a', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/10/'}]
2019-11-20 12:35:01,907 [salt.loaded.ext.module.maasng:632 ][INFO    ][30772] vgroot
2019-11-20 12:35:01,907 [salt.loaded.ext.module.maasng:635 ][INFO    ][30772] lvroot
2019-11-20 12:35:01,908 [salt.loaded.ext.module.maasng:639 ][INFO    ][30772] 107374182400
2019-11-20 12:35:02,626 [salt.loaded.ext.module.maasng:645 ][INFO    ][30772] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'5448e4a7-30ad-4f10-b916-40b2d656f95e', u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrsm4a', u'filesystem': {u'mount_options': None, u'uuid': u'7438daf3-6319-4c51-a0bb-728c5ea1e3c5', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrsm4a', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/'}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'4fa12e4f-38d5-4734-ace7-99e9a7e7e529', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'uuid': u'0f5e7b2e-b1a7-4485-ac41-2e889bb29b18', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rrsm4a', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/12/'}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'rrsm4a', u'power_state': u'on', u'memory': 32768, u'commissioning_status_name': u'Passed', 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"From 'Testing' to 'Ready'", u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'uuid': u'4fa12e4f-38d5-4734-ace7-99e9a7e7e529', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'uuid': u'0f5e7b2e-b1a7-4485-ac41-2e889bb29b18', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'rrsm4a', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/12/'}], u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'5448e4a7-30ad-4f10-b916-40b2d656f95e', u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrsm4a', u'filesystem': {u'mount_options': None, u'uuid': u'7438daf3-6319-4c51-a0bb-728c5ea1e3c5', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrsm4a', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/'}], u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'rrsm4a', u'id': 7}], u'current_installation_result_id': None, u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'5448e4a7-30ad-4f10-b916-40b2d656f95e', u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'rrsm4a', u'filesystem': {u'mount_options': None, u'uuid': u'7438daf3-6319-4c51-a0bb-728c5ea1e3c5', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'rrsm4a', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/blockdevices/4/'}, 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 35, u'mode': u'dhcp'}], 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'rrsm4a', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 36, u'mode': u'link_up'}], 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 18, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'system_id': u'rrsm4a', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/interfaces/18/'}, {u'name': u'enp7s0', u'links': [{u'id': 37, u'mode': u'link_up'}], 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 19, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'system_id': u'rrsm4a', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/interfaces/19/'}, {u'name': u'enp8s0', u'links': [{u'id': 38, u'mode': u'link_up'}], 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'id': 20, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'system_id': u'rrsm4a', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 35, u'mode': u'dhcp'}], 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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'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'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'rrsm4a', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/rrsm4a/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/rrsm4a/'}
2019-11-20 12:35:02,628 [salt.state       :300 ][INFO    ][30772] {'new': {'storage_layout': 'lvm'}}
2019-11-20 12:35:02,629 [salt.state       :1951][INFO    ][30772] Completed state [maas_machines_storage_cmp002_lvm] at time 12:35:02.629075 duration_in_ms=3194.324
2019-11-20 12:35:02,629 [salt.state       :1780][INFO    ][30772] Running state [maas_machines_storage_cmp001_lvm] at time 12:35:02.629635
2019-11-20 12:35:02,630 [salt.state       :1813][INFO    ][30772] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-20 12:35:04,062 [salt.loaded.ext.module.maasng:610 ][INFO    ][30772] 88gp34
2019-11-20 12:35:04,062 [salt.loaded.ext.module.maasng:626 ][INFO    ][30772] sda
2019-11-20 12:35:04,740 [salt.loaded.ext.module.maasng:361 ][INFO    ][30772] 88gp34
2019-11-20 12:35:04,870 [salt.loaded.ext.module.maasng:367 ][INFO    ][30772] [{u'block_size': 4096, u'partition_table_type': u'GPT', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 1, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'88gp34', u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'fa427d29-e8c7-4d92-aab6-fe299f19f90b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88gp34', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'bc153cc7-f82e-401e-88ae-0a69d8261042', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'device_id': 1}], u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'size': 2397998940160}, {u'block_size': 4096, u'partition_table_type': None, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 6, u'uuid': u'0637e0f1-2eb5-4842-8339-d3c51b96e8dd', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'88gp34', u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/6/', u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'e028c73b-cc1d-419f-8c91-360932835e91', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'used_size': 2397988454400, u'model': None, u'size': 2397988454400}]
2019-11-20 12:35:04,871 [salt.loaded.ext.module.maasng:632 ][INFO    ][30772] vgroot
2019-11-20 12:35:04,871 [salt.loaded.ext.module.maasng:635 ][INFO    ][30772] lvroot
2019-11-20 12:35:04,872 [salt.loaded.ext.module.maasng:639 ][INFO    ][30772] 107374182400
2019-11-20 12:35:05,591 [salt.loaded.ext.module.maasng:645 ][INFO    ][30772] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 16, u'mode': u'dhcp'}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'88gp34', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/interfaces/5/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/88gp34/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'88gp34', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/13/', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'1a965d80-82c5-4c7b-94a4-9c2298c34285', u'label': u'root'}, u'uuid': u'88547b4e-e4dd-4817-b350-061a47a0332b', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'88gp34', u'block_size': 4096, u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'id': 13, u'serial': None, u'partitions': []}], u'blockdevice_set': [{u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/', u'system_id': u'88gp34', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'type': u'physical', u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'2b5208a9-a928-440c-ad74-dc8090fbf48b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88gp34', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'59909aeb-7540-41c4-abf6-0ea665ee075e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/partition/8'}]}, {u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'1a965d80-82c5-4c7b-94a4-9c2298c34285', u'label': u'root'}, u'uuid': u'88547b4e-e4dd-4817-b350-061a47a0332b', u'used_for': u'ext4 formatted filesystem mounted at /', u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/13/', u'system_id': u'88gp34', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'size': 107374182400, u'type': u'virtual', u'id': 13, u'serial': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, 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'88gp34', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 4, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 16, u'mode': u'dhcp'}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'system_id': u'88gp34', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 17}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'system_id': u'88gp34', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/interfaces/11/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 19}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 12, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'system_id': u'88gp34', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/interfaces/12/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 21}], 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'effective_mtu': 1500, u'id': 13, u'discovered': None, u'parents': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'system_id': u'88gp34', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/interfaces/13/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'physicalblockdevice_set': [{u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88gp34', u'block_size': 4096, u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'2b5208a9-a928-440c-ad74-dc8090fbf48b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88gp34', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'59909aeb-7540-41c4-abf6-0ea665ee075e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/partition/8'}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'ip_addresses': [u'192.168.11.38'], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/', u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'88gp34', u'block_size': 4096, u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'2b5208a9-a928-440c-ad74-dc8090fbf48b', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'88gp34', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'59909aeb-7540-41c4-abf6-0ea665ee075e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 8, u'resource_uri': u'/MAAS/api/2.0/nodes/88gp34/blockdevices/1/partition/8'}]}}
2019-11-20 12:35:05,593 [salt.state       :300 ][INFO    ][30772] {'new': {'storage_layout': 'lvm'}}
2019-11-20 12:35:05,593 [salt.state       :1951][INFO    ][30772] Completed state [maas_machines_storage_cmp001_lvm] at time 12:35:05.593658 duration_in_ms=2964.023
2019-11-20 12:35:05,597 [salt.minion      :1711][INFO    ][30772] Returning information for job: 20191120123453998760
2019-11-20 12:35:06,231 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123506222001
2019-11-20 12:35:06,253 [salt.minion      :1432][INFO    ][30817] Starting a new job with PID 30817
2019-11-20 12:35:06,936 [salt.state       :915 ][INFO    ][30817] Loading fresh modules for state activity
2019-11-20 12:35:06,987 [salt.fileclient  :1219][INFO    ][30817] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-11-20 12:35:07,027 [salt.state       :1780][INFO    ][30817] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:35:07.027048
2019-11-20 12:35:07,027 [salt.state       :1813][INFO    ][30817] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:35:07,029 [salt.loaded.int.module.cmdmod:395 ][INFO    ][30817] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:35:08,649 [salt.state       :300 ][INFO    ][30817] {'pid': 30824, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:35:08,650 [salt.state       :1951][INFO    ][30817] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:35:08.650171 duration_in_ms=1623.123
2019-11-20 12:35:08,652 [salt.state       :1780][INFO    ][30817] Running state [maas.deploy_machines] at time 12:35:08.652729
2019-11-20 12:35:08,653 [salt.state       :1813][INFO    ][30817] Executing state module.run for [maas.deploy_machines]
2019-11-20 12:35:08,654 [salt.utils.decorators:613 ][WARNING ][30817] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:35:09,356 [salt.loaded.ext.module.maas:684 ][INFO    ][30817] deploymachines hwe_kernel=hwe-16.04 system_id=rrsm4a distro_series=xenial
2019-11-20 12:35:12,125 [salt.loaded.ext.module.maas:684 ][INFO    ][30817] deploymachines hwe_kernel=hwe-16.04 system_id=88gp34 distro_series=xenial
2019-11-20 12:35:14,890 [salt.loaded.ext.module.maas:684 ][INFO    ][30817] deploymachines hwe_kernel=hwe-16.04 system_id=ccea73 distro_series=xenial
2019-11-20 12:35:17,647 [salt.loaded.ext.module.maas:684 ][INFO    ][30817] deploymachines hwe_kernel=hwe-16.04 system_id=my7en6 distro_series=xenial
2019-11-20 12:35:20,073 [salt.loaded.ext.module.maas:684 ][INFO    ][30817] deploymachines hwe_kernel=hwe-16.04 system_id=rg6ggn distro_series=xenial
2019-11-20 12:35:21,326 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123521313939
2019-11-20 12:35:21,349 [salt.minion      :1432][INFO    ][31131] Starting a new job with PID 31131
2019-11-20 12:35:21,373 [salt.minion      :1711][INFO    ][31131] Returning information for job: 20191120123521313939
2019-11-20 12:35:22,150 [salt.state       :300 ][INFO    ][30817] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-11-20 12:35:22,151 [salt.state       :1951][INFO    ][30817] Completed state [maas.deploy_machines] at time 12:35:22.151115 duration_in_ms=13498.386
2019-11-20 12:35:22,154 [salt.minion      :1711][INFO    ][30817] Returning information for job: 20191120123506222001
2019-11-20 12:35:22,767 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120123522752864
2019-11-20 12:35:22,789 [salt.minion      :1432][INFO    ][31148] Starting a new job with PID 31148
2019-11-20 12:35:26,277 [salt.state       :915 ][INFO    ][31148] Loading fresh modules for state activity
2019-11-20 12:35:26,328 [salt.fileclient  :1219][INFO    ][31148] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-11-20 12:35:26,370 [salt.state       :1780][INFO    ][31148] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:35:26.370454
2019-11-20 12:35:26,370 [salt.state       :1813][INFO    ][31148] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:35:26,372 [salt.loaded.int.module.cmdmod:395 ][INFO    ][31148] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:35:27,789 [salt.state       :300 ][INFO    ][31148] {'pid': 31160, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:35:27,790 [salt.state       :1951][INFO    ][31148] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:35:27.790330 duration_in_ms=1419.877
2019-11-20 12:35:27,791 [salt.state       :1780][INFO    ][31148] Running state [maas.wait_for_machine_status] at time 12:35:27.791869
2019-11-20 12:35:27,792 [salt.state       :1813][INFO    ][31148] Executing state module.run for [maas.wait_for_machine_status]
2019-11-20 12:35:27,792 [salt.utils.decorators:613 ][WARNING ][31148] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:35:31,310 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.48686194s left)
2019-11-20 12:35:37,897 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123537882417
2019-11-20 12:35:37,920 [salt.minion      :1432][INFO    ][31175] Starting a new job with PID 31175
2019-11-20 12:35:37,945 [salt.minion      :1711][INFO    ][31175] Returning information for job: 20191120123537882417
2019-11-20 12:36:04,636 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.16089606s left)
2019-11-20 12:36:07,943 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123607930972
2019-11-20 12:36:07,966 [salt.minion      :1432][INFO    ][31207] Starting a new job with PID 31207
2019-11-20 12:36:07,991 [salt.minion      :1711][INFO    ][31207] Returning information for job: 20191120123607930972
2019-11-20 12:36:38,017 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123638004425
2019-11-20 12:36:38,041 [salt.minion      :1432][INFO    ][31246] Starting a new job with PID 31246
2019-11-20 12:36:38,063 [salt.minion      :1711][INFO    ][31246] Returning information for job: 20191120123638004425
2019-11-20 12:36:38,255 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.540977s left)
2019-11-20 12:37:08,047 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123708035785
2019-11-20 12:37:08,064 [salt.minion      :1432][INFO    ][31364] Starting a new job with PID 31364
2019-11-20 12:37:08,086 [salt.minion      :1711][INFO    ][31364] Returning information for job: 20191120123708035785
2019-11-20 12:37:11,465 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.33154893s left)
2019-11-20 12:37:38,102 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123738090568
2019-11-20 12:37:38,124 [salt.minion      :1432][INFO    ][31609] Starting a new job with PID 31609
2019-11-20 12:37:38,148 [salt.minion      :1711][INFO    ][31609] Returning information for job: 20191120123738090568
2019-11-20 12:37:45,083 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.71378994s left)
2019-11-20 12:38:08,157 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123808144848
2019-11-20 12:38:08,181 [salt.minion      :1432][INFO    ][31760] Starting a new job with PID 31760
2019-11-20 12:38:08,205 [salt.minion      :1711][INFO    ][31760] Returning information for job: 20191120123808144848
2019-11-20 12:38:18,767 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.02987695s left)
2019-11-20 12:38:38,217 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123838205375
2019-11-20 12:38:38,240 [salt.minion      :1432][INFO    ][32355] Starting a new job with PID 32355
2019-11-20 12:38:38,265 [salt.minion      :1711][INFO    ][32355] Returning information for job: 20191120123838205375
2019-11-20 12:38:52,426 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.37083101s left)
2019-11-20 12:39:08,279 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123908267002
2019-11-20 12:39:08,302 [salt.minion      :1432][INFO    ][32482] Starting a new job with PID 32482
2019-11-20 12:39:08,324 [salt.minion      :1711][INFO    ][32482] Returning information for job: 20191120123908267002
2019-11-20 12:39:25,815 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2011.98112607s left)
2019-11-20 12:39:38,347 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120123938334302
2019-11-20 12:39:38,370 [salt.minion      :1432][INFO    ][32597] Starting a new job with PID 32597
2019-11-20 12:39:38,395 [salt.minion      :1711][INFO    ][32597] Returning information for job: 20191120123938334302
2019-11-20 12:39:59,415 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1978.38193798s left)
2019-11-20 12:40:08,426 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124008414670
2019-11-20 12:40:08,447 [salt.minion      :1432][INFO    ][32724] Starting a new job with PID 32724
2019-11-20 12:40:08,470 [salt.minion      :1711][INFO    ][32724] Returning information for job: 20191120124008414670
2019-11-20 12:40:32,747 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.04979801s left)
2019-11-20 12:40:38,498 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124038485869
2019-11-20 12:40:38,521 [salt.minion      :1432][INFO    ][681] Starting a new job with PID 681
2019-11-20 12:40:38,546 [salt.minion      :1711][INFO    ][681] Returning information for job: 20191120124038485869
2019-11-20 12:41:06,455 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1911.34128904s left)
2019-11-20 12:41:08,579 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124108566168
2019-11-20 12:41:08,602 [salt.minion      :1432][INFO    ][837] Starting a new job with PID 837
2019-11-20 12:41:08,626 [salt.minion      :1711][INFO    ][837] Returning information for job: 20191120124108566168
2019-11-20 12:41:38,664 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124138652191
2019-11-20 12:41:38,685 [salt.minion      :1432][INFO    ][1113] Starting a new job with PID 1113
2019-11-20 12:41:38,709 [salt.minion      :1711][INFO    ][1113] Returning information for job: 20191120124138652191
2019-11-20 12:41:40,027 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1877.76896691s left)
2019-11-20 12:42:08,752 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124208739825
2019-11-20 12:42:08,775 [salt.minion      :1432][INFO    ][1191] Starting a new job with PID 1191
2019-11-20 12:42:08,798 [salt.minion      :1711][INFO    ][1191] Returning information for job: 20191120124208739825
2019-11-20 12:42:13,687 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1844.10898995s left)
2019-11-20 12:42:38,847 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124238834860
2019-11-20 12:42:38,870 [salt.minion      :1432][INFO    ][1320] Starting a new job with PID 1320
2019-11-20 12:42:38,894 [salt.minion      :1711][INFO    ][1320] Returning information for job: 20191120124238834860
2019-11-20 12:42:46,898 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1810.89896393s left)
2019-11-20 12:43:09,034 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124309022000
2019-11-20 12:43:09,056 [salt.minion      :1432][INFO    ][1464] Starting a new job with PID 1464
2019-11-20 12:43:09,078 [salt.minion      :1711][INFO    ][1464] Returning information for job: 20191120124309022000
2019-11-20 12:43:19,959 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1777.83733201s left)
2019-11-20 12:43:39,138 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124339125753
2019-11-20 12:43:39,161 [salt.minion      :1432][INFO    ][1895] Starting a new job with PID 1895
2019-11-20 12:43:39,186 [salt.minion      :1711][INFO    ][1895] Returning information for job: 20191120124339125753
2019-11-20 12:43:53,436 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1744.36013007s left)
2019-11-20 12:44:09,256 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124409243844
2019-11-20 12:44:09,278 [salt.minion      :1432][INFO    ][2017] Starting a new job with PID 2017
2019-11-20 12:44:09,301 [salt.minion      :1711][INFO    ][2017] Returning information for job: 20191120124409243844
2019-11-20 12:44:26,616 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1711.18056297s left)
2019-11-20 12:44:39,373 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124439360737
2019-11-20 12:44:39,395 [salt.minion      :1432][INFO    ][2056] Starting a new job with PID 2056
2019-11-20 12:44:39,418 [salt.minion      :1711][INFO    ][2056] Returning information for job: 20191120124439360737
2019-11-20 12:45:00,203 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1677.59345007s left)
2019-11-20 12:45:09,497 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124509484297
2019-11-20 12:45:09,519 [salt.minion      :1432][INFO    ][2092] Starting a new job with PID 2092
2019-11-20 12:45:09,544 [salt.minion      :1711][INFO    ][2092] Returning information for job: 20191120124509484297
2019-11-20 12:45:33,737 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1644.05943298s left)
2019-11-20 12:45:39,634 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124539621717
2019-11-20 12:45:39,657 [salt.minion      :1432][INFO    ][2131] Starting a new job with PID 2131
2019-11-20 12:45:39,681 [salt.minion      :1711][INFO    ][2131] Returning information for job: 20191120124539621717
2019-11-20 12:46:07,641 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1610.15576291s left)
2019-11-20 12:46:09,779 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124609766657
2019-11-20 12:46:09,802 [salt.minion      :1432][INFO    ][2164] Starting a new job with PID 2164
2019-11-20 12:46:09,826 [salt.minion      :1711][INFO    ][2164] Returning information for job: 20191120124609766657
2019-11-20 12:46:39,922 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124639915581
2019-11-20 12:46:39,943 [salt.minion      :1432][INFO    ][2203] Starting a new job with PID 2203
2019-11-20 12:46:39,967 [salt.minion      :1711][INFO    ][2203] Returning information for job: 20191120124639915581
2019-11-20 12:46:41,073 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1576.72351599s left)
2019-11-20 12:47:10,081 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124710068207
2019-11-20 12:47:10,103 [salt.minion      :1432][INFO    ][2235] Starting a new job with PID 2235
2019-11-20 12:47:10,127 [salt.minion      :1711][INFO    ][2235] Returning information for job: 20191120124710068207
2019-11-20 12:47:14,618 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1543.17877293s left)
2019-11-20 12:47:40,252 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124740239362
2019-11-20 12:47:40,275 [salt.minion      :1432][INFO    ][2283] Starting a new job with PID 2283
2019-11-20 12:47:40,299 [salt.minion      :1711][INFO    ][2283] Returning information for job: 20191120124740239362
2019-11-20 12:47:48,265 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1509.53102708s left)
2019-11-20 12:48:10,432 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124810419395
2019-11-20 12:48:10,454 [salt.minion      :1432][INFO    ][2317] Starting a new job with PID 2317
2019-11-20 12:48:10,479 [salt.minion      :1711][INFO    ][2317] Returning information for job: 20191120124810419395
2019-11-20 12:48:21,672 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1476.12447786s left)
2019-11-20 12:48:40,623 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124840610202
2019-11-20 12:48:40,641 [salt.minion      :1432][INFO    ][2487] Starting a new job with PID 2487
2019-11-20 12:48:40,663 [salt.minion      :1711][INFO    ][2487] Returning information for job: 20191120124840610202
2019-11-20 12:48:55,415 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1442.38181591s left)
2019-11-20 12:49:10,816 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124910803692
2019-11-20 12:49:10,839 [salt.minion      :1432][INFO    ][2532] Starting a new job with PID 2532
2019-11-20 12:49:10,863 [salt.minion      :1711][INFO    ][2532] Returning information for job: 20191120124910803692
2019-11-20 12:49:28,906 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1408.89076996s left)
2019-11-20 12:49:41,031 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120124941019221
2019-11-20 12:49:41,052 [salt.minion      :1432][INFO    ][2578] Starting a new job with PID 2578
2019-11-20 12:49:41,079 [salt.minion      :1711][INFO    ][2578] Returning information for job: 20191120124941019221
2019-11-20 12:50:02,368 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1375.42849207s left)
2019-11-20 12:50:11,049 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125011036246
2019-11-20 12:50:11,071 [salt.minion      :1432][INFO    ][2611] Starting a new job with PID 2611
2019-11-20 12:50:11,096 [salt.minion      :1711][INFO    ][2611] Returning information for job: 20191120125011036246
2019-11-20 12:50:36,009 [salt.loaded.ext.module.maas:1023][INFO    ][31148] Waiting status:Deployed for machines:['kvm03']
sleep for:30s Timeout:2250s (1341.78794599s left)
2019-11-20 12:50:41,078 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125041066118
2019-11-20 12:50:41,102 [salt.minion      :1432][INFO    ][2657] Starting a new job with PID 2657
2019-11-20 12:50:41,126 [salt.minion      :1711][INFO    ][2657] Returning information for job: 20191120125041066118
2019-11-20 12:51:08,674 [salt.loaded.ext.module.maas:993 ][INFO    ][31148] Machine my7en6 mark broken
2019-11-20 12:51:09,441 [salt.loaded.ext.module.maas:996 ][INFO    ][31148] Machine my7en6 mark fixed
2019-11-20 12:51:10,655 [salt.loaded.ext.module.maas:684 ][INFO    ][31148] deploymachines hwe_kernel=hwe-16.04 system_id=my7en6 distro_series=xenial
2019-11-20 12:51:11,104 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125111095185
2019-11-20 12:51:11,127 [salt.minion      :1432][INFO    ][2707] Starting a new job with PID 2707
2019-11-20 12:51:11,153 [salt.minion      :1711][INFO    ][2707] Returning information for job: 20191120125111095185
2019-11-20 12:51:13,388 [salt.loaded.ext.module.maas:160 ][ERROR   ][31148] Failed for object kvm03 reason Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node.
2019-11-20 12:51:13,389 [salt.state       :302 ][ERROR   ][31148] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm02'], 'errors': {'kvm03': "Unable to change power state to 'cycle' for node kvm03: another action is already in progress for that node."}, 'success': []}
2019-11-20 12:51:13,390 [salt.state       :1951][INFO    ][31148] Completed state [maas.wait_for_machine_status] at time 12:51:13.390065 duration_in_ms=945598.19
2019-11-20 12:51:13,397 [salt.minion      :1711][INFO    ][31148] Returning information for job: 20191120123522752864
2019-11-20 12:51:24,156 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command pillar.get with jid 20191120125124144196
2019-11-20 12:51:24,177 [salt.minion      :1432][INFO    ][2783] Starting a new job with PID 2783
2019-11-20 12:51:24,186 [salt.minion      :1711][INFO    ][2783] Returning information for job: 20191120125124144196
2019-11-20 12:51:24,681 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command service.status with jid 20191120125124668649
2019-11-20 12:51:24,700 [salt.minion      :1432][INFO    ][2788] Starting a new job with PID 2788
2019-11-20 12:51:25,016 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][2788] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:25,051 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][2788] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-11-20 12:51:25,067 [salt.minion      :1711][INFO    ][2788] Returning information for job: 20191120125124668649
2019-11-20 12:51:25,659 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120125125647461
2019-11-20 12:51:25,680 [salt.minion      :1432][INFO    ][2800] Starting a new job with PID 2800
2019-11-20 12:51:29,373 [salt.state       :915 ][INFO    ][2800] Loading fresh modules for state activity
2019-11-20 12:51:29,803 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'salt-minion --version' in directory '/root'
2019-11-20 12:51:30,132 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'salt-minion --version' in directory '/root'
2019-11-20 12:51:31,034 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'salt-minion --version' in directory '/root'
2019-11-20 12:51:31,401 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'salt-minion --version' in directory '/root'
2019-11-20 12:51:32,746 [salt.state       :1780][INFO    ][2800] Running state [salt-minion] at time 12:51:32.746577
2019-11-20 12:51:32,746 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [salt-minion]
2019-11-20 12:51:32,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-20 12:51:32,844 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:32,844 [salt.state       :1951][INFO    ][2800] Completed state [salt-minion] at time 12:51:32.844850 duration_in_ms=98.273
2019-11-20 12:51:32,845 [salt.state       :1780][INFO    ][2800] Running state [salt_minion_dependency_packages] at time 12:51:32.845267
2019-11-20 12:51:32,845 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-11-20 12:51:32,853 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:32,853 [salt.state       :1951][INFO    ][2800] Completed state [salt_minion_dependency_packages] at time 12:51:32.853836 duration_in_ms=8.568
2019-11-20 12:51:32,857 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/minion.d/minion.conf] at time 12:51:32.857703
2019-11-20 12:51:32,858 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-11-20 12:51:33,105 [salt.state       :300 ][INFO    ][2800] File /etc/salt/minion.d/minion.conf is in the correct state
2019-11-20 12:51:33,105 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/minion.d/minion.conf] at time 12:51:33.105884 duration_in_ms=248.18
2019-11-20 12:51:33,106 [salt.state       :1780][INFO    ][2800] Running state [python-netaddr] at time 12:51:33.106176
2019-11-20 12:51:33,106 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [python-netaddr]
2019-11-20 12:51:33,114 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:33,114 [salt.state       :1951][INFO    ][2800] Completed state [python-netaddr] at time 12:51:33.114781 duration_in_ms=8.604
2019-11-20 12:51:33,118 [salt.state       :1780][INFO    ][2800] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 12:51:33.118309
2019-11-20 12:51:33,118 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-11-20 12:51:33,130 [salt.state       :300 ][INFO    ][2800] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-11-20 12:51:33,130 [salt.state       :1951][INFO    ][2800] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 12:51:33.130415 duration_in_ms=12.106
2019-11-20 12:51:33,131 [salt.state       :1780][INFO    ][2800] Running state [salt-minion] at time 12:51:33.131586
2019-11-20 12:51:33,131 [salt.state       :1813][INFO    ][2800] Executing state service.running for [salt-minion]
2019-11-20 12:51:33,132 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:33,174 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-11-20 12:51:33,194 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-11-20 12:51:33,211 [salt.state       :300 ][INFO    ][2800] The service salt-minion is already running
2019-11-20 12:51:33,212 [salt.state       :1951][INFO    ][2800] Completed state [salt-minion] at time 12:51:33.212028 duration_in_ms=80.441
2019-11-20 12:51:33,214 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains.d] at time 12:51:33.213990
2019-11-20 12:51:33,214 [salt.state       :1813][INFO    ][2800] Executing state file.directory for [/etc/salt/grains.d]
2019-11-20 12:51:33,215 [salt.state       :300 ][INFO    ][2800] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-11-20 12:51:33,215 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains.d] at time 12:51:33.215931 duration_in_ms=1.941
2019-11-20 12:51:33,216 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains] at time 12:51:33.216791
2019-11-20 12:51:33,217 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/grains]
2019-11-20 12:51:33,217 [salt.state       :300 ][INFO    ][2800] File /etc/salt/grains exists with proper permissions. No changes made.
2019-11-20 12:51:33,218 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains] at time 12:51:33.218161 duration_in_ms=1.369
2019-11-20 12:51:33,218 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains.d/placeholder] at time 12:51:33.218764
2019-11-20 12:51:33,219 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-11-20 12:51:33,219 [salt.state       :300 ][INFO    ][2800] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-11-20 12:51:33,220 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains.d/placeholder] at time 12:51:33.220072 duration_in_ms=1.309
2019-11-20 12:51:33,220 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains.d/sphinx] at time 12:51:33.220670
2019-11-20 12:51:33,221 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-11-20 12:51:33,231 [salt.state       :300 ][INFO    ][2800] File /etc/salt/grains.d/sphinx is in the correct state
2019-11-20 12:51:33,231 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains.d/sphinx] at time 12:51:33.231679 duration_in_ms=11.009
2019-11-20 12:51:33,234 [salt.state       :1780][INFO    ][2800] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.234450
2019-11-20 12:51:33,234 [salt.state       :1813][INFO    ][2800] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-11-20 12:51:33,235 [salt.state       :300 ][INFO    ][2800] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-11-20 12:51:33,235 [salt.state       :1951][INFO    ][2800] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.235557 duration_in_ms=1.107
2019-11-20 12:51:33,236 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains.d/dns_records] at time 12:51:33.236146
2019-11-20 12:51:33,236 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-11-20 12:51:33,243 [salt.state       :300 ][INFO    ][2800] File /etc/salt/grains.d/dns_records is in the correct state
2019-11-20 12:51:33,243 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains.d/dns_records] at time 12:51:33.243523 duration_in_ms=7.377
2019-11-20 12:51:33,244 [salt.state       :1780][INFO    ][2800] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.244687
2019-11-20 12:51:33,245 [salt.state       :1813][INFO    ][2800] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-11-20 12:51:33,245 [salt.state       :300 ][INFO    ][2800] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-11-20 12:51:33,245 [salt.state       :1951][INFO    ][2800] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.245757 duration_in_ms=1.07
2019-11-20 12:51:33,246 [salt.state       :1780][INFO    ][2800] Running state [/etc/salt/grains.d/salt] at time 12:51:33.246344
2019-11-20 12:51:33,246 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-11-20 12:51:33,261 [salt.state       :300 ][INFO    ][2800] File /etc/salt/grains.d/salt is in the correct state
2019-11-20 12:51:33,261 [salt.state       :1951][INFO    ][2800] Completed state [/etc/salt/grains.d/salt] at time 12:51:33.261579 duration_in_ms=15.234
2019-11-20 12:51:33,262 [salt.state       :1780][INFO    ][2800] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.262700
2019-11-20 12:51:33,263 [salt.state       :1813][INFO    ][2800] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-11-20 12:51:33,263 [salt.state       :300 ][INFO    ][2800] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-11-20 12:51:33,263 [salt.state       :1951][INFO    ][2800] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 12:51:33.263759 duration_in_ms=1.06
2019-11-20 12:51:33,266 [salt.state       :1780][INFO    ][2800] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 12:51:33.266131
2019-11-20 12:51:33,266 [salt.state       :1813][INFO    ][2800] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-11-20 12:51:33,266 [salt.state       :300 ][INFO    ][2800] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-11-20 12:51:33,267 [salt.state       :1951][INFO    ][2800] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 12:51:33.267193 duration_in_ms=1.061
2019-11-20 12:51:33,268 [salt.state       :1780][INFO    ][2800] Running state [mine.update] at time 12:51:33.268036
2019-11-20 12:51:33,268 [salt.state       :1813][INFO    ][2800] Executing state module.wait for [mine.update]
2019-11-20 12:51:33,268 [salt.state       :300 ][INFO    ][2800] No changes made for mine.update
2019-11-20 12:51:33,269 [salt.state       :1951][INFO    ][2800] Completed state [mine.update] at time 12:51:33.269031 duration_in_ms=0.995
2019-11-20 12:51:33,269 [salt.state       :1780][INFO    ][2800] Running state [ca-certificates] at time 12:51:33.269326
2019-11-20 12:51:33,269 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [ca-certificates]
2019-11-20 12:51:33,278 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:33,278 [salt.state       :1951][INFO    ][2800] Completed state [ca-certificates] at time 12:51:33.278831 duration_in_ms=9.504
2019-11-20 12:51:33,279 [salt.state       :1780][INFO    ][2800] Running state [update-ca-certificates] at time 12:51:33.279666
2019-11-20 12:51:33,280 [salt.state       :1813][INFO    ][2800] Executing state cmd.wait for [update-ca-certificates]
2019-11-20 12:51:33,280 [salt.state       :300 ][INFO    ][2800] No changes made for update-ca-certificates
2019-11-20 12:51:33,280 [salt.state       :1951][INFO    ][2800] Completed state [update-ca-certificates] at time 12:51:33.280647 duration_in_ms=0.98
2019-11-20 12:51:33,280 [salt.state       :1780][INFO    ][2800] Running state [iptables] at time 12:51:33.280936
2019-11-20 12:51:33,281 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [iptables]
2019-11-20 12:51:33,289 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:33,289 [salt.state       :1951][INFO    ][2800] Completed state [iptables] at time 12:51:33.289583 duration_in_ms=8.647
2019-11-20 12:51:33,289 [salt.state       :1780][INFO    ][2800] Running state [iptables-persistent] at time 12:51:33.289868
2019-11-20 12:51:33,290 [salt.state       :1813][INFO    ][2800] Executing state pkg.installed for [iptables-persistent]
2019-11-20 12:51:33,298 [salt.state       :300 ][INFO    ][2800] All specified packages are already installed
2019-11-20 12:51:33,298 [salt.state       :1951][INFO    ][2800] Completed state [iptables-persistent] at time 12:51:33.298302 duration_in_ms=8.435
2019-11-20 12:51:33,299 [salt.state       :1780][INFO    ][2800] Running state [iptables_modules_v4_load] at time 12:51:33.299457
2019-11-20 12:51:33,299 [salt.state       :1813][INFO    ][2800] Executing state kmod.present for [iptables_modules_v4_load]
2019-11-20 12:51:33,300 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'lsmod' in directory '/root'
2019-11-20 12:51:33,323 [salt.state       :300 ][INFO    ][2800] Kernel modules iptable_filter, ip_tables are already present
2019-11-20 12:51:33,323 [salt.state       :1951][INFO    ][2800] Completed state [iptables_modules_v4_load] at time 12:51:33.323470 duration_in_ms=24.013
2019-11-20 12:51:33,324 [salt.state       :1780][INFO    ][2800] Running state [/etc/iptables/rules.v4] at time 12:51:33.324239
2019-11-20 12:51:33,324 [salt.state       :1813][INFO    ][2800] Executing state file.managed for [/etc/iptables/rules.v4]
2019-11-20 12:51:33,423 [salt.state       :300 ][INFO    ][2800] File /etc/iptables/rules.v4 is in the correct state
2019-11-20 12:51:33,423 [salt.state       :1951][INFO    ][2800] Completed state [/etc/iptables/rules.v4] at time 12:51:33.423292 duration_in_ms=99.053
2019-11-20 12:51:33,424 [salt.state       :1780][INFO    ][2800] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 12:51:33.424283
2019-11-20 12:51:33,424 [salt.state       :1813][INFO    ][2800] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-11-20 12:51:33,425 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-11-20 12:51:33,446 [salt.state       :300 ][INFO    ][2800] onlyif execution failed
2019-11-20 12:51:33,446 [salt.state       :1951][INFO    ][2800] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 12:51:33.446514 duration_in_ms=22.23
2019-11-20 12:51:33,447 [salt.state       :1780][INFO    ][2800] Running state [netfilter-persistent] at time 12:51:33.447888
2019-11-20 12:51:33,448 [salt.state       :1813][INFO    ][2800] Executing state service.running for [netfilter-persistent]
2019-11-20 12:51:33,449 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:33,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-11-20 12:51:33,487 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-11-20 12:51:33,505 [salt.state       :300 ][INFO    ][2800] The service netfilter-persistent is already running
2019-11-20 12:51:33,506 [salt.state       :1951][INFO    ][2800] Completed state [netfilter-persistent] at time 12:51:33.506380 duration_in_ms=58.491
2019-11-20 12:51:33,507 [salt.state       :1780][INFO    ][2800] Running state [iptables_extra.remove_stale_tables] at time 12:51:33.507640
2019-11-20 12:51:33,508 [salt.state       :1813][INFO    ][2800] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-11-20 12:51:33,508 [salt.state       :300 ][INFO    ][2800] No changes made for iptables_extra.remove_stale_tables
2019-11-20 12:51:33,508 [salt.state       :1951][INFO    ][2800] Completed state [iptables_extra.remove_stale_tables] at time 12:51:33.508928 duration_in_ms=1.287
2019-11-20 12:51:33,509 [salt.state       :1780][INFO    ][2800] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 12:51:33.509281
2019-11-20 12:51:33,509 [salt.state       :1813][INFO    ][2800] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-11-20 12:51:33,510 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2800] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-11-20 12:51:33,526 [salt.state       :300 ][INFO    ][2800] onlyif execution failed
2019-11-20 12:51:33,527 [salt.state       :1951][INFO    ][2800] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 12:51:33.527125 duration_in_ms=17.845
2019-11-20 12:51:33,528 [salt.state       :1780][INFO    ][2800] Running state [/etc/iptables/rules.v6] at time 12:51:33.528448
2019-11-20 12:51:33,528 [salt.state       :1813][INFO    ][2800] Executing state file.absent for [/etc/iptables/rules.v6]
2019-11-20 12:51:33,529 [salt.state       :300 ][INFO    ][2800] File /etc/iptables/rules.v6 is not present
2019-11-20 12:51:33,529 [salt.state       :1951][INFO    ][2800] Completed state [/etc/iptables/rules.v6] at time 12:51:33.529850 duration_in_ms=1.402
2019-11-20 12:51:33,530 [salt.state       :1780][INFO    ][2800] Running state [iptables_extra.flush_all] at time 12:51:33.530791
2019-11-20 12:51:33,531 [salt.state       :1813][INFO    ][2800] Executing state module.wait for [iptables_extra.flush_all]
2019-11-20 12:51:33,531 [salt.state       :300 ][INFO    ][2800] No changes made for iptables_extra.flush_all
2019-11-20 12:51:33,531 [salt.state       :1951][INFO    ][2800] Completed state [iptables_extra.flush_all] at time 12:51:33.531869 duration_in_ms=1.079
2019-11-20 12:51:33,535 [salt.minion      :1711][INFO    ][2800] Returning information for job: 20191120125125647461
2019-11-20 12:51:34,150 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120125134137435
2019-11-20 12:51:34,172 [salt.minion      :1432][INFO    ][2875] Starting a new job with PID 2875
2019-11-20 12:51:34,962 [salt.state       :915 ][INFO    ][2875] Loading fresh modules for state activity
2019-11-20 12:51:35,640 [salt.state       :1780][INFO    ][2875] Running state [maas-rack-controller] at time 12:51:35.640028
2019-11-20 12:51:35,640 [salt.state       :1813][INFO    ][2875] Executing state pkg.installed for [maas-rack-controller]
2019-11-20 12:51:35,640 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-20 12:51:35,719 [salt.state       :300 ][INFO    ][2875] All specified packages are already installed
2019-11-20 12:51:35,719 [salt.state       :1951][INFO    ][2875] Completed state [maas-rack-controller] at time 12:51:35.719508 duration_in_ms=79.479
2019-11-20 12:51:35,719 [salt.state       :1780][INFO    ][2875] Running state [ipmitool] at time 12:51:35.719768
2019-11-20 12:51:35,719 [salt.state       :1813][INFO    ][2875] Executing state pkg.installed for [ipmitool]
2019-11-20 12:51:35,724 [salt.state       :300 ][INFO    ][2875] All specified packages are already installed
2019-11-20 12:51:35,724 [salt.state       :1951][INFO    ][2875] Completed state [ipmitool] at time 12:51:35.724547 duration_in_ms=4.779
2019-11-20 12:51:35,726 [salt.state       :1780][INFO    ][2875] Running state [/etc/maas/rackd.conf] at time 12:51:35.726860
2019-11-20 12:51:35,727 [salt.state       :1813][INFO    ][2875] Executing state file.line for [/etc/maas/rackd.conf]
2019-11-20 12:51:35,727 [salt.state       :300 ][INFO    ][2875] No changes needed to be made
2019-11-20 12:51:35,728 [salt.state       :1951][INFO    ][2875] Completed state [/etc/maas/rackd.conf] at time 12:51:35.728000 duration_in_ms=1.139
2019-11-20 12:51:35,728 [salt.state       :1780][INFO    ][2875] Running state [/etc/maas/rackd.conf] at time 12:51:35.728165
2019-11-20 12:51:35,728 [salt.state       :1813][INFO    ][2875] Executing state file.managed for [/etc/maas/rackd.conf]
2019-11-20 12:51:35,728 [salt.loaded.int.states.file:2298][WARNING ][2875] 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-11-20 12:51:35,728 [salt.state       :300 ][INFO    ][2875] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-11-20 12:51:35,729 [salt.state       :1951][INFO    ][2875] Completed state [/etc/maas/rackd.conf] at time 12:51:35.729087 duration_in_ms=0.921
2019-11-20 12:51:35,729 [salt.state       :1780][INFO    ][2875] Running state [maas-rackd] at time 12:51:35.729793
2019-11-20 12:51:35,729 [salt.state       :1813][INFO    ][2875] Executing state service.running for [maas-rackd]
2019-11-20 12:51:35,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:35,761 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-11-20 12:51:35,776 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2875] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-11-20 12:51:35,791 [salt.state       :300 ][INFO    ][2875] The service maas-rackd is already running
2019-11-20 12:51:35,791 [salt.state       :1951][INFO    ][2875] Completed state [maas-rackd] at time 12:51:35.791868 duration_in_ms=62.074
2019-11-20 12:51:35,793 [salt.minion      :1711][INFO    ][2875] Returning information for job: 20191120125134137435
2019-11-20 12:51:36,424 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120125136411070
2019-11-20 12:51:36,447 [salt.minion      :1432][INFO    ][2898] Starting a new job with PID 2898
2019-11-20 12:51:37,204 [salt.state       :915 ][INFO    ][2898] Loading fresh modules for state activity
2019-11-20 12:51:37,897 [salt.state       :1780][INFO    ][2898] Running state [maas-region-controller] at time 12:51:37.897907
2019-11-20 12:51:37,898 [salt.state       :1813][INFO    ][2898] Executing state pkg.installed for [maas-region-controller]
2019-11-20 12:51:37,898 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-11-20 12:51:37,976 [salt.state       :300 ][INFO    ][2898] All specified packages are already installed
2019-11-20 12:51:37,976 [salt.state       :1951][INFO    ][2898] Completed state [maas-region-controller] at time 12:51:37.976814 duration_in_ms=78.907
2019-11-20 12:51:37,977 [salt.state       :1780][INFO    ][2898] Running state [python-oauth] at time 12:51:37.977050
2019-11-20 12:51:37,977 [salt.state       :1813][INFO    ][2898] Executing state pkg.installed for [python-oauth]
2019-11-20 12:51:37,981 [salt.state       :300 ][INFO    ][2898] All specified packages are already installed
2019-11-20 12:51:37,981 [salt.state       :1951][INFO    ][2898] Completed state [python-oauth] at time 12:51:37.981784 duration_in_ms=4.734
2019-11-20 12:51:37,984 [salt.state       :1780][INFO    ][2898] Running state [/etc/maas/regiond.conf] at time 12:51:37.984046
2019-11-20 12:51:37,984 [salt.state       :1813][INFO    ][2898] Executing state file.replace for [/etc/maas/regiond.conf]
2019-11-20 12:51:38,028 [salt.state       :300 ][INFO    ][2898] No changes needed to be made
2019-11-20 12:51:38,028 [salt.state       :1951][INFO    ][2898] Completed state [/etc/maas/regiond.conf] at time 12:51:38.028830 duration_in_ms=44.783
2019-11-20 12:51:38,029 [salt.state       :1780][INFO    ][2898] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 12:51:38.029341
2019-11-20 12:51:38,029 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-11-20 12:51:38,087 [salt.state       :300 ][INFO    ][2898] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-11-20 12:51:38,088 [salt.state       :1951][INFO    ][2898] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 12:51:38.088042 duration_in_ms=58.701
2019-11-20 12:51:38,088 [salt.state       :1780][INFO    ][2898] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:51:38.088561
2019-11-20 12:51:38,088 [salt.state       :1813][INFO    ][2898] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-20 12:51:38,107 [salt.state       :300 ][INFO    ][2898] No changes needed to be made
2019-11-20 12:51:38,107 [salt.state       :1951][INFO    ][2898] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:51:38.107319 duration_in_ms=18.757
2019-11-20 12:51:38,107 [salt.state       :1780][INFO    ][2898] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:51:38.107827
2019-11-20 12:51:38,108 [salt.state       :1813][INFO    ][2898] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-11-20 12:51:38,137 [salt.state       :300 ][INFO    ][2898] No changes needed to be made
2019-11-20 12:51:38,137 [salt.state       :1951][INFO    ][2898] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 12:51:38.137328 duration_in_ms=29.501
2019-11-20 12:51:38,137 [salt.state       :1780][INFO    ][2898] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 12:51:38.137838
2019-11-20 12:51:38,138 [salt.state       :1813][INFO    ][2898] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-11-20 12:51:38,161 [salt.state       :300 ][INFO    ][2898] No changes needed to be made
2019-11-20 12:51:38,161 [salt.state       :1951][INFO    ][2898] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 12:51:38.161791 duration_in_ms=23.953
2019-11-20 12:51:38,162 [salt.state       :1780][INFO    ][2898] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 12:51:38.162255
2019-11-20 12:51:38,162 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-11-20 12:51:38,173 [salt.state       :300 ][INFO    ][2898] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-11-20 12:51:38,174 [salt.state       :1951][INFO    ][2898] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 12:51:38.174034 duration_in_ms=11.779
2019-11-20 12:51:38,175 [salt.state       :1780][INFO    ][2898] Running state [a2enmod headers] at time 12:51:38.175178
2019-11-20 12:51:38,175 [salt.state       :1813][INFO    ][2898] Executing state cmd.run for [a2enmod headers]
2019-11-20 12:51:38,176 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command 'a2enmod headers' in directory '/root'
2019-11-20 12:51:38,247 [salt.state       :300 ][INFO    ][2898] {'pid': 2917, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-11-20 12:51:38,248 [salt.state       :1951][INFO    ][2898] Completed state [a2enmod headers] at time 12:51:38.248105 duration_in_ms=72.926
2019-11-20 12:51:38,248 [salt.state       :1780][INFO    ][2898] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 12:51:38.248710
2019-11-20 12:51:38,249 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-11-20 12:51:38,268 [salt.state       :300 ][INFO    ][2898] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-11-20 12:51:38,268 [salt.state       :1951][INFO    ][2898] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 12:51:38.268699 duration_in_ms=19.989
2019-11-20 12:51:38,269 [salt.state       :1780][INFO    ][2898] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 12:51:38.269528
2019-11-20 12:51:38,269 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-11-20 12:51:38,376 [salt.state       :300 ][INFO    ][2898] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-11-20 12:51:38,377 [salt.state       :1951][INFO    ][2898] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 12:51:38.377367 duration_in_ms=107.826
2019-11-20 12:51:38,378 [salt.state       :1780][INFO    ][2898] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 12:51:38.378666
2019-11-20 12:51:38,379 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-11-20 12:51:38,447 [salt.state       :300 ][INFO    ][2898] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-11-20 12:51:38,447 [salt.state       :1951][INFO    ][2898] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 12:51:38.447551 duration_in_ms=68.886
2019-11-20 12:51:38,448 [salt.state       :1780][INFO    ][2898] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 12:51:38.448076
2019-11-20 12:51:38,448 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-11-20 12:51:38,513 [salt.state       :300 ][INFO    ][2898] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-11-20 12:51:38,513 [salt.state       :1951][INFO    ][2898] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 12:51:38.513357 duration_in_ms=65.282
2019-11-20 12:51:38,513 [salt.state       :1780][INFO    ][2898] Running state [/root/.pgpass] at time 12:51:38.513665
2019-11-20 12:51:38,513 [salt.state       :1813][INFO    ][2898] Executing state file.managed for [/root/.pgpass]
2019-11-20 12:51:38,561 [salt.state       :300 ][INFO    ][2898] File /root/.pgpass is in the correct state
2019-11-20 12:51:38,561 [salt.state       :1951][INFO    ][2898] Completed state [/root/.pgpass] at time 12:51:38.561239 duration_in_ms=47.574
2019-11-20 12:51:38,567 [salt.state       :1780][INFO    ][2898] Running state [maas-region syncdb --noinput] at time 12:51:38.567255
2019-11-20 12:51:38,567 [salt.state       :1813][INFO    ][2898] Executing state cmd.run for [maas-region syncdb --noinput]
2019-11-20 12:51:38,568 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-11-20 12:51:40,600 [salt.state       :300 ][INFO    ][2898] {'pid': 2930, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, piston3, sessions, sites, auth, contenttypes, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-11-20 12:51:40,601 [salt.state       :1951][INFO    ][2898] Completed state [maas-region syncdb --noinput] at time 12:51:40.601216 duration_in_ms=2033.959
2019-11-20 12:51:40,601 [salt.state       :2022][WARNING ][2898] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-11-20 12:51:40,605 [salt.state       :1780][INFO    ][2898] Running state [maas-regiond] at time 12:51:40.605105
2019-11-20 12:51:40,605 [salt.state       :1813][INFO    ][2898] Executing state service.running for [maas-regiond]
2019-11-20 12:51:40,607 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:40,647 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-11-20 12:51:40,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-11-20 12:51:40,683 [salt.state       :300 ][INFO    ][2898] The service maas-regiond is already running
2019-11-20 12:51:40,684 [salt.state       :1951][INFO    ][2898] Completed state [maas-regiond] at time 12:51:40.684119 duration_in_ms=79.013
2019-11-20 12:51:40,686 [salt.state       :1780][INFO    ][2898] Running state [bind9] at time 12:51:40.686715
2019-11-20 12:51:40,687 [salt.state       :1813][INFO    ][2898] Executing state service.running for [bind9]
2019-11-20 12:51:40,688 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:40,707 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-11-20 12:51:40,725 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-11-20 12:51:40,742 [salt.state       :300 ][INFO    ][2898] The service bind9 is already running
2019-11-20 12:51:40,742 [salt.state       :1951][INFO    ][2898] Completed state [bind9] at time 12:51:40.742642 duration_in_ms=55.925
2019-11-20 12:51:40,745 [salt.state       :1780][INFO    ][2898] Running state [apache2] at time 12:51:40.745107
2019-11-20 12:51:40,745 [salt.state       :1813][INFO    ][2898] Executing state service.running for [apache2]
2019-11-20 12:51:40,746 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-11-20 12:51:40,765 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-11-20 12:51:40,782 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-11-20 12:51:40,803 [salt.state       :300 ][INFO    ][2898] The service apache2 is already running
2019-11-20 12:51:40,804 [salt.state       :1951][INFO    ][2898] Completed state [apache2] at time 12:51:40.804459 duration_in_ms=59.352
2019-11-20 12:51:40,807 [salt.state       :1780][INFO    ][2898] Running state [maasng.wait_for_http_code] at time 12:51:40.807306
2019-11-20 12:51:40,807 [salt.state       :1813][INFO    ][2898] Executing state module.run for [maasng.wait_for_http_code]
2019-11-20 12:51:40,808 [salt.utils.decorators:613 ][WARNING ][2898] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:51:40,945 [salt.state       :300 ][INFO    ][2898] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-11-20 12:51:40,946 [salt.state       :1951][INFO    ][2898] Completed state [maasng.wait_for_http_code] at time 12:51:40.946286 duration_in_ms=138.98
2019-11-20 12:51:40,947 [salt.state       :1780][INFO    ][2898] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 12:51:40.947608
2019-11-20 12:51:40,948 [salt.state       :1813][INFO    ][2898] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-11-20 12:51:40,948 [salt.state       :300 ][INFO    ][2898] /var/lib/maas/.setup_admin exists
2019-11-20 12:51:40,949 [salt.state       :1951][INFO    ][2898] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 12:51:40.949043 duration_in_ms=1.436
2019-11-20 12:51:40,950 [salt.state       :1780][INFO    ][2898] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:51:40.950046
2019-11-20 12:51:40,950 [salt.state       :1813][INFO    ][2898] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:51:40,951 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2898] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:51:42,493 [salt.state       :300 ][INFO    ][2898] {'pid': 2968, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:51:42,493 [salt.state       :1951][INFO    ][2898] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:51:42.493814 duration_in_ms=1543.766
2019-11-20 12:51:42,502 [salt.state       :1780][INFO    ][2898] Running state [maas_region_boot_source_resources_mirror] at time 12:51:42.502182
2019-11-20 12:51:42,502 [salt.state       :1813][INFO    ][2898] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-11-20 12:51:42,621 [salt.state       :300 ][INFO    ][2898] {'changes': {}}
2019-11-20 12:51:42,622 [salt.state       :1951][INFO    ][2898] Completed state [maas_region_boot_source_resources_mirror] at time 12:51:42.622049 duration_in_ms=119.867
2019-11-20 12:51:42,623 [salt.state       :1780][INFO    ][2898] Running state [maasng.boot_resources_import] at time 12:51:42.623149
2019-11-20 12:51:42,623 [salt.state       :1813][INFO    ][2898] Executing state module.run for [maasng.boot_resources_import]
2019-11-20 12:51:42,624 [salt.utils.decorators:613 ][WARNING ][2898] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:51:42,748 [salt.loaded.ext.module.maasng:1600][INFO    ][2898] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-11-20 12:51:47,829 [salt.loaded.ext.module.maasng:1600][INFO    ][2898] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-11-20 12:51:51,473 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125151460386
2019-11-20 12:51:51,493 [salt.minion      :1432][INFO    ][3002] Starting a new job with PID 3002
2019-11-20 12:51:51,516 [salt.minion      :1711][INFO    ][3002] Returning information for job: 20191120125151460386
2019-11-20 12:51:52,887 [salt.loaded.ext.module.maasng:1600][INFO    ][2898] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-11-20 12:51:58,007 [salt.state       :300 ][INFO    ][2898] {'ret': True}
2019-11-20 12:51:58,008 [salt.state       :1951][INFO    ][2898] Completed state [maasng.boot_resources_import] at time 12:51:58.008119 duration_in_ms=15384.969
2019-11-20 12:51:58,009 [salt.state       :1780][INFO    ][2898] Running state [maas_region_boot_sources_selection_xenial] at time 12:51:58.009340
2019-11-20 12:51:58,009 [salt.state       :1813][INFO    ][2898] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-11-20 12:51:58,216 [salt.state       :300 ][INFO    ][2898] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-11-20 12:51:58,217 [salt.state       :1951][INFO    ][2898] Completed state [maas_region_boot_sources_selection_xenial] at time 12:51:58.217028 duration_in_ms=207.688
2019-11-20 12:51:58,218 [salt.state       :1780][INFO    ][2898] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 12:51:58.218346
2019-11-20 12:51:58,218 [salt.state       :1813][INFO    ][2898] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-11-20 12:51:58,219 [salt.utils.decorators:613 ][WARNING ][2898] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:51:58,220 [salt.loaded.ext.module.maasng:1771][INFO    ][2898] boot-sources sync initiated for ALL Rack's
2019-11-20 12:51:59,174 [salt.state       :300 ][INFO    ][2898] {'ret': True}
2019-11-20 12:51:59,175 [salt.state       :1951][INFO    ][2898] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 12:51:59.174951 duration_in_ms=956.605
2019-11-20 12:51:59,177 [salt.state       :1780][INFO    ][2898] Running state [maas.process_maas_config] at time 12:51:59.176989
2019-11-20 12:51:59,177 [salt.state       :1813][INFO    ][2898] Executing state module.run for [maas.process_maas_config]
2019-11-20 12:51:59,178 [salt.utils.decorators:613 ][WARNING ][2898] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:51:59,179 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=enable_http_proxy value=True
2019-11-20 12:51:59,252 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=upstream_dns value=8.8.8.8
2019-11-20 12:51:59,318 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=commissioning_distro_series value=xenial
2019-11-20 12:51:59,378 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=default_osystem value=ubuntu
2019-11-20 12:52:02,285 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=active_discovery_interval value=600
2019-11-20 12:52:02,348 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=dnssec_validation value=no
2019-11-20 12:52:02,408 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=maas_name value=mas01
2019-11-20 12:52:02,462 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=network_discovery value=enabled
2019-11-20 12:52:02,576 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=enable_third_party_drivers value=True
2019-11-20 12:52:02,630 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=default_storage_layout value=lvm
2019-11-20 12:52:02,693 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=ntp_external_only value=True
2019-11-20 12:52:02,756 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=disk_erase_with_secure_erase value=False
2019-11-20 12:52:02,815 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=default_distro_series value=xenial
2019-11-20 12:52:02,882 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-11-20 12:52:03,019 [salt.state       :300 ][INFO    ][2898] {'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-11-20 12:52:03,020 [salt.state       :1951][INFO    ][2898] Completed state [maas.process_maas_config] at time 12:52:03.020171 duration_in_ms=3843.18
2019-11-20 12:52:03,021 [salt.state       :1780][INFO    ][2898] Running state [pxe_admin] at time 12:52:03.021564
2019-11-20 12:52:03,022 [salt.state       :1813][INFO    ][2898] Executing state maasng.fabric_present for [pxe_admin]
2019-11-20 12:52:03,078 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'srmw3h', u'relay_vlan': None, u'external_dhcp': None, u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-11-20 12:52:03,150 [salt.loaded.ext.module.maasng:1008][WARNING ][2898] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-11-20 12:52:03,151 [salt.loaded.ext.module.maasng:1011][WARNING ][2898] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-11-20 12:52:03,235 [salt.state       :300 ][INFO    ][2898] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-11-20 12:52:03,235 [salt.state       :1951][INFO    ][2898] Completed state [pxe_admin] at time 12:52:03.235450 duration_in_ms=213.885
2019-11-20 12:52:03,235 [salt.state       :1780][INFO    ][2898] Running state [vlan 0] at time 12:52:03.235887
2019-11-20 12:52:03,236 [salt.state       :1813][INFO    ][2898] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-20 12:52:03,294 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, 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-11-20 12:52:03,408 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-11-20 12:52:03,695 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-20 12:52:03,767 [salt.state       :300 ][INFO    ][2898] {'new': 'Vlan untagged was updated'}
2019-11-20 12:52:03,768 [salt.state       :1951][INFO    ][2898] Completed state [vlan 0] at time 12:52:03.768310 duration_in_ms=532.421
2019-11-20 12:52:03,769 [salt.state       :1780][INFO    ][2898] Running state [192.168.11.0/24] at time 12:52:03.769575
2019-11-20 12:52:03,770 [salt.state       :1813][INFO    ][2898] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-11-20 12:52:03,989 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, 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-11-20 12:52:03,990 [salt.loaded.ext.module.maasng:1235][WARNING ][2898] Ignoring parameter vlan:0
2019-11-20 12:52:04,073 [salt.state       :300 ][INFO    ][2898] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-11-20 12:52:04,074 [salt.state       :1951][INFO    ][2898] Completed state [192.168.11.0/24] at time 12:52:04.074136 duration_in_ms=304.559
2019-11-20 12:52:04,075 [salt.state       :1780][INFO    ][2898] Running state [maas_create_iprange_1] at time 12:52:04.075724
2019-11-20 12:52:04,076 [salt.state       :1813][INFO    ][2898] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-11-20 12:52:04,133 [salt.state       :300 ][INFO    ][2898] Iprange maas_create_iprange_1 already exist.
2019-11-20 12:52:04,133 [salt.state       :1951][INFO    ][2898] Completed state [maas_create_iprange_1] at time 12:52:04.133421 duration_in_ms=57.697
2019-11-20 12:52:04,133 [salt.state       :1780][INFO    ][2898] Running state [vlan 0] at time 12:52:04.133816
2019-11-20 12:52:04,134 [salt.state       :1813][INFO    ][2898] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-11-20 12:52:04,174 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-20 12:52:04,282 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-11-20 12:52:04,457 [salt.loaded.ext.module.maasng:945 ][INFO    ][2898] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'srmw3h', u'mtu': 1500, 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-11-20 12:52:04,565 [salt.state       :300 ][INFO    ][2898] {'new': 'Vlan untagged was updated'}
2019-11-20 12:52:04,566 [salt.state       :1951][INFO    ][2898] Completed state [vlan 0] at time 12:52:04.566265 duration_in_ms=432.448
2019-11-20 12:52:04,567 [salt.state       :1780][INFO    ][2898] Running state [opnfv] at time 12:52:04.567135
2019-11-20 12:52:04,567 [salt.state       :1813][INFO    ][2898] Executing state maasng.sshkey_present for [opnfv]
2019-11-20 12:52:04,611 [salt.loaded.ext.module.maasng:1903][INFO    ][2898] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-11-20 12:52:04,612 [salt.state       :300 ][INFO    ][2898] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-11-20 12:52:04,612 [salt.state       :1951][INFO    ][2898] Completed state [opnfv] at time 12:52:04.612625 duration_in_ms=45.49
2019-11-20 12:52:04,613 [salt.state       :1780][INFO    ][2898] Running state [maas.process_tags] at time 12:52:04.613521
2019-11-20 12:52:04,613 [salt.state       :1813][INFO    ][2898] Executing state module.run for [maas.process_tags]
2019-11-20 12:52:04,614 [salt.utils.decorators:613 ][WARNING ][2898] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:52:04,671 [salt.loaded.ext.module.maas:92  ][INFO    ][2898] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-11-20 12:52:04,745 [salt.state       :300 ][INFO    ][2898] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-11-20 12:52:04,745 [salt.state       :1951][INFO    ][2898] Completed state [maas.process_tags] at time 12:52:04.745524 duration_in_ms=132.003
2019-11-20 12:52:04,749 [salt.minion      :1711][INFO    ][2898] Returning information for job: 20191120125136411070
2019-11-20 12:52:05,257 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120125205244331
2019-11-20 12:52:05,275 [salt.minion      :1432][INFO    ][3381] Starting a new job with PID 3381
2019-11-20 12:52:08,834 [salt.state       :915 ][INFO    ][3381] Loading fresh modules for state activity
2019-11-20 12:52:08,924 [salt.state       :1780][INFO    ][3381] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:52:08.924471
2019-11-20 12:52:08,924 [salt.state       :1813][INFO    ][3381] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:52:08,926 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3381] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:52:10,398 [salt.state       :300 ][INFO    ][3381] {'pid': 3404, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:52:10,399 [salt.state       :1951][INFO    ][3381] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:52:10.398894 duration_in_ms=1474.422
2019-11-20 12:52:10,401 [salt.state       :1780][INFO    ][3381] Running state [maas.process_machines] at time 12:52:10.401389
2019-11-20 12:52:10,401 [salt.state       :1813][INFO    ][3381] Executing state module.run for [maas.process_machines]
2019-11-20 12:52:10,403 [salt.utils.decorators:613 ][WARNING ][3381] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:52:10,861 [salt.loaded.ext.module.maas:412 ][WARNING ][3381] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:52:10,862 [salt.loaded.ext.module.maas:92  ][INFO    ][3381] 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=rrsm4a architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:52:11,744 [salt.loaded.ext.module.maas:412 ][WARNING ][3381] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:52:11,745 [salt.loaded.ext.module.maas:92  ][INFO    ][3381] 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=88gp34 architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:52:12,984 [salt.loaded.ext.module.maas:412 ][WARNING ][3381] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:52:12,984 [salt.loaded.ext.module.maas:92  ][INFO    ][3381] 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=ccea73 architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:52:14,259 [salt.loaded.ext.module.maas:412 ][WARNING ][3381] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:52:14,260 [salt.loaded.ext.module.maas:92  ][INFO    ][3381] 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=my7en6 architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:52:15,187 [salt.loaded.ext.module.maas:412 ][WARNING ][3381] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-11-20 12:52:15,188 [salt.loaded.ext.module.maas:92  ][INFO    ][3381] 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=rg6ggn architecture=amd64/generic power_parameters_power_user=admin
2019-11-20 12:52:16,452 [salt.state       :300 ][INFO    ][3381] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-20 12:52:16,452 [salt.state       :1951][INFO    ][3381] Completed state [maas.process_machines] at time 12:52:16.452811 duration_in_ms=6051.421
2019-11-20 12:52:16,456 [salt.minion      :1711][INFO    ][3381] Returning information for job: 20191120125205244331
2019-11-20 12:52:49,802 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120125249789228
2019-11-20 12:52:49,825 [salt.minion      :1432][INFO    ][3772] Starting a new job with PID 3772
2019-11-20 12:52:53,605 [salt.state       :915 ][INFO    ][3772] Loading fresh modules for state activity
2019-11-20 12:52:53,694 [salt.state       :1780][INFO    ][3772] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:52:53.694193
2019-11-20 12:52:53,694 [salt.state       :1813][INFO    ][3772] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 12:52:53,696 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3772] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 12:52:55,114 [salt.state       :300 ][INFO    ][3772] {'pid': 3779, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 12:52:55,114 [salt.state       :1951][INFO    ][3772] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 12:52:55.114534 duration_in_ms=1420.341
2019-11-20 12:52:55,115 [salt.state       :1780][INFO    ][3772] Running state [maas.wait_for_machine_status] at time 12:52:55.115668
2019-11-20 12:52:55,115 [salt.state       :1813][INFO    ][3772] Executing state module.run for [maas.wait_for_machine_status]
2019-11-20 12:52:55,116 [salt.utils.decorators:613 ][WARNING ][3772] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 12:52:57,147 [salt.loaded.ext.module.maas:993 ][INFO    ][3772] Machine my7en6 mark broken
2019-11-20 12:52:57,709 [salt.loaded.ext.module.maas:996 ][INFO    ][3772] Machine my7en6 mark fixed
2019-11-20 12:52:58,791 [salt.loaded.ext.module.maas:684 ][INFO    ][3772] deploymachines hwe_kernel=hwe-16.04 system_id=my7en6 distro_series=xenial
2019-11-20 12:53:01,863 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1493.25781107s left)
2019-11-20 12:53:04,905 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125304846160
2019-11-20 12:53:04,926 [salt.minion      :1432][INFO    ][3858] Starting a new job with PID 3858
2019-11-20 12:53:04,954 [salt.minion      :1711][INFO    ][3858] Returning information for job: 20191120125304846160
2019-11-20 12:53:34,954 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125334942031
2019-11-20 12:53:34,974 [salt.minion      :1432][INFO    ][3925] Starting a new job with PID 3925
2019-11-20 12:53:34,998 [salt.minion      :1711][INFO    ][3925] Returning information for job: 20191120125334942031
2019-11-20 12:53:35,386 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1459.73443007s left)
2019-11-20 12:54:05,022 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125405009578
2019-11-20 12:54:05,045 [salt.minion      :1432][INFO    ][3956] Starting a new job with PID 3956
2019-11-20 12:54:05,072 [salt.minion      :1711][INFO    ][3956] Returning information for job: 20191120125405009578
2019-11-20 12:54:08,787 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1426.33333111s left)
2019-11-20 12:54:35,075 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125435063061
2019-11-20 12:54:35,098 [salt.minion      :1432][INFO    ][3997] Starting a new job with PID 3997
2019-11-20 12:54:35,124 [salt.minion      :1711][INFO    ][3997] Returning information for job: 20191120125435063061
2019-11-20 12:54:41,661 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1393.4599781s left)
2019-11-20 12:55:05,124 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125505112275
2019-11-20 12:55:05,142 [salt.minion      :1432][INFO    ][4083] Starting a new job with PID 4083
2019-11-20 12:55:05,165 [salt.minion      :1711][INFO    ][4083] Returning information for job: 20191120125505112275
2019-11-20 12:55:15,188 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1359.93255401s left)
2019-11-20 12:55:35,175 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125535163401
2019-11-20 12:55:35,198 [salt.minion      :1432][INFO    ][4223] Starting a new job with PID 4223
2019-11-20 12:55:35,225 [salt.minion      :1711][INFO    ][4223] Returning information for job: 20191120125535163401
2019-11-20 12:55:48,841 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1326.27990508s left)
2019-11-20 12:56:05,238 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125605224303
2019-11-20 12:56:05,260 [salt.minion      :1432][INFO    ][4262] Starting a new job with PID 4262
2019-11-20 12:56:05,286 [salt.minion      :1711][INFO    ][4262] Returning information for job: 20191120125605224303
2019-11-20 12:56:21,967 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1293.15324306s left)
2019-11-20 12:56:35,302 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125635289381
2019-11-20 12:56:35,325 [salt.minion      :1432][INFO    ][4356] Starting a new job with PID 4356
2019-11-20 12:56:35,350 [salt.minion      :1711][INFO    ][4356] Returning information for job: 20191120125635289381
2019-11-20 12:56:55,614 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1259.50659895s left)
2019-11-20 12:57:05,367 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125705355292
2019-11-20 12:57:05,389 [salt.minion      :1432][INFO    ][4400] Starting a new job with PID 4400
2019-11-20 12:57:05,415 [salt.minion      :1711][INFO    ][4400] Returning information for job: 20191120125705355292
2019-11-20 12:57:29,225 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1225.89541793s left)
2019-11-20 12:57:35,445 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125735429297
2019-11-20 12:57:35,471 [salt.minion      :1432][INFO    ][4494] Starting a new job with PID 4494
2019-11-20 12:57:35,510 [salt.minion      :1711][INFO    ][4494] Returning information for job: 20191120125735429297
2019-11-20 12:58:02,747 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1192.37388611s left)
2019-11-20 12:58:05,539 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125805526081
2019-11-20 12:58:05,562 [salt.minion      :1432][INFO    ][4564] Starting a new job with PID 4564
2019-11-20 12:58:05,593 [salt.minion      :1711][INFO    ][4564] Returning information for job: 20191120125805526081
2019-11-20 12:58:35,623 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125835610348
2019-11-20 12:58:35,645 [salt.minion      :1432][INFO    ][4695] Starting a new job with PID 4695
2019-11-20 12:58:35,672 [salt.minion      :1711][INFO    ][4695] Returning information for job: 20191120125835610348
2019-11-20 12:58:36,232 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1158.88831496s left)
2019-11-20 12:59:05,705 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125905693135
2019-11-20 12:59:05,727 [salt.minion      :1432][INFO    ][4743] Starting a new job with PID 4743
2019-11-20 12:59:05,754 [salt.minion      :1711][INFO    ][4743] Returning information for job: 20191120125905693135
2019-11-20 12:59:09,989 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1125.13179302s left)
2019-11-20 12:59:35,795 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120125935782981
2019-11-20 12:59:35,818 [salt.minion      :1432][INFO    ][4784] Starting a new job with PID 4784
2019-11-20 12:59:35,844 [salt.minion      :1711][INFO    ][4784] Returning information for job: 20191120125935782981
2019-11-20 12:59:43,839 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1091.28127003s left)
2019-11-20 13:00:05,891 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120130005878793
2019-11-20 13:00:05,913 [salt.minion      :1432][INFO    ][4843] Starting a new job with PID 4843
2019-11-20 13:00:05,941 [salt.minion      :1711][INFO    ][4843] Returning information for job: 20191120130005878793
2019-11-20 13:00:16,932 [salt.loaded.ext.module.maas:1023][INFO    ][3772] Waiting status:Ready|Deployed for machines:['kvm03']
sleep for:30s Timeout:1500s (1058.18886304s left)
2019-11-20 13:00:36,076 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command saltutil.find_job with jid 20191120130036063583
2019-11-20 13:00:36,099 [salt.minion      :1432][INFO    ][4943] Starting a new job with PID 4943
2019-11-20 13:00:36,126 [salt.minion      :1711][INFO    ][4943] Returning information for job: 20191120130036063583
2019-11-20 13:00:50,769 [salt.state       :300 ][INFO    ][3772] {'ret': True}
2019-11-20 13:00:50,770 [salt.state       :1951][INFO    ][3772] Completed state [maas.wait_for_machine_status] at time 13:00:50.770174 duration_in_ms=475654.503
2019-11-20 13:00:50,774 [salt.minion      :1711][INFO    ][3772] Returning information for job: 20191120125249789228
2019-11-20 13:00:51,370 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120130051358289
2019-11-20 13:00:51,389 [salt.minion      :1432][INFO    ][5026] Starting a new job with PID 5026
2019-11-20 13:00:55,184 [salt.state       :915 ][INFO    ][5026] Loading fresh modules for state activity
2019-11-20 13:00:55,321 [salt.state       :1780][INFO    ][5026] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:00:55.321628
2019-11-20 13:00:55,321 [salt.state       :1813][INFO    ][5026] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 13:00:55,323 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5026] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 13:00:56,814 [salt.state       :300 ][INFO    ][5026] {'pid': 5035, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 13:00:56,815 [salt.state       :1951][INFO    ][5026] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:00:56.815243 duration_in_ms=1493.615
2019-11-20 13:00:56,817 [salt.state       :1780][INFO    ][5026] Running state [maas_machines_storage_cmp002_lvm] at time 13:00:56.817867
2019-11-20 13:00:56,818 [salt.state       :1813][INFO    ][5026] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-11-20 13:00:57,508 [salt.state       :300 ][INFO    ][5026] Machine cmp002 is not in Ready state.
2019-11-20 13:00:57,508 [salt.state       :1951][INFO    ][5026] Completed state [maas_machines_storage_cmp002_lvm] at time 13:00:57.508595 duration_in_ms=690.727
2019-11-20 13:00:57,509 [salt.state       :1780][INFO    ][5026] Running state [maas_machines_storage_cmp001_lvm] at time 13:00:57.509199
2019-11-20 13:00:57,509 [salt.state       :1813][INFO    ][5026] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-11-20 13:00:58,223 [salt.state       :300 ][INFO    ][5026] Machine cmp001 is not in Ready state.
2019-11-20 13:00:58,224 [salt.state       :1951][INFO    ][5026] Completed state [maas_machines_storage_cmp001_lvm] at time 13:00:58.224129 duration_in_ms=714.929
2019-11-20 13:00:58,228 [salt.minion      :1711][INFO    ][5026] Returning information for job: 20191120130051358289
2019-11-20 13:00:58,841 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120130058828839
2019-11-20 13:00:58,864 [salt.minion      :1432][INFO    ][5046] Starting a new job with PID 5046
2019-11-20 13:00:59,622 [salt.state       :915 ][INFO    ][5046] Loading fresh modules for state activity
2019-11-20 13:00:59,709 [salt.state       :1780][INFO    ][5046] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:00:59.709696
2019-11-20 13:00:59,710 [salt.state       :1813][INFO    ][5046] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 13:00:59,712 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5046] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 13:01:01,177 [salt.state       :300 ][INFO    ][5046] {'pid': 5053, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 13:01:01,178 [salt.state       :1951][INFO    ][5046] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:01:01.178815 duration_in_ms=1469.118
2019-11-20 13:01:01,181 [salt.state       :1780][INFO    ][5046] Running state [maas.deploy_machines] at time 13:01:01.181609
2019-11-20 13:01:01,182 [salt.state       :1813][INFO    ][5046] Executing state module.run for [maas.deploy_machines]
2019-11-20 13:01:01,183 [salt.utils.decorators:613 ][WARNING ][5046] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 13:01:01,971 [salt.state       :300 ][INFO    ][5046] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-11-20 13:01:01,971 [salt.state       :1951][INFO    ][5046] Completed state [maas.deploy_machines] at time 13:01:01.971679 duration_in_ms=790.068
2019-11-20 13:01:01,975 [salt.minion      :1711][INFO    ][5046] Returning information for job: 20191120130058828839
2019-11-20 13:01:02,613 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command state.apply with jid 20191120130102600354
2019-11-20 13:01:02,636 [salt.minion      :1432][INFO    ][5062] Starting a new job with PID 5062
2019-11-20 13:01:03,402 [salt.state       :915 ][INFO    ][5062] Loading fresh modules for state activity
2019-11-20 13:01:03,495 [salt.state       :1780][INFO    ][5062] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:01:03.495116
2019-11-20 13:01:03,495 [salt.state       :1813][INFO    ][5062] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-11-20 13:01:03,498 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5062] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-11-20 13:01:04,930 [salt.state       :300 ][INFO    ][5062] {'pid': 5069, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-11-20 13:01:04,931 [salt.state       :1951][INFO    ][5062] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 13:01:04.931124 duration_in_ms=1436.007
2019-11-20 13:01:04,934 [salt.state       :1780][INFO    ][5062] Running state [maas.wait_for_machine_status] at time 13:01:04.934536
2019-11-20 13:01:04,935 [salt.state       :1813][INFO    ][5062] Executing state module.run for [maas.wait_for_machine_status]
2019-11-20 13:01:04,936 [salt.utils.decorators:613 ][WARNING ][5062] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-11-20 13:01:08,620 [salt.state       :300 ][INFO    ][5062] {'ret': True}
2019-11-20 13:01:08,620 [salt.state       :1951][INFO    ][5062] Completed state [maas.wait_for_machine_status] at time 13:01:08.620667 duration_in_ms=3686.13
2019-11-20 13:01:08,624 [salt.minion      :1711][INFO    ][5062] Returning information for job: 20191120130102600354
2019-11-20 13:29:57,764 [salt.utils.schedule:1377][INFO    ][28576] Running scheduled job: __mine_interval
2019-11-20 14:26:45,973 [salt.minion      :1308][INFO    ][28576] User sudo_ubuntu Executing command cp.push_dir with jid 20191120142645960709
2019-11-20 14:26:45,998 [salt.minion      :1432][INFO    ][11130] Starting a new job with PID 11130
