2023-09-08 16:00:52,014 INFO subiquity:199 Starting Subiquity server revision 1229 of snap /snap/ubuntu-desktop-installer/1229 2023-09-08 16:00:52,014 INFO subiquity:200 Arguments passed: ['/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/1229/etc/subiquity/postinst.d'] 2023-09-08 16:00:52,014 DEBUG subiquity:201 Kernel commandline: CommandLineParams(_raw='BOOT_IMAGE=/casper/vmlinuz nomodeset layerfs-path=standard.live.squashfs --- quiet splash\n', _tokens={'splash', 'quiet', '---', 'nomodeset'}, _values={'BOOT_IMAGE': '/casper/vmlinuz', 'layerfs-path': 'standard.live.squashfs'}) 2023-09-08 16:00:52,015 DEBUG subiquity:202 Environment: environ({'SNAP_REVISION': '1229', 'SNAP_REAL_HOME': '/root', 'SNAP_USER_COMMON': '/root/snap/ubuntu-desktop-installer/common', 'PATH_ORIG': '/snap/ubuntu-desktop-installer/1229/usr/sbin:/snap/ubuntu-desktop-installer/1229/usr/bin:/snap/ubuntu-desktop-installer/1229/sbin:/snap/ubuntu-desktop-installer/1229/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', 'SNAP_INSTANCE_KEY': '', 'SNAP_EUID': '0', 'PWD': '/snap/ubuntu-desktop-installer/1229/bin/subiquity', 'SYSTEMD_EXEC_PID': '3206', 'SNAP_CONTEXT': 'VuiwqsJidM2XJ2ZRNQgBDXeWGTzWyLvWnpDHAE6IzkiLVnhz9acq', 'LANG': 'C.UTF-8', 'SNAP_ARCH': 'amd64', 'PY3OR2_PYTHON': '/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', 'SNAP_INSTANCE_NAME': 'ubuntu-desktop-installer', 'SNAP_USER_DATA': '/root/snap/ubuntu-desktop-installer/1229', 'INVOCATION_ID': '0845ddb6ec8b486fa47593bee1925e3a', 'SNAP_REEXEC': '', 'SNAP_UID': '0', 'LD_LIBRARY_PATH_ORIG': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/ubuntu-desktop-installer/1229/lib:/snap/ubuntu-desktop-installer/1229/usr/lib:/snap/ubuntu-desktop-installer/1229/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1229/usr/lib/x86_64-linux-gnu', 'PYTHONPATH_ORIG': '', 'PYTHONPATH': '/snap/ubuntu-desktop-installer/1229/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1229/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1229/usr/lib/python3/site-packages:', 'PYTHON': '/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', 'PYTHONIOENCODING': 'utf-8', 'SNAP': '/snap/ubuntu-desktop-installer/1229', 'SNAP_COMMON': '/var/snap/ubuntu-desktop-installer/common', 'SNAP_VERSION': '0+git.09349bf4', 'DISPLAY': ':0', 'SHLVL': '1', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'SNAP_COOKIE': 'VuiwqsJidM2XJ2ZRNQgBDXeWGTzWyLvWnpDHAE6IzkiLVnhz9acq', 'SNAP_DATA': '/var/snap/ubuntu-desktop-installer/1229', 'LD_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/ubuntu-desktop-installer/1229/lib:/snap/ubuntu-desktop-installer/1229/usr/lib:/snap/ubuntu-desktop-installer/1229/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1229/usr/lib/x86_64-linux-gnu', 'SNAP_NAME': 'ubuntu-desktop-installer', 'JOURNAL_STREAM': '8:29178', 'PATH': '/snap/ubuntu-desktop-installer/1229/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1229/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1229/bin:/snap/ubuntu-desktop-installer/1229/sbin:/snap/ubuntu-desktop-installer/1229/usr/sbin:/snap/ubuntu-desktop-installer/1229/usr/bin:/snap/ubuntu-desktop-installer/1229/sbin:/snap/ubuntu-desktop-installer/1229/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', 'SUBIQUITY_ROOT': '/snap/ubuntu-desktop-installer/1229/bin/subiquity', 'OLDPWD': '/var/snap/ubuntu-desktop-installer/1229', '_': '/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', 'APPORT_DATA_DIR': '/snap/ubuntu-desktop-installer/1229/bin/subiquity/share/apport'}) 2023-09-08 16:00:52,015 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-08 16:00:52,017 DEBUG subiquitycore.prober:33 Prober() init finished, data:None 2023-09-08 16:00:52,109 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True) 2023-09-08 16:00:52,148 DEBUG subiquitycore.utils:118 arun_command called: ['cloud-init', 'status', '--wait'] 2023-09-08 16:00:52,797 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-08 16:00:52,798 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-08 16:00:52,799 INFO aiohttp.access:206 [08/Sep/2023:16:00:52 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:53,803 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-08 16:00:53,803 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-08 16:00:53,803 INFO aiohttp.access:206 [08/Sep/2023:16:00:53 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:54,689 DEBUG subiquitycore.utils:132 arun_command ['cloud-init', 'status', '--wait'] exited with code 0 2023-09-08 16:00:54,689 DEBUG subiquity.server.server:567 waited 2.541456699371338s for cloud-init 2023-09-08 16:00:54,690 DEBUG subiquity.server.server:571 cloud-init status: '\nstatus: disabled\n', assumed disabled 2023-09-08 16:00:54,691 DEBUG subiquity.server.server:468 load_autoinstall_config only_early True file None 2023-09-08 16:00:54,691 DEBUG subiquity.server.server:468 load_autoinstall_config only_early False file None 2023-09-08 16:00:54,692 DEBUG subiquitycore.core:118 starting controllers 2023-09-08 16:00:54,693 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic-hwe-22.04 due to /run/kernel-meta-package 2023-09-08 16:00:54,701 DEBUG subiquity.models.source:93 loaded 1 sources from '/cdrom/casper/install-sources.yaml' 2023-09-08 16:00:54,703 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-09-08 16:00:54,704 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp2s0'} 2023-09-08 16:00:54,704 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp3s0'} 2023-09-08 16:00:54,704 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'} 2023-09-08 16:00:54,704 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-09-08 16:00:54,704 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-09-08 16:00:54,921 DEBUG subiquitycore.models.network:455 new_link 1 lo lo 2023-09-08 16:00:54,921 DEBUG subiquitycore.models.network:457 ignoring based on type 2023-09-08 16:00:54,921 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp2s0'} 2023-09-08 16:00:55,047 DEBUG subiquitycore.models.network:455 new_link 2 enp2s0 eth 2023-09-08 16:00:55,048 DEBUG subiquitycore.models.network:486 new_link 2 enp2s0 with config {} 2023-09-08 16:00:55,048 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp2s0 2023-09-08 16:00:55,048 DEBUG subiquity.server.controllers.network:319 dev_info enp2s0 {} 2023-09-08 16:00:55,048 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp2s0 2023-09-08 16:00:55,048 DEBUG probert.network:672 link_change NEW {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp3s0'} 2023-09-08 16:00:55,174 DEBUG subiquitycore.models.network:455 new_link 3 wlp3s0 wlan 2023-09-08 16:00:55,174 DEBUG subiquitycore.models.network:486 new_link 3 wlp3s0 with config {} 2023-09-08 16:00:55,175 DEBUG subiquity.server.controllers.network:100 maybe_start_install_wpasupplicant 2023-09-08 16:00:55,175 DEBUG root:30 start: subiquity/Network/_send_update: NEW wlp3s0 2023-09-08 16:00:55,176 DEBUG subiquity.server.controllers.network:319 dev_info wlp3s0 {} 2023-09-08 16:00:55,177 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW wlp3s0 2023-09-08 16:00:55,177 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'} 2023-09-08 16:00:55,177 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-09-08 16:00:55,178 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1} 2023-09-08 16:00:55,178 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1} 2023-09-08 16:00:55,178 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1} 2023-09-08 16:00:55,178 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1} 2023-09-08 16:00:55,178 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1} 2023-09-08 16:00:55,178 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_INTERFACE', 'ifindex': -1} 2023-09-08 16:00:55,178 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_INTERFACE', 'ifindex': 3, 'ssids': []} 2023-09-08 16:00:55,202 DEBUG subiquitycore.core:121 controllers started 2023-09-08 16:00:55,202 INFO root:30 start: subiquity/apply_autoinstall_config: 2023-09-08 16:00:55,203 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 2023-09-08 16:00:55,204 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,205 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 2023-09-08 16:00:55,205 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,206 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 2023-09-08 16:00:55,206 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,206 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 2023-09-08 16:00:55,207 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,207 DEBUG subiquity.models.subiquity:252 model userdata for postinstall stage is configured, to go {'drivers', 'locale', 'ubuntu_pro', 'identity', 'packages', 'snaplist', 'ssh'} 2023-09-08 16:00:55,208 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 2023-09-08 16:00:55,208 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,209 DEBUG subiquity.models.subiquity:252 model packages for postinstall stage is configured, to go {'drivers', 'locale', 'ubuntu_pro', 'identity', 'snaplist', 'ssh'} 2023-09-08 16:00:55,209 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 2023-09-08 16:00:55,210 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,210 DEBUG subiquity.models.subiquity:252 model debconf_selections for install stage is configured, to go {'proxy', 'kernel', 'keyboard', 'source', 'filesystem'} 2023-09-08 16:00:55,210 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Locale as interactive 2023-09-08 16:00:55,210 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Refresh as interactive 2023-09-08 16:00:55,210 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 2023-09-08 16:00:55,211 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,211 DEBUG subiquity.models.subiquity:252 model kernel for install stage is configured, to go {'keyboard', 'proxy', 'source', 'filesystem'} 2023-09-08 16:00:55,212 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Integrity as interactive 2023-09-08 16:00:55,212 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Keyboard as interactive 2023-09-08 16:00:55,212 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 2023-09-08 16:00:55,212 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,213 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Source as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Network as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping UbuntuPro as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Proxy as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Mirror as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Filesystem as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Identity as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping SSH as interactive 2023-09-08 16:00:55,214 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping SnapList as interactive 2023-09-08 16:00:55,214 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 2023-09-08 16:00:55,215 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,215 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Codecs as interactive 2023-09-08 16:00:55,215 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Drivers as interactive 2023-09-08 16:00:55,215 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping OEM as interactive 2023-09-08 16:00:55,216 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping TimeZone as interactive 2023-09-08 16:00:55,216 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Install as interactive 2023-09-08 16:00:55,216 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Updates as interactive 2023-09-08 16:00:55,216 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 2023-09-08 16:00:55,216 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,216 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Shutdown as interactive 2023-09-08 16:00:55,217 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 2023-09-08 16:00:55,217 DEBUG subiquity.models.subiquity:252 model locale for postinstall stage is configured, to go {'drivers', 'ubuntu_pro', 'identity', 'snaplist', 'ssh'} 2023-09-08 16:00:55,217 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 2023-09-08 16:00:55,217 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 2023-09-08 16:00:55,218 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-09-08 16:00:55,225 DEBUG subiquitycore.utils:118 arun_command called: ['/usr/sbin/realm', 'discover'] 2023-09-08 16:00:55,240 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1560 2023-09-08 16:00:55,241 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 2023-09-08 16:00:55,242 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 2023-09-08 16:00:55,242 DEBUG root:30 start: subiquity/Install/install: 2023-09-08 16:00:55,243 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:00:55,269 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:00:55,269 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-09-08 16:00:55,269 DEBUG subiquity.server.pkghelper:66 checking if wpasupplicant is available 2023-09-08 16:00:58,239 DEBUG subiquity.server.pkghelper:72 wpasupplicant already installed 2023-09-08 16:00:58,240 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-09-08 16:00:58,241 DEBUG subiquity.server.controllers.network:120 wlan_support_install_finished PackageInstallState.DONE 2023-09-08 16:00:58,242 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-09-08 16:00:58,244 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.09349bf4' 2023-09-08 16:00:58,246 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-08 16:00:58,247 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info 2023-09-08 16:00:58,247 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 2023-09-08 16:00:58,248 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-08 16:00:58,249 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-08 16:00:58,249 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,260 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-08 16:00:58,260 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-08 16:00:58,261 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,262 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-08 16:00:58,262 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-08 16:00:58,263 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,263 INFO root:30 start: subiquity/Meta/client_variant_POST: 2023-09-08 16:00:58,265 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null 2023-09-08 16:00:58,267 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "POST /meta/client_variant?variant=%22desktop%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,267 DEBUG subiquitycore.utils:132 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1 2023-09-08 16:00:58,269 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-08 16:00:58,271 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 2023-09-08 16:00:58,271 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null 2023-09-08 16:00:58,272 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /meta/interactive_sections HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,273 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-08 16:00:58,274 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-08 16:00:58,274 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,284 DEBUG root:30 start: subiquity/Locale/GET: 2023-09-08 16:00:58,285 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8" 2023-09-08 16:00:58,285 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /locale HTTP/1.1" 200 195 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,287 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-09-08 16:00:58,288 DEBUG subiquity.models.subiquity:252 model ubuntu_pro for postinstall stage is configured, to go {'codecs', 'ssh', 'drivers', 'identity', 'timezone', 'snaplist', 'network'} 2023-09-08 16:00:58,288 DEBUG subiquity.models.subiquity:252 model proxy for install stage is configured, to go {'keyboard', 'mirror', 'source', 'filesystem', 'network'} 2023-09-08 16:00:58,288 DEBUG subiquity.models.subiquity:252 model mirror for install stage is configured, to go {'keyboard', 'filesystem', 'network', 'source'} 2023-09-08 16:00:58,289 DEBUG subiquity.models.subiquity:252 model ssh for postinstall stage is configured, to go {'codecs', 'drivers', 'identity', 'timezone', 'snaplist', 'network'} 2023-09-08 16:00:58,289 DEBUG subiquity.models.subiquity:252 model snaplist for postinstall stage is configured, to go {'codecs', 'drivers', 'identity', 'timezone', 'network'} 2023-09-08 16:00:58,289 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-09-08 16:00:58,290 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "POST /meta/mark_configured?endpoint_names=%5B%22mirror%22%2C%22proxy%22%2C%22ssh%22%2C%22snaplist%22%2C%22ubuntu_pro%22%5D HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:00:58,311 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-09-08 16:00:58,313 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-09-08 16:00:58,313 DEBUG probert.dasd:134 Probing DASD devies 2023-09-08 16:00:58,314 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-09-08 16:00:58,472 DEBUG root:30 start: subiquity/Refresh/GET: 2023-09-08 16:01:00,040 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:00,064 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:00,064 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'TP-Link_A076', 'no status'), (b'TP-Link_Guest_A076', 'no status'), (b'DIRECT-6F-HP OfficeJet Pro 8720', 'no status'), (b'TP-Link_0D84', 'no status'), (b'javelin7', 'no status'), (b'Frontier9824', 'no status'), (b'javelin7_5G', 'no status'), (b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', 'no status'), (b'Bandits', 'no status'), (b'TP-Link_2E0C', 'no status'), (b'Willow2Guest', 'no status'), (b'', 'no status'), (b'TP-Link_2E0C', 'no status'), (b'', 'no status'), (b'TP-Link_0D84_5G_2', 'no status')]} 2023-09-08 16:01:00,065 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:00,077 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:00,077 DEBUG probert.network:585 event for link_change: CHANGE {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp3s0'} 2023-09-08 16:01:00,077 DEBUG probert.network:672 link_change CHANGE {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp3s0'} 2023-09-08 16:01:00,078 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE wlp3s0 2023-09-08 16:01:00,078 DEBUG subiquity.server.controllers.network:319 dev_info wlp3s0 {} 2023-09-08 16:01:00,078 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE wlp3s0 2023-09-08 16:01:02,756 DEBUG probert.utils:85 Command `/snap/ubuntu-desktop-installer/1229/sbin/ntfsresize --no-action --force --no-progress-bar --info /dev/sda1` exited with result: 0 2023-09-08 16:01:03,262 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:03,262 DEBUG probert.utils:50 ntfsresize v2021.8.22 (libntfs-3g) 2023-09-08 16:01:03,262 DEBUG probert.utils:50 Device name : /dev/sda1 2023-09-08 16:01:03,262 DEBUG probert.utils:50 NTFS volume version: 3.1 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Cluster size : 4096 bytes 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Current volume size: 1048572416 bytes (1049 MB) 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Current device size: 1048576000 bytes (1049 MB) 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Checking filesystem consistency ... 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Accounting clusters ... 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Space in use : 303 MB (28.9%) 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Collecting resizing constraints ... 2023-09-08 16:01:03,263 DEBUG probert.utils:50 You might resize at 302624768 bytes or 303 MB (freeing 746 MB). 2023-09-08 16:01:03,263 DEBUG probert.utils:50 Please make a test run using both the -n and -s options before real resizing! 2023-09-08 16:01:03,263 DEBUG probert.utils:52 2023-09-08 16:01:03,263 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:03,265 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda9` exited with result: 0 2023-09-08 16:01:03,265 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem volume name: 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Last mounted on: / 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem UUID: e52867c5-0b50-42fb-8288-f30765f926c5 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem features: has_journal ext_attr resize_inode dir_index filetype extent flex_bg sparse_super large_file huge_file uninit_bg dir_nlink extra_isize 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem state: clean 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Errors behavior: Continue 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-09-08 16:01:03,265 DEBUG probert.utils:50 Inode count: 27860992 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Block count: 111435008 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Reserved block count: 5571750 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Free blocks: 92316480 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Free inodes: 27487589 2023-09-08 16:01:03,266 DEBUG probert.utils:50 First block: 0 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Block size: 4096 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Fragment size: 4096 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Reserved GDT blocks: 997 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Blocks per group: 32768 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Fragments per group: 32768 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Inodes per group: 8192 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Inode blocks per group: 512 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Flex block group size: 16 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Filesystem created: Wed Mar 25 09:07:00 2015 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Last mount time: Tue Oct 4 17:30:32 2022 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Last write time: Tue Oct 4 17:30:18 2022 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Mount count: 1232 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Maximum mount count: -1 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Last checked: Fri May 8 03:58:06 2015 2023-09-08 16:01:03,266 DEBUG probert.utils:50 Check interval: 0 () 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Lifetime writes: 694 GB 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-09-08 16:01:03,267 DEBUG probert.utils:50 First inode: 11 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Inode size: 256 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Required extra isize: 28 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Desired extra isize: 28 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Journal inode: 8 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Default directory hash: half_md4 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Directory Hash Seed: f0740d75-0157-487f-bd9a-ccd989c5cad2 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Journal backup: inode blocks 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Journal features: journal_incompat_revoke 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Total journal size: 128M 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Total journal blocks: 32768 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Max transaction length: 32768 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Fast commit length: 0 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Journal sequence: 0x00168070 2023-09-08 16:01:03,267 DEBUG probert.utils:50 Journal start: 0 2023-09-08 16:01:03,268 DEBUG probert.utils:50 2023-09-08 16:01:03,268 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-09-08 16:01:03,268 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-09-08 16:01:03,268 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:05,214 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:05,216 DEBUG probert.utils:85 Command `/snap/ubuntu-desktop-installer/1229/sbin/ntfsresize --no-action --force --no-progress-bar --info /dev/sda7` exited with result: 0 2023-09-08 16:01:05,216 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:05,216 DEBUG probert.utils:50 ntfsresize v2021.8.22 (libntfs-3g) 2023-09-08 16:01:05,216 DEBUG probert.utils:50 Device name : /dev/sda7 2023-09-08 16:01:05,216 DEBUG probert.utils:50 NTFS volume version: 3.1 2023-09-08 16:01:05,216 DEBUG probert.utils:50 Cluster size : 4096 bytes 2023-09-08 16:01:05,216 DEBUG probert.utils:50 Current volume size: 15831396864 bytes (15832 MB) 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Current device size: 15831400448 bytes (15832 MB) 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Checking filesystem consistency ... 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Accounting clusters ... 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Space in use : 14038 MB (88.7%) 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Collecting resizing constraints ... 2023-09-08 16:01:05,217 DEBUG probert.utils:50 You might resize at 14037442560 bytes or 14038 MB (freeing 1794 MB). 2023-09-08 16:01:05,217 DEBUG probert.utils:50 Please make a test run using both the -n and -s options before real resizing! 2023-09-08 16:01:05,217 DEBUG probert.utils:52 2023-09-08 16:01:05,217 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:05,219 DEBUG probert.utils:85 Command `/snap/ubuntu-desktop-installer/1229/sbin/ntfsresize --no-action --force --no-progress-bar --info /dev/sda6` exited with result: 0 2023-09-08 16:01:05,219 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:05,219 DEBUG probert.utils:50 ntfsresize v2021.8.22 (libntfs-3g) 2023-09-08 16:01:05,219 DEBUG probert.utils:50 Device name : /dev/sda6 2023-09-08 16:01:05,219 DEBUG probert.utils:50 NTFS volume version: 3.1 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Cluster size : 4096 bytes 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Current volume size: 26843542016 bytes (26844 MB) 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Current device size: 26843545600 bytes (26844 MB) 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Checking filesystem consistency ... 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Accounting clusters ... 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Space in use : 7804 MB (29.1%) 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Collecting resizing constraints ... 2023-09-08 16:01:05,220 DEBUG probert.utils:50 You might resize at 7803494400 bytes or 7804 MB (freeing 19040 MB). 2023-09-08 16:01:05,220 DEBUG probert.utils:50 Please make a test run using both the -n and -s options before real resizing! 2023-09-08 16:01:05,220 DEBUG probert.utils:52 2023-09-08 16:01:05,220 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:05,221 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sdb4` exited with result: 0 2023-09-08 16:01:05,221 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:05,221 DEBUG probert.utils:50 Filesystem volume name: writable 2023-09-08 16:01:05,221 DEBUG probert.utils:50 Last mounted on: /root/var/crash 2023-09-08 16:01:05,221 DEBUG probert.utils:50 Filesystem UUID: 8eb9369c-ab9c-4a9b-b061-864ea563c13e 2023-09-08 16:01:05,221 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Filesystem features: has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Filesystem state: clean 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Errors behavior: Continue 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Inode count: 1695744 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Block count: 6781696 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Reserved block count: 339084 2023-09-08 16:01:05,222 DEBUG probert.utils:50 Overhead clusters: 150485 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Free blocks: 6631205 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Free inodes: 1695733 2023-09-08 16:01:05,223 DEBUG probert.utils:50 First block: 0 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Block size: 4096 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Fragment size: 4096 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Group descriptor size: 64 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Blocks per group: 32768 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Fragments per group: 32768 2023-09-08 16:01:05,223 DEBUG probert.utils:50 Inodes per group: 8192 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Inode blocks per group: 512 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Flex block group size: 16 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Filesystem created: Fri Sep 8 15:57:54 2023 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Last mount time: Fri Sep 8 15:59:01 2023 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Last write time: Fri Sep 8 15:59:01 2023 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Mount count: 1 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Maximum mount count: -1 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Last checked: Fri Sep 8 15:57:54 2023 2023-09-08 16:01:05,224 DEBUG probert.utils:50 Check interval: 0 () 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Lifetime writes: 4174 kB 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-09-08 16:01:05,225 DEBUG probert.utils:50 First inode: 11 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Inode size: 256 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Required extra isize: 32 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Desired extra isize: 32 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Journal inode: 8 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Default directory hash: half_md4 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Directory Hash Seed: 11f84ecc-fc6e-4821-86d3-73f090efb800 2023-09-08 16:01:05,225 DEBUG probert.utils:50 Journal backup: inode blocks 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Checksum type: crc32c 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Checksum: 0x234776da 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Journal features: journal_64bit journal_checksum_v3 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Total journal size: 128M 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Total journal blocks: 32768 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Max transaction length: 32768 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Fast commit length: 0 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Journal sequence: 0x00000002 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Journal start: 1 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-09-08 16:01:05,226 DEBUG probert.utils:50 Journal checksum: 0x3313e17b 2023-09-08 16:01:05,226 DEBUG probert.utils:50 2023-09-08 16:01:05,227 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-09-08 16:01:05,227 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-09-08 16:01:05,227 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:05,240 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:05,240 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-09-08 16:01:06,816 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sdb4` exited with result: 0 2023-09-08 16:01:06,816 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:06,816 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 48974 2023-09-08 16:01:06,817 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-09-08 16:01:06,817 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-09-08 16:01:06,817 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:08,624 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda9` exited with result: 0 2023-09-08 16:01:08,882 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-09-08 16:01:08,883 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 18122190 2023-09-08 16:01:08,883 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-09-08 16:01:08,883 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-09-08 16:01:08,883 DEBUG probert.utils:88 -------------------------------------------------- 2023-09-08 16:01:09,956 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:09,966 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:09,966 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'TP-Link_A076', 'no status'), (b'TP-Link_Guest_A076', 'no status'), (b'TP-Link_0D84', 'no status'), (b'javelin7', 'no status'), (b'Frontier9824', 'no status'), (b'javelin7_5G', 'no status'), (b'Willow2Guest', 'no status'), (b'', 'no status'), (b'TP-Link_2E0C', 'no status'), (b'', 'no status'), (b'TP-Link_0D84_5G_2', 'no status'), (b'Frontier3072', 'no status'), (b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', 'no status')]} 2023-09-08 16:01:09,967 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:09,988 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:32,758 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 500 261 2023-09-08 16:01:35,037 ERROR subiquity.server.controllers.refresh:197 checking for snap update failed Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/refresh.py", line 195, in check_for_update result = await self.app.snapdapi.v2.find.GET(select="refresh") File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/common/api/client.py", line 47, in impl async with make_request( File "/snap/ubuntu-desktop-installer/1229/usr/lib/python3.10/contextlib.py", line 199, in __aenter__ return await anext(self.gen) File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/snapdapi.py", line 298, in make_request content = await async_snapd.get(path[1:], **params) File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquitycore/snapd.py", line 198, in get response.raise_for_status() File "/snap/ubuntu-desktop-installer/1229/usr/lib/python3/dist-packages/requests/models.py", line 943, in raise_for_status raise HTTPError(http_error_msg, response=self) requests.exceptions.HTTPError: 500 Server Error: Internal Server Error for url: http+unix://%2Frun%2Fsnapd.socket/v2/find?select=refresh 2023-09-08 16:01:35,039 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: checking for snap update failed 2023-09-08 16:01:35,039 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNKNOWN", "current_snap_version": "0+git.09349bf4", "new_sn... 2023-09-08 16:01:35,040 INFO aiohttp.access:206 [08/Sep/2023:16:00:58 +0000] "GET /refresh?wait=true HTTP/1.1" 200 280 "-" "Dart/3.0 (dart:io)" 2023-09-08 16:01:47,109 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:49,744 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:49,744 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-09-08 16:01:51,960 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:51,970 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:01:51,971 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'TP-Link_A076', 'no status'), (b'TP-Link_Guest_A076', 'no status'), (b'TP-Link_0D84', 'no status'), (b'javelin7', 'no status'), (b'Frontier9824', 'no status'), (b'javelin7_5G', 'no status'), (b'TP-Link_0D84_5G_2', 'no status'), (b'Wurznet', 'no status'), (b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', 'no status'), (b'DIRECT-6F-HP OfficeJet Pro 8720', 'no status'), (b'NTGR_VMB_1496690716', 'no status'), (b'', 'no status'), (b'', 'no status')]} 2023-09-08 16:01:51,971 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-08 16:01:51,996 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-08 16:02:28,251 ERROR root:30 finish: subiquity/Filesystem/_probe/probe_once: FAIL: cancelled 2023-09-08 16:02:28,252 ERROR block-discover:1227 block probing failed restricted=False Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquitycore/context.py", line 149, in decorated_async return await meth(self, **kw) File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/filesystem.py", line 1189, in _probe_once storage = await self.app.prober.get_storage(probe_types) File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquitycore/prober.py", line 66, in get_storage return await run_in_thread(run_probert, probe_types) File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquitycore/async_helpers.py", line 59, in run_in_thread return await loop.run_in_executor(None, func, *args) asyncio.exceptions.CancelledError During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1229/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for return fut.result() asyncio.exceptions.CancelledError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/filesystem.py", line 1221, in _probe await asyncio.wait_for(self._probe_once_task.task, 90.0) File "/snap/ubuntu-desktop-installer/1229/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for raise exceptions.TimeoutError() from exc asyncio.exceptions.TimeoutError 2023-09-08 16:02:28,257 DEBUG subiquity.common.errorreport:394 generating crash report 2023-09-08 16:02:28,259 INFO subiquity.common.errorreport:415 saving crash report 'block probing crashed with TimeoutError' to /var/crash/1694188948.257439375.block_probe_fail.crash 2023-09-08 16:02:28,260 DEBUG subiquity.server.controllers.filesystem:1236 block probing took 90.0 seconds 2023-09-08 16:02:28,261 INFO root:30 start: subiquity/ErrorReporter/1694188948.257439375.block_probe_fail/add_info: 2023-09-08 16:02:28,262 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=True 2023-09-08 16:02:28,264 DEBUG asyncio:54 Using selector: EpollSelector