2023-09-08 15:55:36,365 INFO subiquity:199 Starting Subiquity server revision 1229 of snap /snap/ubuntu-desktop-installer/1229
2023-09-08 15:55:36,365 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 15:55:36,365 DEBUG subiquity:201 Kernel commandline: CommandLineParams(_raw='BOOT_IMAGE=/casper/vmlinuz layerfs-path=standard.live.squashfs --- quiet splash\n', _tokens={'---', 'splash', 'quiet'}, _values={'BOOT_IMAGE': '/casper/vmlinuz', 'layerfs-path': 'standard.live.squashfs'})
2023-09-08 15:55:36,365 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': '2926', 'SNAP_CONTEXT': 'UDiC8q8jOJe-iiMBo6JMjtsOT3y1A9zy7xf7ZvL7_CL3ZCs9vrh4', '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': '010887c6dd3b424b9a83507c4215809a', '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': 'UDiC8q8jOJe-iiMBo6JMjtsOT3y1A9zy7xf7ZvL7_CL3ZCs9vrh4', '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:24086', '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 15:55:36,365 DEBUG asyncio:54 Using selector: EpollSelector
2023-09-08 15:55:36,366 DEBUG subiquitycore.prober:33 Prober() init finished, data:None
2023-09-08 15:55:36,417 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
2023-09-08 15:55:36,443 DEBUG subiquitycore.utils:118 arun_command called: ['cloud-init', 'status', '--wait']
2023-09-08 15:55:36,848 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:36,848 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 15:55:36,849 INFO aiohttp.access:206  [08/Sep/2023:15:55:36 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:37,852 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:37,853 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 15:55:37,854 INFO aiohttp.access:206  [08/Sep/2023:15:55:37 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,134 DEBUG subiquitycore.utils:132 arun_command ['cloud-init', 'status', '--wait'] exited with code 0
2023-09-08 15:55:38,135 DEBUG subiquity.server.server:567 waited 1.6919021606445312s for cloud-init
2023-09-08 15:55:38,135 DEBUG subiquity.server.server:571 cloud-init status: '\nstatus: disabled\n', assumed disabled
2023-09-08 15:55:38,135 DEBUG subiquity.server.server:468 load_autoinstall_config only_early True file None
2023-09-08 15:55:38,135 DEBUG subiquity.server.server:468 load_autoinstall_config only_early False file None
2023-09-08 15:55:38,136 DEBUG subiquitycore.core:118 starting controllers
2023-09-08 15:55:38,136 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic-hwe-22.04 due to /run/kernel-meta-package
2023-09-08 15:55:38,141 DEBUG subiquity.models.source:93 loaded 1 sources from '/cdrom/casper/install-sources.yaml'
2023-09-08 15:55:38,142 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 15:55:38,142 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2023-09-08 15:55:38,142 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 15:55:38,142 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.122.12/24'}
2023-09-08 15:55:38,142 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-09-08 15:55:38,142 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 640, 'family': 10, 'scope': 253, 'local': b'fe80::9a8a:3152:af37:71f9/64'}
2023-09-08 15:55:38,142 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2023-09-08 15:55:38,200 DEBUG subiquitycore.models.network:455 new_link 1 lo lo
2023-09-08 15:55:38,200 DEBUG subiquitycore.models.network:457 ignoring based on type
2023-09-08 15:55:38,200 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2023-09-08 15:55:38,290 DEBUG subiquitycore.models.network:455 new_link 2 enp1s0 eth
2023-09-08 15:55:38,290 DEBUG subiquitycore.models.network:486 new_link 2 enp1s0 with config {}
2023-09-08 15:55:38,290 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp1s0
2023-09-08 15:55:38,290 DEBUG subiquity.server.controllers.network:319 dev_info enp1s0 {}
2023-09-08 15:55:38,291 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp1s0
2023-09-08 15:55:38,291 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 15:55:38,291 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.122.12/24'}
2023-09-08 15:55:38,291 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2023-09-08 15:55:38,291 DEBUG subiquity.server.controllers.network:319 dev_info enp1s0 {}
2023-09-08 15:55:38,291 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2023-09-08 15:55:38,291 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-09-08 15:55:38,291 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 640, 'family': 10, 'scope': 253, 'local': b'fe80::9a8a:3152:af37:71f9/64'}
2023-09-08 15:55:38,292 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2023-09-08 15:55:38,292 DEBUG subiquity.server.controllers.network:319 dev_info enp1s0 {}
2023-09-08 15:55:38,292 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2023-09-08 15:55:38,292 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2}
2023-09-08 15:55:38,368 DEBUG pyroute2.ndb.140189777449008.sources.localhost:74 init
2023-09-08 15:55:38,369 DEBUG pyroute2.ndb.140189777449008.sources.localhost:384 starting the source
2023-09-08 15:55:38,370 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:74 init
2023-09-08 15:55:38,370 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:384 starting the source
2023-09-08 15:55:38,370 DEBUG pyroute2.ndb.140189777449008.sources.localhost:74 connecting
2023-09-08 15:55:38,371 DEBUG pyroute2.ndb.140189777449008.sources.localhost:74 loading
2023-09-08 15:55:38,371 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:74 connecting
2023-09-08 15:55:38,384 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:74 loading
2023-09-08 15:55:38,388 DEBUG pyroute2.ndb.140189777449008.sources.localhost:74 running
2023-09-08 15:55:38,390 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:74 running
2023-09-08 15:55:38,396 DEBUG pyroute2.ndb.140189777449008.sources.localhost:399 source shutdown
2023-09-08 15:55:38,404 DEBUG pyroute2.ndb.140189777449008.sources.localhost:374 sync
2023-09-08 15:55:38,404 DEBUG pyroute2.ndb.140189777449008.sources.localhost:369 shutdown handled by the main thread
2023-09-08 15:55:38,404 DEBUG pyroute2.ndb.140189777449008.sources.localhost:74 stopped
2023-09-08 15:55:38,404 DEBUG pyroute2.ndb.140189777449008.main:851 flush DB for the target localhost
2023-09-08 15:55:38,405 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:399 source shutdown
2023-09-08 15:55:38,405 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:374 sync
2023-09-08 15:55:38,405 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:369 shutdown handled by the main thread
2023-09-08 15:55:38,405 DEBUG pyroute2.ndb.140189777449008.sources.localhost/nsmanager:74 stopped
2023-09-08 15:55:38,411 DEBUG pyroute2.ndb.140189777449008.main:851 flush DB for the target localhost/nsmanager
2023-09-08 15:55:38,412 DEBUG subiquitycore.controllers.network:102 default routes True
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'169.254.0.0/16', 'ifindex': 2}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.122.0/24', 'ifindex': 2}
2023-09-08 15:55:38,412 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 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.122.12', 'ifindex': 2}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.122.255', 'ifindex': 2}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1}
2023-09-08 15:55:38,412 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2}
2023-09-08 15:55:38,413 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1}
2023-09-08 15:55:38,413 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::9a8a:3152:af37:71f9', 'ifindex': 2}
2023-09-08 15:55:38,413 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 5, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2}
2023-09-08 15:55:38,544 DEBUG subiquitycore.core:121 controllers started
2023-09-08 15:55:38,544 INFO root:30 start: subiquity/apply_autoinstall_config: 
2023-09-08 15:55:38,544 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 
2023-09-08 15:55:38,545 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,545 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 
2023-09-08 15:55:38,545 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,546 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 
2023-09-08 15:55:38,546 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,546 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 
2023-09-08 15:55:38,546 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,546 DEBUG subiquity.models.subiquity:252 model userdata for postinstall stage is configured, to go {'drivers', 'ubuntu_pro', 'ssh', 'locale', 'identity', 'snaplist', 'packages'}
2023-09-08 15:55:38,546 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 
2023-09-08 15:55:38,546 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,546 DEBUG subiquity.models.subiquity:252 model packages for postinstall stage is configured, to go {'drivers', 'ubuntu_pro', 'ssh', 'locale', 'snaplist', 'identity'}
2023-09-08 15:55:38,546 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 
2023-09-08 15:55:38,547 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,547 DEBUG subiquity.models.subiquity:252 model debconf_selections for install stage is configured, to go {'source', 'proxy', 'filesystem', 'keyboard', 'kernel'}
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Locale as interactive
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Refresh as interactive
2023-09-08 15:55:38,547 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 
2023-09-08 15:55:38,547 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,547 DEBUG subiquity.models.subiquity:252 model kernel for install stage is configured, to go {'source', 'proxy', 'filesystem', 'keyboard'}
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Integrity as interactive
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Keyboard as interactive
2023-09-08 15:55:38,547 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 
2023-09-08 15:55:38,547 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Source as interactive
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Network as interactive
2023-09-08 15:55:38,547 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping UbuntuPro as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Proxy as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Mirror as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Filesystem as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Identity as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping SSH as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping SnapList as interactive
2023-09-08 15:55:38,548 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 
2023-09-08 15:55:38,548 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Codecs as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Drivers as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping OEM as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping TimeZone as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Install as interactive
2023-09-08 15:55:38,548 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Updates as interactive
2023-09-08 15:55:38,548 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 
2023-09-08 15:55:38,549 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,549 DEBUG subiquity.server.server:459 apply_autoinstall_config: skipping Shutdown as interactive
2023-09-08 15:55:38,549 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 
2023-09-08 15:55:38,549 DEBUG subiquity.models.subiquity:252 model locale for postinstall stage is configured, to go {'drivers', 'ubuntu_pro', 'ssh', 'snaplist', 'identity'}
2023-09-08 15:55:38,550 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 
2023-09-08 15:55:38,550 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 
2023-09-08 15:55:38,551 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2023-09-08 15:55:38,554 DEBUG subiquitycore.utils:118 arun_command called: ['/usr/sbin/realm', 'discover']
2023-09-08 15:55:38,585 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 
2023-09-08 15:55:38,586 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 
2023-09-08 15:55:38,586 DEBUG root:30 start: subiquity/Install/install: 
2023-09-08 15:55:38,587 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps
2023-09-08 15:55:38,637 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1560
2023-09-08 15:55:38,742 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-09-08 15:55:38,742 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2023-09-08 15:55:38,742 DEBUG root:30 start: subiquity/SnapList/loader: 
2023-09-08 15:55:38,743 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-09-08 15:55:38,748 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled
2023-09-08 15:55:38,749 DEBUG root:30 start: subiquity/SnapList/loader/list: 
2023-09-08 15:55:38,749 DEBUG asyncio:54 Using selector: EpollSelector
2023-09-08 15:55:38,760 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.09349bf4'
2023-09-08 15:55:38,760 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info
2023-09-08 15:55:38,760 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 
2023-09-08 15:55:38,768 DEBUG subiquitycore.utils:132 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1
2023-09-08 15:55:38,861 DEBUG subiquity.server.geoip:124 no CountryCode found in '<?xml version="1.0" encoding="UTF-8"?><Response><Ip>10.172.200.64</Ip><Status>IP NOT FOUND</Status></Response>\n'
2023-09-08 15:55:38,873 INFO root:30 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:38,873 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-09-08 15:55:38,874 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,881 INFO root:30 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:38,882 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-09-08 15:55:38,882 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,883 INFO root:30 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:38,883 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-09-08 15:55:38,885 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,886 INFO root:30 start: subiquity/Meta/client_variant_POST: 
2023-09-08 15:55:38,886 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null
2023-09-08 15:55:38,887 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "POST /meta/client_variant?variant=%22desktop%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,888 INFO root:30 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:38,904 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 
2023-09-08 15:55:38,905 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null
2023-09-08 15:55:38,905 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /meta/interactive_sections HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,906 INFO root:30 start: subiquity/Meta/status_GET: 
2023-09-08 15:55:38,907 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-09-08 15:55:38,907 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,919 DEBUG root:30 start: subiquity/Locale/GET: 
2023-09-08 15:55:38,920 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8"
2023-09-08 15:55:38,920 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +0000] "GET /locale HTTP/1.1" 200 195 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:38,920 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2023-09-08 15:55:38,920 DEBUG subiquity.models.subiquity:252 model ubuntu_pro for postinstall stage is configured, to go {'drivers', 'codecs', 'ssh', 'snaplist', 'identity', 'network', 'timezone'}
2023-09-08 15:55:38,921 DEBUG subiquity.models.subiquity:252 model proxy for install stage is configured, to go {'mirror', 'source', 'filesystem', 'keyboard', 'network'}
2023-09-08 15:55:38,921 DEBUG subiquity.models.subiquity:252 model mirror for install stage is configured, to go {'source', 'filesystem', 'network', 'keyboard'}
2023-09-08 15:55:38,921 DEBUG subiquity.models.subiquity:252 model ssh for postinstall stage is configured, to go {'drivers', 'codecs', 'snaplist', 'identity', 'network', 'timezone'}
2023-09-08 15:55:38,921 DEBUG subiquity.models.subiquity:252 model snaplist for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'timezone'}
2023-09-08 15:55:38,921 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2023-09-08 15:55:38,921 INFO aiohttp.access:206  [08/Sep/2023:15:55:38 +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 15:55:39,012 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 200 None
2023-09-08 15:55:39,016 DEBUG root:30 finish: subiquity/SnapList/loader/list: SUCCESS: 
2023-09-08 15:55:39,016 DEBUG subiquity.server.controllers.snaplist:92 fetched list of 22 snaps
2023-09-08 15:55:39,020 DEBUG root:30 start: subiquity/SnapList/loader/fetch/microk8s: 
2023-09-08 15:55:39,256 DEBUG root:30 start: subiquity/Refresh/GET: 
2023-09-08 15:55:39,398 DEBUG probert.dasd:134 Probing DASD devies
2023-09-08 15:55:39,398 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-09-08 15:55:39,420 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 200 59
2023-09-08 15:55:39,420 DEBUG subiquity.server.controllers.refresh:201 check_for_update received []
2023-09-08 15:55:39,421 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: no new version of snap available
2023-09-08 15:55:39,421 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.09349bf4", "ne...
2023-09-08 15:55:39,421 INFO aiohttp.access:206  [08/Sep/2023:15:55:39 +0000] "GET /refresh?wait=true HTTP/1.1" 200 284 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:55:39,422 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-09-08 15:55:39,436 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=microk8s HTTP/1.1" 200 None
2023-09-08 15:55:39,438 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-09-08 15:55:39,461 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/microk8s: SUCCESS: 
2023-09-08 15:55:39,462 DEBUG root:30 start: subiquity/SnapList/loader/fetch/nextcloud: 
2023-09-08 15:55:40,030 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=nextcloud HTTP/1.1" 200 None
2023-09-08 15:55:40,031 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/nextcloud: SUCCESS: 
2023-09-08 15:55:40,031 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wekan: 
2023-09-08 15:55:40,322 DEBUG curtin:1321 Extracting storage config from probe data
2023-09-08 15:55:40,323 DEBUG curtin:73 /dev/vda is multipath device member? False
2023-09-08 15:55:40,323 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:55:40,323 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:55:40,323 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:55:40,323 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:55:40,348 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:55:40,348 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-09-08 15:55:40,348 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:55:40,348 DEBUG curtin:1328 Sorting extracted configurations
2023-09-08 15:55:40,349 INFO curtin:1347 Validating extracted storage config components
2023-09-08 15:55:40,373 DEBUG curtin:1364 Extracted (unmerged) storage config:
storage:
-   id: disk-vda
    path: /dev/vda
    type: disk

2023-09-08 15:55:40,373 DEBUG curtin:1368 Generating storage config dependencies
2023-09-08 15:55:40,373 DEBUG curtin:1374 Merging storage config dependencies
2023-09-08 15:55:40,373 DEBUG curtin:1379 Merged storage config:
storage:
    config:
    -   id: disk-vda
        path: /dev/vda
        type: disk
    version: 2

2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'252:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')}
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:55:40,373 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:31
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:19
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:32
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:48
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:75
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:55:40,374 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:55:40,375 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-09-08 15:55:40,375 DEBUG subiquity.server.controllers.filesystem:1236 block probing took 1.6 seconds
2023-09-08 15:55:40,375 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-09-08 15:55:40,408 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wekan HTTP/1.1" 200 None
2023-09-08 15:55:40,409 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wekan: SUCCESS: 
2023-09-08 15:55:40,409 DEBUG root:30 start: subiquity/SnapList/loader/fetch/kata-containers: 
2023-09-08 15:55:40,819 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=kata-containers HTTP/1.1" 200 None
2023-09-08 15:55:40,819 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/kata-containers: SUCCESS: 
2023-09-08 15:55:40,820 DEBUG root:30 start: subiquity/SnapList/loader/fetch/docker: 
2023-09-08 15:55:41,026 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=docker HTTP/1.1" 200 None
2023-09-08 15:55:41,027 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/docker: SUCCESS: 
2023-09-08 15:55:41,027 DEBUG root:30 start: subiquity/SnapList/loader/fetch/canonical-livepatch: 
2023-09-08 15:55:41,436 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=canonical-livepatch HTTP/1.1" 200 None
2023-09-08 15:55:41,438 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/canonical-livepatch: SUCCESS: 
2023-09-08 15:55:41,438 DEBUG root:30 start: subiquity/SnapList/loader/fetch/rocketchat-server: 
2023-09-08 15:55:41,718 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=rocketchat-server HTTP/1.1" 200 None
2023-09-08 15:55:41,719 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/rocketchat-server: SUCCESS: 
2023-09-08 15:55:41,719 DEBUG root:30 start: subiquity/SnapList/loader/fetch/mosquitto: 
2023-09-08 15:55:42,046 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=mosquitto HTTP/1.1" 200 None
2023-09-08 15:55:42,048 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/mosquitto: SUCCESS: 
2023-09-08 15:55:42,048 DEBUG root:30 start: subiquity/SnapList/loader/fetch/etcd: 
2023-09-08 15:55:42,458 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=etcd HTTP/1.1" 200 None
2023-09-08 15:55:42,460 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/etcd: SUCCESS: 
2023-09-08 15:55:42,461 DEBUG root:30 start: subiquity/SnapList/loader/fetch/powershell: 
2023-09-08 15:55:42,664 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=powershell HTTP/1.1" 200 None
2023-09-08 15:55:42,665 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/powershell: SUCCESS: 
2023-09-08 15:55:42,665 DEBUG root:30 start: subiquity/SnapList/loader/fetch/sabnzbd: 
2023-09-08 15:55:42,865 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=sabnzbd HTTP/1.1" 200 None
2023-09-08 15:55:42,867 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/sabnzbd: SUCCESS: 
2023-09-08 15:55:42,867 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wormhole: 
2023-09-08 15:55:43,070 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wormhole HTTP/1.1" 200 None
2023-09-08 15:55:43,072 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wormhole: SUCCESS: 
2023-09-08 15:55:43,072 DEBUG root:30 start: subiquity/SnapList/loader/fetch/aws-cli: 
2023-09-08 15:55:43,481 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=aws-cli HTTP/1.1" 200 None
2023-09-08 15:55:43,483 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/aws-cli: SUCCESS: 
2023-09-08 15:55:43,483 DEBUG root:30 start: subiquity/SnapList/loader/fetch/google-cloud-sdk: 
2023-09-08 15:55:43,705 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=google-cloud-sdk HTTP/1.1" 200 1799
2023-09-08 15:55:43,705 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/google-cloud-sdk: SUCCESS: 
2023-09-08 15:55:43,706 DEBUG root:30 start: subiquity/SnapList/loader/fetch/slcli: 
2023-09-08 15:55:44,095 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=slcli HTTP/1.1" 200 None
2023-09-08 15:55:44,095 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/slcli: SUCCESS: 
2023-09-08 15:55:44,096 DEBUG root:30 start: subiquity/SnapList/loader/fetch/doctl: 
2023-09-08 15:55:44,301 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=doctl HTTP/1.1" 200 None
2023-09-08 15:55:44,301 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/doctl: SUCCESS: 
2023-09-08 15:55:44,302 DEBUG root:30 start: subiquity/SnapList/loader/fetch/conjure-up: 
2023-09-08 15:55:44,505 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=conjure-up HTTP/1.1" 200 None
2023-09-08 15:55:44,506 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/conjure-up: SUCCESS: 
2023-09-08 15:55:44,506 DEBUG root:30 start: subiquity/SnapList/loader/fetch/postgresql10: 
2023-09-08 15:55:44,913 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=postgresql10 HTTP/1.1" 200 1523
2023-09-08 15:55:44,914 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/postgresql10: SUCCESS: 
2023-09-08 15:55:44,914 DEBUG root:30 start: subiquity/SnapList/loader/fetch/heroku: 
2023-09-08 15:55:45,118 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=heroku HTTP/1.1" 200 None
2023-09-08 15:55:45,118 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/heroku: SUCCESS: 
2023-09-08 15:55:45,119 DEBUG root:30 start: subiquity/SnapList/loader/fetch/keepalived: 
2023-09-08 15:55:45,323 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=keepalived HTTP/1.1" 200 None
2023-09-08 15:55:45,324 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/keepalived: SUCCESS: 
2023-09-08 15:55:45,324 DEBUG root:30 start: subiquity/SnapList/loader/fetch/prometheus: 
2023-09-08 15:55:45,528 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=prometheus HTTP/1.1" 200 None
2023-09-08 15:55:45,529 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/prometheus: SUCCESS: 
2023-09-08 15:55:45,529 DEBUG root:30 start: subiquity/SnapList/loader/fetch/juju: 
2023-09-08 15:55:45,938 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=juju HTTP/1.1" 200 None
2023-09-08 15:55:45,940 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/juju: SUCCESS: 
2023-09-08 15:55:45,940 DEBUG root:30 finish: subiquity/SnapList/loader: SUCCESS: 
2023-09-08 15:56:01,282 DEBUG root:30 start: subiquity/Locale/POST: 
2023-09-08 15:56:01,283 DEBUG subiquity.server.controllers.locale:68 en_US.UTF-8
2023-09-08 15:56:01,283 DEBUG subiquity.models.subiquity:252 model locale for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'timezone'}
2023-09-08 15:56:01,284 DEBUG root:30 finish: subiquity/Locale/POST: SUCCESS: 200 null
2023-09-08 15:56:01,284 INFO aiohttp.access:206  [08/Sep/2023:15:56:01 +0000] "POST /locale HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:01,284 DEBUG subiquitycore.utils:118 arun_command called: ['localectl', 'set-locale', 'en_US.UTF-8']
2023-09-08 15:56:01,821 DEBUG subiquitycore.utils:132 arun_command ['localectl', 'set-locale', 'en_US.UTF-8'] exited with code 0
2023-09-08 15:56:02,890 DEBUG root:30 start: subiquity/Filesystem/has_rst_GET: 
2023-09-08 15:56:02,891 DEBUG root:30 finish: subiquity/Filesystem/has_rst_GET: SUCCESS: 200 false
2023-09-08 15:56:02,891 INFO aiohttp.access:206  [08/Sep/2023:15:56:02 +0000] "GET /storage/has_rst HTTP/1.1" 200 191 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:02,898 DEBUG root:30 start: subiquity/Keyboard/GET: 
2023-09-08 15:56:02,911 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2023-09-08 15:56:02,911 INFO aiohttp.access:206  [08/Sep/2023:15:56:02 +0000] "GET /keyboard HTTP/1.1" 200 41538 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:02,914 DEBUG root:30 start: subiquity/Keyboard/GET: 
2023-09-08 15:56:02,922 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2023-09-08 15:56:02,923 INFO aiohttp.access:206  [08/Sep/2023:15:56:02 +0000] "GET /keyboard HTTP/1.1" 200 41538 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:02,937 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 
2023-09-08 15:56:02,937 DEBUG subiquitycore.utils:118 arun_command called: ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','us')]"]
2023-09-08 15:56:03,057 DEBUG subiquitycore.utils:132 arun_command ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','us')]"] exited with code 0
2023-09-08 15:56:03,057 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null
2023-09-08 15:56:03,058 INFO aiohttp.access:206  [08/Sep/2023:15:56:02 +0000] "POST /keyboard/input_source?user=%22ubuntu%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:04,353 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 
2023-09-08 15:56:04,354 DEBUG subiquitycore.utils:118 arun_command called: ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','gb')]"]
2023-09-08 15:56:04,441 DEBUG subiquitycore.utils:132 arun_command ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','gb')]"] exited with code 0
2023-09-08 15:56:04,441 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null
2023-09-08 15:56:04,441 INFO aiohttp.access:206  [08/Sep/2023:15:56:04 +0000] "POST /keyboard/input_source?user=%22ubuntu%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:05,594 DEBUG root:30 start: subiquity/Keyboard/POST: 
2023-09-08 15:56:05,595 DEBUG subiquity.server.controllers.keyboard:221 KeyboardSetting(layout='gb', variant='', toggle=None)
2023-09-08 15:56:05,596 DEBUG subiquitycore.utils:118 arun_command called: ['setupcon', '--save', '--force', '--keyboard-only']
2023-09-08 15:56:06,077 DEBUG subiquitycore.utils:132 arun_command ['setupcon', '--save', '--force', '--keyboard-only'] exited with code 0
2023-09-08 15:56:06,077 DEBUG subiquitycore.utils:118 arun_command called: ['/snap/ubuntu-desktop-installer/1229/bin/subiquity/bin/subiquity-loadkeys']
2023-09-08 15:56:06,088 DEBUG subiquitycore.utils:132 arun_command ['/snap/ubuntu-desktop-installer/1229/bin/subiquity/bin/subiquity-loadkeys'] exited with code 0
2023-09-08 15:56:06,088 DEBUG subiquity.models.subiquity:252 model keyboard for install stage is configured, to go {'source', 'filesystem', 'network'}
2023-09-08 15:56:06,088 DEBUG root:30 finish: subiquity/Keyboard/POST: SUCCESS: 200 null
2023-09-08 15:56:06,089 INFO aiohttp.access:206  [08/Sep/2023:15:56:05 +0000] "POST /keyboard HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:07,351 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2023-09-08 15:56:07,352 DEBUG subiquitycore.models.network:447 has_network True
2023-09-08 15:56:07,352 DEBUG subiquity.models.subiquity:252 model network for install stage is configured, to go {'source', 'filesystem'}
2023-09-08 15:56:07,352 DEBUG subiquity.models.subiquity:252 model network for postinstall stage is configured, to go {'timezone', 'drivers', 'codecs', 'identity'}
2023-09-08 15:56:07,352 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2023-09-08 15:56:07,353 INFO aiohttp.access:206  [08/Sep/2023:15:56:07 +0000] "POST /meta/mark_configured?endpoint_names=%5B%22network%22%5D HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:07,354 DEBUG root:30 start: subiquity/Refresh/GET: 
2023-09-08 15:56:07,354 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.09349bf4", "ne...
2023-09-08 15:56:07,354 INFO aiohttp.access:206  [08/Sep/2023:15:56:07 +0000] "GET /refresh?wait=true HTTP/1.1" 200 284 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:07,356 DEBUG root:30 start: subiquity/Source/GET: 
2023-09-08 15:56:07,356 DEBUG root:30 finish: subiquity/Source/GET: SUCCESS: 200 {"sources": [{"name": "Ubuntu Desktop", "description": "A full featured Ubunt...
2023-09-08 15:56:07,357 INFO aiohttp.access:206  [08/Sep/2023:15:56:07 +0000] "GET /source HTTP/1.1" 200 419 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:07,363 DEBUG root:30 start: subiquity/Drivers/GET: 
2023-09-08 15:56:07,363 DEBUG root:30 finish: subiquity/Drivers/GET: SUCCESS: 200 {"install": false, "drivers": null, "local_only": false, "search_drivers": fa...
2023-09-08 15:56:07,364 INFO aiohttp.access:206  [08/Sep/2023:15:56:07 +0000] "GET /drivers HTTP/1.1" 200 268 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:07,365 DEBUG root:30 start: subiquity/Codecs/GET: 
2023-09-08 15:56:07,365 DEBUG root:30 finish: subiquity/Codecs/GET: SUCCESS: 200 {"install": false}
2023-09-08 15:56:07,365 INFO aiohttp.access:206  [08/Sep/2023:15:56:07 +0000] "GET /codecs HTTP/1.1" 200 205 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:08,521 DEBUG root:30 start: subiquity/Source/POST: 
2023-09-08 15:56:08,522 DEBUG subiquity.models.subiquity:252 model source for install stage is configured, to go {'filesystem'}
2023-09-08 15:56:08,522 DEBUG subiquity.server.controllers.drivers:88 source variant has been set. Querying list of drivers.
2023-09-08 15:56:08,522 DEBUG root:30 finish: subiquity/Source/POST: SUCCESS: 200 null
2023-09-08 15:56:08,522 INFO aiohttp.access:206  [08/Sep/2023:15:56:08 +0000] "POST /source?source_id=%22ubuntu-desktop%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:08,523 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/standard.squashfs', '/tmp/tmpxz1b42lu/standard.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:08,529 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/standard.enhanced-secureboot.squashfs', '/tmp/tmpxz1b42lu/standard.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:08,555 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/standard.enhanced-secureboot.en.squashfs', '/tmp/tmpxz1b42lu/standard.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:08,585 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmpxz1b42lu/standard.enhanced-secureboot.en.squashfs.dir:/tmp/tmpxz1b42lu/standard.enhanced-secureboot.squashfs.dir:/tmp/tmpxz1b42lu/standard.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmpxz1b42lu/root.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:08,613 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'mount', '-o', 'bind', '/tmp/tmpxz1b42lu/root.dir/var/lib/snapd/seed/systems', '/var/lib/snapd/seed/systems']
2023-09-08 15:56:08,617 DEBUG root:30 start: subiquity/Drivers/_list_drivers: 
2023-09-08 15:56:08,617 DEBUG root:30 start: subiquity/Drivers/_list_drivers/wait_apt: 
2023-09-08 15:56:08,617 DEBUG root:30 start: subiquity/Drivers/POST: 
2023-09-08 15:56:08,617 DEBUG subiquity.models.subiquity:252 model drivers for postinstall stage is configured, to go {'timezone', 'codecs', 'identity'}
2023-09-08 15:56:08,617 DEBUG root:30 finish: subiquity/Drivers/POST: SUCCESS: 200 null
2023-09-08 15:56:08,618 INFO aiohttp.access:206  [08/Sep/2023:15:56:08 +0000] "POST /drivers HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:08,618 DEBUG root:30 start: subiquity/Codecs/POST: 
2023-09-08 15:56:08,618 DEBUG subiquity.models.subiquity:252 model codecs for postinstall stage is configured, to go {'identity', 'timezone'}
2023-09-08 15:56:08,618 DEBUG root:30 finish: subiquity/Codecs/POST: SUCCESS: 200 null
2023-09-08 15:56:08,618 INFO aiohttp.access:206  [08/Sep/2023:15:56:08 +0000] "POST /codecs HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:08,619 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-09-08 15:56:08,657 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'mount', '-o', 'bind', '/tmp/tmpxz1b42lu/root.dir/var/lib/snapd/seed/snaps/pc-kernel_1397.snap', '/var/lib/snapd/seed/snaps/pc-kernel_1397.snap']
2023-09-08 15:56:08,664 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0']
2023-09-08 15:56:08,674 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-09-08 15:56:08,674 DEBUG subiquity.server.controllers.filesystem:1438 _udev_event add Device('/sys/devices/virtual/block/loop12')
2023-09-08 15:56:08,674 DEBUG subiquity.server.controllers.filesystem:1421 Triggered Probert run on udev event
2023-09-08 15:56:08,675 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-09-08 15:56:08,675 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-09-08 15:56:08,680 DEBUG asyncio:54 Using selector: EpollSelector
2023-09-08 15:56:08,724 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'mount', '-o', 'bind', '/tmp/tmpxz1b42lu/root.dir/var/lib/snapd/seed/snaps/pc_154.snap', '/var/lib/snapd/seed/snaps/pc_154.snap']
2023-09-08 15:56:09,577 DEBUG probert.dasd:134 Probing DASD devies
2023-09-08 15:56:09,577 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-09-08 15:56:09,586 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-09-08 15:56:09,588 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-09-08 15:56:09,702 DEBUG curtin:1321 Extracting storage config from probe data
2023-09-08 15:56:09,702 DEBUG curtin:73 /dev/vda is multipath device member? False
2023-09-08 15:56:09,702 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:56:09,702 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:56:09,702 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:56:09,702 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:56:09,741 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:56:09,741 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-09-08 15:56:09,741 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:56:09,741 DEBUG curtin:1328 Sorting extracted configurations
2023-09-08 15:56:09,741 INFO curtin:1347 Validating extracted storage config components
2023-09-08 15:56:09,790 DEBUG curtin:1364 Extracted (unmerged) storage config:
storage:
-   id: disk-vda
    path: /dev/vda
    type: disk

2023-09-08 15:56:09,790 DEBUG curtin:1368 Generating storage config dependencies
2023-09-08 15:56:09,791 DEBUG curtin:1374 Merging storage config dependencies
2023-09-08 15:56:09,791 DEBUG curtin:1379 Merged storage config:
storage:
    config:
    -   id: disk-vda
        path: /dev/vda
        type: disk
    version: 2

2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'252:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')}
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:09,791 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:65
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:65
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:65
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:31
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:19
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:32
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41
2023-09-08 15:56:09,792 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:65
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:48
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:75
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:09,793 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:09,793 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-09-08 15:56:09,793 DEBUG subiquity.server.controllers.filesystem:1236 block probing took 1.1 seconds
2023-09-08 15:56:09,794 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-09-08 15:56:12,500 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/systems/enhanced-secureboot-desktop HTTP/1.1" 200 None
2023-09-08 15:56:12,501 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'umount', '/var/lib/snapd/seed/snaps/pc_154.snap']
2023-09-08 15:56:12,554 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'umount', '/var/lib/snapd/seed/snaps/pc-kernel_1397.snap']
2023-09-08 15:56:12,598 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2949', '--setenv', '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', '--setenv', '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:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1229/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1229', '--', 'umount', '/var/lib/snapd/seed/systems']
2023-09-08 15:56:12,638 DEBUG curtin:95 Running command ['umount', '/tmp/tmpxz1b42lu/root.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:12,642 DEBUG curtin:95 Running command ['umount', '/tmp/tmpxz1b42lu/standard.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:12,660 DEBUG curtin:95 Running command ['umount', '/tmp/tmpxz1b42lu/standard.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:12,705 DEBUG curtin:95 Running command ['umount', '/tmp/tmpxz1b42lu/standard.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-09-08 15:56:12,728 DEBUG subiquity.server.controllers.filesystem:312 got system SystemDetails(current=False, volumes={'pc': Volume(schema='gpt', bootloader='grub', id='', structure=[VolumeStructure(name='EFI System partition', label='ubuntu-seed', offset=1048576, offset_write=None, size=786432000, type='C12A7328-F81F-11D2-BA4B-00A0C93EC93B', role='system-seed-null', id='', filesystem='vfat', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=2, preserve=None)), VolumeStructure(name='ubuntu-boot', label='ubuntu-boot', offset=787480576, offset_write=None, size=786432000, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-boot', id='', filesystem='ext4', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=1, preserve=None)), VolumeStructure(name='ubuntu-save', label='ubuntu-save', offset=1573912576, offset_write=None, size=33554432, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-save', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None)), VolumeStructure(name='ubuntu-data', label='ubuntu-data', offset=1607467008, offset_write=None, size=4294967296, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-data', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None))])}, storage_encryption=StorageEncryption(support=<StorageEncryptionSupport.UNAVAILABLE: 'unavailable'>, storage_safety=<StorageSafety.PREFER_ENCRYPTED: 'prefer-encrypted'>, encryption_type=<EncryptionType.NONE: ''>, unavailable_reason='not encrypting device storage as checking TPM gave: not a supported EFI system'))
2023-09-08 15:56:12,729 DEBUG subiquity.server.controllers.filesystem:381 got system SystemDetails(current=False, volumes={'pc': Volume(schema='gpt', bootloader='grub', id='', structure=[VolumeStructure(name='EFI System partition', label='ubuntu-seed', offset=1048576, offset_write=None, size=786432000, type='C12A7328-F81F-11D2-BA4B-00A0C93EC93B', role='system-seed-null', id='', filesystem='vfat', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=2, preserve=None)), VolumeStructure(name='ubuntu-boot', label='ubuntu-boot', offset=787480576, offset_write=None, size=786432000, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-boot', id='', filesystem='ext4', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=1, preserve=None)), VolumeStructure(name='ubuntu-save', label='ubuntu-save', offset=1573912576, offset_write=None, size=33554432, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-save', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None)), VolumeStructure(name='ubuntu-data', label='ubuntu-data', offset=1607467008, offset_write=None, size=4294967296, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-data', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None))])}, storage_encryption=StorageEncryption(support=<StorageEncryptionSupport.UNAVAILABLE: 'unavailable'>, storage_safety=<StorageSafety.PREFER_ENCRYPTED: 'prefer-encrypted'>, encryption_type=<EncryptionType.NONE: ''>, unavailable_reason='not encrypting device storage as checking TPM gave: not a supported EFI system')) for variation enhanced-secureboot
2023-09-08 15:56:12,729 DEBUG subiquity.server.controllers.filesystem:387 Not offering core boot based install: not a UEFI system
2023-09-08 15:56:12,729 DEBUG subiquity.server.controllers.filesystem:381 got system None for variation standard
2023-09-08 15:56:12,729 DEBUG subiquity.server.controllers.filesystem:935 suggested install minimum size: 9.759G
2023-09-08 15:56:12,730 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2023-09-08 15:56:12,731 INFO aiohttp.access:206  [08/Sep/2023:15:56:08 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 698 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:12,731 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0']
2023-09-08 15:56:12,737 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-09-08 15:56:12,737 DEBUG subiquity.server.controllers.filesystem:1438 _udev_event change Device('/sys/devices/virtual/block/loop12')
2023-09-08 15:56:12,737 DEBUG subiquity.server.controllers.filesystem:1438 _udev_event change Device('/sys/devices/virtual/block/loop12')
2023-09-08 15:56:12,738 DEBUG subiquity.server.controllers.filesystem:1438 _udev_event change Device('/sys/devices/virtual/block/loop11')
2023-09-08 15:56:12,738 DEBUG subiquity.server.controllers.filesystem:1438 _udev_event change Device('/sys/devices/virtual/block/loop11')
2023-09-08 15:56:12,738 DEBUG subiquity.server.controllers.filesystem:1421 Triggered Probert run on udev event
2023-09-08 15:56:12,738 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-09-08 15:56:12,738 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-09-08 15:56:12,739 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-09-08 15:56:12,740 DEBUG asyncio:54 Using selector: EpollSelector
2023-09-08 15:56:12,976 DEBUG probert.dasd:134 Probing DASD devies
2023-09-08 15:56:12,976 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-09-08 15:56:12,978 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-09-08 15:56:12,979 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-09-08 15:56:13,012 DEBUG curtin:1321 Extracting storage config from probe data
2023-09-08 15:56:13,012 DEBUG curtin:73 /dev/vda is multipath device member? False
2023-09-08 15:56:13,012 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:56:13,012 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:56:13,012 DEBUG curtin:86 /dev/vda is multipath device partition? False
2023-09-08 15:56:13,012 DEBUG curtin:61 /dev/vda is multipath device? False
2023-09-08 15:56:13,023 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:56:13,023 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-09-08 15:56:13,023 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-09-08 15:56:13,023 DEBUG curtin:1328 Sorting extracted configurations
2023-09-08 15:56:13,023 INFO curtin:1347 Validating extracted storage config components
2023-09-08 15:56:13,032 DEBUG curtin:1364 Extracted (unmerged) storage config:
storage:
-   id: disk-vda
    path: /dev/vda
    type: disk

2023-09-08 15:56:13,033 DEBUG curtin:1368 Generating storage config dependencies
2023-09-08 15:56:13,033 DEBUG curtin:1374 Merging storage config dependencies
2023-09-08 15:56:13,033 DEBUG curtin:1379 Merged storage config:
storage:
    config:
    -   id: disk-vda
        path: /dev/vda
        type: disk
    version: 2

2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'252:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')}
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:27
2023-09-08 15:56:13,033 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:31
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:19
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:32
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:2
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:48
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:75
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:13,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4
2023-09-08 15:56:13,034 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-09-08 15:56:13,034 DEBUG subiquity.server.controllers.filesystem:1236 block probing took 0.3 seconds
2023-09-08 15:56:13,034 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-09-08 15:56:13,034 DEBUG subiquity.server.controllers.filesystem:935 suggested install minimum size: 9.759G
2023-09-08 15:56:13,035 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2023-09-08 15:56:13,035 INFO aiohttp.access:206  [08/Sep/2023:15:56:12 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 698 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:13,038 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2023-09-08 15:56:13,039 DEBUG subiquity.server.controllers.filesystem:935 suggested install minimum size: 9.759G
2023-09-08 15:56:13,040 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2023-09-08 15:56:13,040 INFO aiohttp.access:206  [08/Sep/2023:15:56:13 +0000] "GET /storage/v2/guided?wait=true HTTP/1.1" 200 474 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:13,041 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2023-09-08 15:56:13,042 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2023-09-08 15:56:13,042 INFO aiohttp.access:206  [08/Sep/2023:15:56:13 +0000] "GET /storage/has_bitlocker HTTP/1.1" 200 188 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:34,702 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2023-09-08 15:56:34,702 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2023-09-08 15:56:34,703 INFO aiohttp.access:206  [08/Sep/2023:15:56:34 +0000] "GET /storage/has_bitlocker HTTP/1.1" 200 188 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:34,704 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-09-08 15:56:34,705 DEBUG subiquity.server.controllers.filesystem:935 suggested install minimum size: 9.759G
2023-09-08 15:56:34,705 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2023-09-08 15:56:34,706 INFO aiohttp.access:206  [08/Sep/2023:15:56:34 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 698 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:34,707 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2023-09-08 15:56:34,707 DEBUG subiquity.server.controllers.filesystem:935 suggested install minimum size: 9.759G
2023-09-08 15:56:34,708 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2023-09-08 15:56:34,708 INFO aiohttp.access:206  [08/Sep/2023:15:56:34 +0000] "GET /storage/v2/guided?wait=true HTTP/1.1" 200 474 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:34,714 DEBUG root:30 start: subiquity/Filesystem/v2_guided_POST: 
2023-09-08 15:56:34,714 DEBUG subiquity.server.controllers.filesystem:1091 GuidedChoiceV2(target=GuidedStorageTargetReformat(disk_id='disk-vda', allowed=[<GuidedCapability.DIRECT: 2>, <GuidedCapability.LVM: 3>, <GuidedCapability.LVM_LUKS: 4>, <GuidedCapability.ZFS: 5>], disallowed=[]), capability=<GuidedCapability.ZFS: 5>, recovery_key=None, sizing_policy=<SizingPolicy.ALL: 2>, reset_partition=False)
2023-09-08 15:56:34,715 DEBUG curtin:37 swap suggestion analysis: available: 18G maxsize: 4G memsize: 3G size before decision: 3G suggested size: 3G reason: lesser of formula or maxsize
2023-09-08 15:56:34,794 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_POST: SUCCESS: 500 Traceback (most recent call last):
  File "/snap/ubuntu-desktop-installer/122...
2023-09-08 15:56:34,794 DEBUG subiquity.server.server:446 request to /storage/v2/guided crashed
Traceback (most recent call last):
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/common/api/server.py", line 164, in handler
    result = await implementation(**args)
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/filesystem.py", line 1093, in v2_guided_POST
    await self.guided(data)
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/filesystem.py", line 672, in guided
    self.guided_zfs(gap, choice)
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/server/controllers/filesystem.py", line 510, in guided_zfs
    self.create_partition(device, gap_swap, dict(fstype="swap"))
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/common/filesystem/manipulator.py", line 103, in create_partition
    part = self.model.add_partition(
  File "/snap/ubuntu-desktop-installer/1229/bin/subiquity/subiquity/models/filesystem.py", line 1992, in add_partition
    raise Exception(
Exception: ('size %s or offset %s not aligned to %s', 4096942080, 2149580800, 1048576)
2023-09-08 15:56:34,795 DEBUG subiquity.common.errorreport:394 generating crash report
2023-09-08 15:56:34,796 INFO subiquity.common.errorreport:415 saving crash report 'request to /storage/v2/guided crashed with Exception' to /var/crash/1694188594.795275211.server_request_fail.crash
2023-09-08 15:56:34,797 INFO aiohttp.access:206  [08/Sep/2023:15:56:34 +0000] "POST /storage/v2/guided HTTP/1.1" 500 1572 "-" "Dart/3.0 (dart:io)"
2023-09-08 15:56:34,797 INFO root:30 start: subiquity/ErrorReporter/1694188594.795275211.server_request_fail/add_info: