2023-10-11 03:36:18,847 INFO subiquity:199 Starting Subiquity server revision 1257 of snap /snap/ubuntu-desktop-installer/1257
2023-10-11 03:36:18,848 INFO subiquity:200 Arguments passed: ['/snap/ubuntu-desktop-installer/1257/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/1257/etc/subiquity/postinst.d']
2023-10-11 03:36:18,848 DEBUG subiquity:201 Kernel commandline: CommandLineParams(_raw='BOOT_IMAGE=/casper/vmlinuz layerfs-path=minimal.standard.live.squashfs --- quiet splash\n', _tokens={'quiet', 'splash', '---'}, _values={'BOOT_IMAGE': '/casper/vmlinuz', 'layerfs-path': 'minimal.standard.live.squashfs'})
2023-10-11 03:36:18,848 DEBUG subiquity:202 Environment: environ({'SNAP_REVISION': '1257', 'SNAP_REAL_HOME': '/root', 'SNAP_USER_COMMON': '/root/snap/ubuntu-desktop-installer/common', 'PATH_ORIG': '/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/bin/subiquity', 'SYSTEMD_EXEC_PID': '2045', 'SNAP_CONTEXT': 'UYPH5Zx0uv4wLKXLSgv4zzLriBpA8-p4sbeGmuaKK7fj2Nqyyq-X', 'LANG': 'C.UTF-8', 'SNAP_ARCH': 'amd64', 'PY3OR2_PYTHON': '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', 'SNAP_INSTANCE_NAME': 'ubuntu-desktop-installer', 'SNAP_USER_DATA': '/root/snap/ubuntu-desktop-installer/1257', 'INVOCATION_ID': '2d04830f947c4e0fa86ba07ca495df15', '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/1257/lib:/snap/ubuntu-desktop-installer/1257/usr/lib:/snap/ubuntu-desktop-installer/1257/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1257/usr/lib/x86_64-linux-gnu', 'PYTHONPATH_ORIG': '', 'PYTHONPATH': '/snap/ubuntu-desktop-installer/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', 'PYTHON': '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', 'PYTHONIOENCODING': 'utf-8', 'SNAP': '/snap/ubuntu-desktop-installer/1257', 'SNAP_COMMON': '/var/snap/ubuntu-desktop-installer/common', 'SNAP_VERSION': '0+git.bca6e31c', 'DISPLAY': ':0', 'SHLVL': '1', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'SNAP_COOKIE': 'UYPH5Zx0uv4wLKXLSgv4zzLriBpA8-p4sbeGmuaKK7fj2Nqyyq-X', 'SNAP_DATA': '/var/snap/ubuntu-desktop-installer/1257', 'LD_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/ubuntu-desktop-installer/1257/lib:/snap/ubuntu-desktop-installer/1257/usr/lib:/snap/ubuntu-desktop-installer/1257/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1257/usr/lib/x86_64-linux-gnu', 'SNAP_NAME': 'ubuntu-desktop-installer', 'JOURNAL_STREAM': '8:21893', 'PATH': '/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/bin/subiquity', 'OLDPWD': '/var/snap/ubuntu-desktop-installer/1257', '_': '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', 'APPORT_DATA_DIR': '/snap/ubuntu-desktop-installer/1257/bin/subiquity/share/apport'})
2023-10-11 03:36:18,848 DEBUG asyncio:54 Using selector: EpollSelector
2023-10-11 03:36:18,848 DEBUG subiquitycore.prober:33 Prober() init finished, data:None
2023-10-11 03:36:18,878 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
2023-10-11 03:36:18,884 DEBUG subiquitycore.netplan:113 config for zz-all-en = {'dhcp4': True, 'match': {'name': 'en*'}}
2023-10-11 03:36:18,884 DEBUG subiquitycore.netplan:113 config for zz-all-eth = {'dhcp4': True, 'match': {'name': 'eth*'}}
2023-10-11 03:36:18,892 DEBUG subiquitycore.utils:121 arun_command called: ['cloud-init', 'status', '--wait']
2023-10-11 03:36:35,323 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:35,324 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-10-11 03:36:36,326 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:36,326 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-10-11 03:36:37,335 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:37,335 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-10-11 03:36:38,339 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:38,339 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-10-11 03:36:39,342 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:39,343 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-10-11 03:36:40,346 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:40,347 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-10-11 03:36:41,352 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:41,352 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-10-11 03:36:41,431 DEBUG subiquitycore.utils:135 arun_command ['cloud-init', 'status', '--wait'] exited with code 0
2023-10-11 03:36:41,431 DEBUG subiquity.server.server:569 waited 22.53916358947754s for cloud-init
2023-10-11 03:36:41,433 DEBUG subiquity.cloudinit:14 Loaded cloud config from /run/cloud-init/combined-cloud-config.json
2023-10-11 03:36:41,433 DEBUG subiquity.server.server:553 no autoinstall found in cloud-config
2023-10-11 03:36:41,433 DEBUG subiquitycore.utils:79 run_command called: ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys']
2023-10-11 03:36:41,444 DEBUG subiquitycore.utils:98 run_command ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys'] exited with code 255
2023-10-11 03:36:41,445 DEBUG subiquitycore.ssh:52 ssh-keygen -lf /home/installer/.ssh/authorized_keys failed '/home/installer/.ssh/authorized_keys is not a public key file.\r\n'
2023-10-11 03:36:41,445 DEBUG subiquitycore.utils:79 run_command called: chpasswd
2023-10-11 03:36:41,676 DEBUG subiquitycore.utils:98 run_command chpasswd exited with code 0
2023-10-11 03:36:41,678 DEBUG subiquity.server.server:470 load_autoinstall_config only_early True file None
2023-10-11 03:36:41,678 DEBUG subiquity.server.server:470 load_autoinstall_config only_early False file None
2023-10-11 03:36:41,679 DEBUG subiquitycore.core:118 starting controllers
2023-10-11 03:36:41,684 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic-hwe-22.04 due to /etc/subiquity/kernel-meta-package
2023-10-11 03:36:41,690 DEBUG subiquity.models.source:93 loaded 2 sources from '/cdrom/casper/install-sources.yaml'
2023-10-11 03:36:41,691 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2023-10-11 03:36:41,691 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2023-10-11 03:36:41,691 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-10-11 03:36:41,691 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.1.89/24'}
2023-10-11 03:36:41,691 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-10-11 03:36:41,691 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5054:ff:fe7b:dd45/64'}
2023-10-11 03:36:41,691 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2023-10-11 03:36:41,776 DEBUG subiquitycore.models.network:475 new_link 1 lo lo
2023-10-11 03:36:41,776 DEBUG subiquitycore.models.network:477 ignoring based on type
2023-10-11 03:36:41,776 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2023-10-11 03:36:41,844 DEBUG subiquitycore.models.network:475 new_link 2 enp1s0 eth
2023-10-11 03:36:41,848 DEBUG subiquitycore.models.network:506 new_link 2 enp1s0 with config {'dhcp4': True}
2023-10-11 03:36:41,852 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp1s0
2023-10-11 03:36:41,852 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp1s0
2023-10-11 03:36:41,853 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2023-10-11 03:36:41,853 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.1.89/24'}
2023-10-11 03:36:41,853 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2023-10-11 03:36:41,853 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2023-10-11 03:36:41,853 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-10-11 03:36:41,853 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5054:ff:fe7b:dd45/64'}
2023-10-11 03:36:41,853 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2023-10-11 03:36:41,853 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2023-10-11 03:36:41,853 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2}
2023-10-11 03:36:41,945 DEBUG pyroute2.ndb.140225001771584.sources.localhost:74 init
2023-10-11 03:36:41,946 DEBUG pyroute2.ndb.140225001771584.sources.localhost:384 starting the source
2023-10-11 03:36:41,951 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:74 init
2023-10-11 03:36:41,951 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:384 starting the source
2023-10-11 03:36:41,951 DEBUG pyroute2.ndb.140225001771584.sources.localhost:74 connecting
2023-10-11 03:36:41,951 DEBUG pyroute2.ndb.140225001771584.sources.localhost:74 loading
2023-10-11 03:36:41,965 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:74 connecting
2023-10-11 03:36:41,966 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:74 loading
2023-10-11 03:36:41,977 DEBUG pyroute2.ndb.140225001771584.sources.localhost:74 running
2023-10-11 03:36:41,979 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:74 running
2023-10-11 03:36:42,010 DEBUG pyroute2.ndb.140225001771584.sources.localhost:399 source shutdown
2023-10-11 03:36:42,011 DEBUG pyroute2.ndb.140225001771584.sources.localhost:374 sync
2023-10-11 03:36:42,011 DEBUG pyroute2.ndb.140225001771584.sources.localhost:369 shutdown handled by the main thread
2023-10-11 03:36:42,011 DEBUG pyroute2.ndb.140225001771584.sources.localhost:74 stopped
2023-10-11 03:36:42,011 DEBUG pyroute2.ndb.140225001771584.main:851 flush DB for the target localhost
2023-10-11 03:36:42,011 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:399 source shutdown
2023-10-11 03:36:42,025 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:374 sync
2023-10-11 03:36:42,025 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:369 shutdown handled by the main thread
2023-10-11 03:36:42,025 DEBUG pyroute2.ndb.140225001771584.sources.localhost/nsmanager:74 stopped
2023-10-11 03:36:42,026 DEBUG pyroute2.ndb.140225001771584.main:851 flush DB for the target localhost/nsmanager
2023-10-11 03:36:42,026 DEBUG subiquitycore.controllers.network:102 default routes True
2023-10-11 03:36:42,026 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'169.254.0.0/16', 'ifindex': 2}
2023-10-11 03:36:42,026 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.1.0/24', 'ifindex': 2}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.1.89', 'ifindex': 2}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.1.255', 'ifindex': 2}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::5054:ff:fe7b:dd45', 'ifindex': 2}
2023-10-11 03:36:42,027 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 5, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2}
2023-10-11 03:36:42,139 DEBUG subiquitycore.core:121 controllers started
2023-10-11 03:36:42,139 INFO root:30 start: subiquity/apply_autoinstall_config: 
2023-10-11 03:36:42,139 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 
2023-10-11 03:36:42,151 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,152 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 
2023-10-11 03:36:42,152 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,152 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 
2023-10-11 03:36:42,152 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,152 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 
2023-10-11 03:36:42,152 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,153 DEBUG subiquity.models.subiquity:256 model userdata for postinstall stage is configured, to go {'locale', 'drivers', 'ssh', 'identity', 'packages', 'ubuntu_pro', 'snaplist'}
2023-10-11 03:36:42,153 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 
2023-10-11 03:36:42,153 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,154 DEBUG subiquity.models.subiquity:256 model packages for postinstall stage is configured, to go {'locale', 'drivers', 'ssh', 'identity', 'ubuntu_pro', 'snaplist'}
2023-10-11 03:36:42,154 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 
2023-10-11 03:36:42,154 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,154 DEBUG subiquity.models.subiquity:256 model debconf_selections for install stage is configured, to go {'proxy', 'keyboard', 'source', 'filesystem', 'kernel'}
2023-10-11 03:36:42,154 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Locale as interactive
2023-10-11 03:36:42,154 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Refresh as interactive
2023-10-11 03:36:42,154 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 
2023-10-11 03:36:42,154 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,154 DEBUG subiquity.models.subiquity:256 model kernel for install stage is configured, to go {'source', 'filesystem', 'keyboard', 'proxy'}
2023-10-11 03:36:42,155 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Integrity as interactive
2023-10-11 03:36:42,155 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Keyboard as interactive
2023-10-11 03:36:42,155 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 
2023-10-11 03:36:42,155 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Source as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Network as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping UbuntuPro as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Proxy as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Mirror as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Filesystem as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Identity as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SSH as interactive
2023-10-11 03:36:42,160 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SnapList as interactive
2023-10-11 03:36:42,160 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 
2023-10-11 03:36:42,160 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Codecs as interactive
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Drivers as interactive
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping OEM as interactive
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping TimeZone as interactive
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Install as interactive
2023-10-11 03:36:42,161 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Updates as interactive
2023-10-11 03:36:42,161 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 
2023-10-11 03:36:42,161 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,162 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Shutdown as interactive
2023-10-11 03:36:42,162 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 
2023-10-11 03:36:42,162 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'drivers', 'ssh', 'identity', 'ubuntu_pro', 'snaplist'}
2023-10-11 03:36:42,162 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 
2023-10-11 03:36:42,162 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 
2023-10-11 03:36:42,173 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2023-10-11 03:36:42,174 DEBUG subiquitycore.utils:121 arun_command called: ['/usr/sbin/realm', 'discover']
2023-10-11 03:36:42,210 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 
2023-10-11 03:36:42,210 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 
2023-10-11 03:36:42,210 DEBUG root:30 start: subiquity/Install/install: 
2023-10-11 03:36:42,211 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps
2023-10-11 03:36:42,277 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1560
2023-10-11 03:36:42,348 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-10-11 03:36:42,348 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2023-10-11 03:36:42,348 DEBUG root:30 start: subiquity/SnapList/loader: 
2023-10-11 03:36:42,348 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-10-11 03:36:42,349 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled
2023-10-11 03:36:42,349 DEBUG root:30 start: subiquity/SnapList/loader/list: 
2023-10-11 03:36:42,351 DEBUG asyncio:54 Using selector: EpollSelector
2023-10-11 03:36:42,362 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.bca6e31c'
2023-10-11 03:36:42,363 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info
2023-10-11 03:36:42,363 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 
2023-10-11 03:36:42,372 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:42,372 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-10-11 03:36:42,373 DEBUG subiquitycore.utils:135 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1
2023-10-11 03:36:42,377 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:42,378 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-10-11 03:36:42,378 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:42,378 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-10-11 03:36:42,378 INFO root:30 start: subiquity/Meta/client_variant_POST: 
2023-10-11 03:36:42,378 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null
2023-10-11 03:36:42,379 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:42,380 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 
2023-10-11 03:36:42,380 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null
2023-10-11 03:36:42,380 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:36:42,382 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2023-10-11 03:36:42,383 DEBUG root:30 start: subiquity/Locale/GET: 
2023-10-11 03:36:42,383 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8"
2023-10-11 03:36:42,383 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2023-10-11 03:36:42,383 DEBUG subiquity.models.subiquity:256 model ubuntu_pro for postinstall stage is configured, to go {'network', 'timezone', 'drivers', 'ssh', 'identity', 'codecs', 'snaplist'}
2023-10-11 03:36:42,383 DEBUG subiquity.models.subiquity:256 model proxy for install stage is configured, to go {'network', 'mirror', 'keyboard', 'source', 'filesystem'}
2023-10-11 03:36:42,384 DEBUG subiquity.models.subiquity:256 model mirror for install stage is configured, to go {'network', 'filesystem', 'source', 'keyboard'}
2023-10-11 03:36:42,384 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'network', 'timezone', 'drivers', 'identity', 'codecs', 'snaplist'}
2023-10-11 03:36:42,384 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'network', 'timezone', 'drivers', 'identity', 'codecs'}
2023-10-11 03:36:42,384 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2023-10-11 03:36:42,655 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-10-11 03:36:42,657 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-10-11 03:36:42,763 DEBUG probert.dasd:134 Probing DASD devies
2023-10-11 03:36:42,764 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-10-11 03:36:42,888 DEBUG root:30 start: subiquity/Refresh/GET: 
2023-10-11 03:36:43,465 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0
2023-10-11 03:36:43,466 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem volume name:   <none>
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Last mounted on:          /boot
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem UUID:          fae25d8a-a32c-444f-b68c-9564dd9d7951
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem magic number:  0xEF53
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem revision #:    1 (dynamic)
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem features:      has_journal ext_attr resize_inode dir_index filetype extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem flags:         signed_directory_hash 
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Default mount options:    user_xattr acl
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem state:         clean
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Errors behavior:          Continue
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Filesystem OS type:       Linux
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Inode count:              131072
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Block count:              524288
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Reserved block count:     26214
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Overhead clusters:        26150
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Free blocks:              464667
2023-10-11 03:36:43,466 DEBUG probert.utils:50 Free inodes:              130755
2023-10-11 03:36:43,467 DEBUG probert.utils:50 First block:              0
2023-10-11 03:36:43,467 DEBUG probert.utils:50 Block size:               4096
2023-10-11 03:36:43,467 DEBUG probert.utils:50 Fragment size:            4096
2023-10-11 03:36:43,467 DEBUG probert.utils:50 Group descriptor size:    64
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Reserved GDT blocks:      255
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Blocks per group:         32768
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Fragments per group:      32768
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Inodes per group:         8192
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Inode blocks per group:   512
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Flex block group size:    16
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Filesystem created:       Tue Oct 10 11:28:01 2023
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Last mount time:          Tue Oct 10 11:33:01 2023
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Last write time:          Tue Oct 10 11:35:18 2023
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Mount count:              2
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Maximum mount count:      -1
2023-10-11 03:36:43,468 DEBUG probert.utils:50 Last checked:             Tue Oct 10 11:28:01 2023
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Check interval:           0 (<none>)
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Lifetime writes:          276 MB
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Reserved blocks uid:      0 (user root)
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Reserved blocks gid:      0 (group root)
2023-10-11 03:36:43,470 DEBUG probert.utils:50 First inode:              11
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Inode size:	          256
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Required extra isize:     32
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Desired extra isize:      32
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal inode:            8
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Default directory hash:   half_md4
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Directory Hash Seed:      089c0956-f64f-480a-a3b3-a49462ba5745
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal backup:           inode blocks
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Checksum type:            crc32c
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Checksum:                 0x01f3858a
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal features:         journal_64bit journal_checksum_v3
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Total journal size:       64M
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Total journal blocks:     16384
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Max transaction length:   16384
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Fast commit length:       0
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal sequence:         0x00000146
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal start:            0
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal checksum type:    crc32c
2023-10-11 03:36:43,470 DEBUG probert.utils:50 Journal checksum:         0x33b77eaf
2023-10-11 03:36:43,470 DEBUG probert.utils:50 
2023-10-11 03:36:43,470 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:36:43,470 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:36:43,470 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:36:43,493 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0
2023-10-11 03:36:43,493 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:36:43,493 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 60709
2023-10-11 03:36:43,493 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:36:43,493 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:36:43,493 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:36:44,531 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 200 59
2023-10-11 03:36:44,532 DEBUG subiquity.server.controllers.refresh:201 check_for_update received []
2023-10-11 03:36:44,533 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: no new version of snap available
2023-10-11 03:36:44,533 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.bca6e31c", "ne...
2023-10-11 03:36:44,666 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 200 None
2023-10-11 03:36:44,673 DEBUG root:30 finish: subiquity/SnapList/loader/list: SUCCESS: 
2023-10-11 03:36:44,674 DEBUG subiquity.server.controllers.snaplist:92 fetched list of 22 snaps
2023-10-11 03:36:44,674 DEBUG root:30 start: subiquity/SnapList/loader/fetch/microk8s: 
2023-10-11 03:36:44,847 DEBUG curtin:1325 Extracting storage config from probe data
2023-10-11 03:36:44,848 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:36:44,848 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-10-11 03:36:44,848 DEBUG curtin:73 /dev/sda is multipath device member? False
2023-10-11 03:36:44,848 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:36:44,848 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:36:44,848 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:36:44,848 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:36:44,867 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:36:44,867 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:36:44,867 DEBUG curtin:61 /dev/sda1 is multipath device? False
2023-10-11 03:36:44,867 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:36:44,867 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:36:44,882 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:36:44,882 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:36:44,882 DEBUG curtin:61 /dev/sda2 is multipath device? False
2023-10-11 03:36:44,882 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:36:44,882 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:36:44,891 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:36:44,891 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:36:44,891 DEBUG curtin:61 /dev/sda3 is multipath device? False
2023-10-11 03:36:44,891 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:36:44,891 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:36:44,900 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:36:44,900 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:36:44,908 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:36:44,917 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:36:44,927 DEBUG curtin:1332 Sorting extracted configurations
2023-10-11 03:36:44,927 INFO curtin:1351 Validating extracted storage config components
2023-10-11 03:36:44,951 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-sda
    path: /dev/sda
    ptable: gpt
    serial: QEMU_HARDDISK_QM00003
    type: disk
-   device: disk-sda
    flag: boot
    id: partition-sda1
    number: 1
    offset: 1048576
    partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
    path: /dev/sda1
    size: 1127219200
    type: partition
    uuid: a4d92113-3f26-4a74-b067-fd3f86749584
-   device: disk-sda
    flag: linux
    id: partition-sda2
    number: 2
    offset: 1128267776
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda2
    size: 2147483648
    type: partition
    uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
-   device: disk-sda
    flag: linux
    id: partition-sda3
    number: 3
    offset: 3275751424
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda3
    size: 28935454720
    type: partition
    uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
-   fstype: vfat
    id: format-partition-sda1
    type: format
    volume: partition-sda1
-   fstype: crypto_LUKS
    id: format-partition-sda3
    preserve: true
    type: format
    uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
    volume: partition-sda3
-   fstype: ext4
    id: format-partition-sda2
    type: format
    uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
    volume: partition-sda2

2023-10-11 03:36:44,951 DEBUG curtin:1372 Generating storage config dependencies
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: format-partition-sda3:SourceType:format -> (DepId:partition-sda3 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,951 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:36:44,952 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:36:44,952 DEBUG curtin:1378 Merging storage config dependencies
2023-10-11 03:36:44,954 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-sda
        path: /dev/sda
        ptable: gpt
        serial: QEMU_HARDDISK_QM00003
        type: disk
    -   device: disk-sda
        flag: boot
        id: partition-sda1
        number: 1
        offset: 1048576
        partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
        path: /dev/sda1
        size: 1127219200
        type: partition
        uuid: a4d92113-3f26-4a74-b067-fd3f86749584
    -   device: disk-sda
        flag: linux
        id: partition-sda2
        number: 2
        offset: 1128267776
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda2
        size: 2147483648
        type: partition
        uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
    -   device: disk-sda
        flag: linux
        id: partition-sda3
        number: 3
        offset: 3275751424
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda3
        size: 28935454720
        type: partition
        uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
    -   fstype: vfat
        id: format-partition-sda1
        type: format
        volume: partition-sda1
    -   fstype: ext4
        id: format-partition-sda2
        type: format
        uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
        volume: partition-sda2
    -   fstype: crypto_LUKS
        id: format-partition-sda3
        preserve: true
        type: format
        uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
        volume: partition-sda3
    version: 2

2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='QEMU_HARDDISK_QM00003', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:1': Partition(device=disk-sda, size=1127219200, flag='boot', number=1, preserve=True, offset=1048576, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sda1', uuid='a4d92113-3f26-4a74-b067-fd3f86749584', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=2147483648, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='aa3b7693-3951-40cb-bac4-30debb6fdc9e', id='partition-sda2', type='partition'), '8:3': Partition(device=disk-sda, size=28935454720, flag='linux', number=3, preserve=True, offset=3275751424, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda3', uuid='e26de0b8-3adc-4514-a9e6-a01c08d1ea91', id='partition-sda3', type='partition')}
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 11:0
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 0:45
2023-10-11 03:36:44,954 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:49
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:47
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:63
2023-10-11 03:36:44,955 DEBUG subiquity.models.filesystem:1475 considering mount of 0:64
2023-10-11 03:36:44,956 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-10-11 03:36:44,956 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 2.6 seconds
2023-10-11 03:36:44,956 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor
2023-10-11 03:36:44,956 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-10-11 03:36:45,717 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=microk8s HTTP/1.1" 200 None
2023-10-11 03:36:45,725 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/microk8s: SUCCESS: 
2023-10-11 03:36:45,725 DEBUG root:30 start: subiquity/SnapList/loader/fetch/nextcloud: 
2023-10-11 03:36:46,253 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=nextcloud HTTP/1.1" 200 None
2023-10-11 03:36:46,254 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/nextcloud: SUCCESS: 
2023-10-11 03:36:46,254 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wekan: 
2023-10-11 03:36:46,677 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wekan HTTP/1.1" 200 None
2023-10-11 03:36:46,678 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wekan: SUCCESS: 
2023-10-11 03:36:46,678 DEBUG root:30 start: subiquity/SnapList/loader/fetch/kata-containers: 
2023-10-11 03:36:47,107 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=kata-containers HTTP/1.1" 200 None
2023-10-11 03:36:47,108 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/kata-containers: SUCCESS: 
2023-10-11 03:36:47,108 DEBUG root:30 start: subiquity/SnapList/loader/fetch/docker: 
2023-10-11 03:36:47,531 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=docker HTTP/1.1" 200 None
2023-10-11 03:36:47,532 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/docker: SUCCESS: 
2023-10-11 03:36:47,532 DEBUG root:30 start: subiquity/SnapList/loader/fetch/canonical-livepatch: 
2023-10-11 03:36:47,955 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=canonical-livepatch HTTP/1.1" 200 None
2023-10-11 03:36:47,957 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/canonical-livepatch: SUCCESS: 
2023-10-11 03:36:47,957 DEBUG root:30 start: subiquity/SnapList/loader/fetch/rocketchat-server: 
2023-10-11 03:36:48,422 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=rocketchat-server HTTP/1.1" 200 None
2023-10-11 03:36:48,423 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/rocketchat-server: SUCCESS: 
2023-10-11 03:36:48,423 DEBUG root:30 start: subiquity/SnapList/loader/fetch/mosquitto: 
2023-10-11 03:36:48,813 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=mosquitto HTTP/1.1" 200 None
2023-10-11 03:36:48,814 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/mosquitto: SUCCESS: 
2023-10-11 03:36:48,814 DEBUG root:30 start: subiquity/SnapList/loader/fetch/etcd: 
2023-10-11 03:36:49,310 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=etcd HTTP/1.1" 200 None
2023-10-11 03:36:49,311 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/etcd: SUCCESS: 
2023-10-11 03:36:49,311 DEBUG root:30 start: subiquity/SnapList/loader/fetch/powershell: 
2023-10-11 03:36:49,740 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=powershell HTTP/1.1" 200 None
2023-10-11 03:36:49,741 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/powershell: SUCCESS: 
2023-10-11 03:36:49,741 DEBUG root:30 start: subiquity/SnapList/loader/fetch/sabnzbd: 
2023-10-11 03:36:50,156 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=sabnzbd HTTP/1.1" 200 None
2023-10-11 03:36:50,156 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/sabnzbd: SUCCESS: 
2023-10-11 03:36:50,156 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wormhole: 
2023-10-11 03:36:50,628 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wormhole HTTP/1.1" 200 None
2023-10-11 03:36:50,629 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wormhole: SUCCESS: 
2023-10-11 03:36:50,629 DEBUG root:30 start: subiquity/SnapList/loader/fetch/aws-cli: 
2023-10-11 03:36:51,064 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=aws-cli HTTP/1.1" 200 None
2023-10-11 03:36:51,064 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/aws-cli: SUCCESS: 
2023-10-11 03:36:51,065 DEBUG root:30 start: subiquity/SnapList/loader/fetch/google-cloud-sdk: 
2023-10-11 03:36:51,512 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=google-cloud-sdk HTTP/1.1" 200 1799
2023-10-11 03:36:51,513 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/google-cloud-sdk: SUCCESS: 
2023-10-11 03:36:51,513 DEBUG root:30 start: subiquity/SnapList/loader/fetch/slcli: 
2023-10-11 03:36:51,616 DEBUG root:30 start: subiquity/Locale/POST: 
2023-10-11 03:36:51,616 DEBUG subiquity.server.controllers.locale:68 en_US.UTF-8
2023-10-11 03:36:51,617 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'network', 'timezone', 'drivers', 'identity', 'codecs'}
2023-10-11 03:36:51,617 DEBUG root:30 finish: subiquity/Locale/POST: SUCCESS: 200 null
2023-10-11 03:36:51,617 DEBUG subiquitycore.utils:121 arun_command called: ['localectl', 'set-locale', 'en_US.UTF-8']
2023-10-11 03:36:51,964 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=slcli HTTP/1.1" 200 None
2023-10-11 03:36:51,965 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/slcli: SUCCESS: 
2023-10-11 03:36:51,965 DEBUG root:30 start: subiquity/SnapList/loader/fetch/doctl: 
2023-10-11 03:36:52,227 DEBUG subiquitycore.utils:135 arun_command ['localectl', 'set-locale', 'en_US.UTF-8'] exited with code 0
2023-10-11 03:36:52,465 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=doctl HTTP/1.1" 200 None
2023-10-11 03:36:52,466 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/doctl: SUCCESS: 
2023-10-11 03:36:52,466 DEBUG root:30 start: subiquity/SnapList/loader/fetch/conjure-up: 
2023-10-11 03:36:52,892 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=conjure-up HTTP/1.1" 200 None
2023-10-11 03:36:52,893 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/conjure-up: SUCCESS: 
2023-10-11 03:36:52,893 DEBUG root:30 start: subiquity/SnapList/loader/fetch/postgresql10: 
2023-10-11 03:36:53,315 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=postgresql10 HTTP/1.1" 200 1523
2023-10-11 03:36:53,315 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/postgresql10: SUCCESS: 
2023-10-11 03:36:53,316 DEBUG root:30 start: subiquity/SnapList/loader/fetch/heroku: 
2023-10-11 03:36:53,761 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=heroku HTTP/1.1" 200 None
2023-10-11 03:36:53,762 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/heroku: SUCCESS: 
2023-10-11 03:36:53,762 DEBUG root:30 start: subiquity/SnapList/loader/fetch/keepalived: 
2023-10-11 03:36:54,268 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=keepalived HTTP/1.1" 200 None
2023-10-11 03:36:54,269 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/keepalived: SUCCESS: 
2023-10-11 03:36:54,269 DEBUG root:30 start: subiquity/SnapList/loader/fetch/prometheus: 
2023-10-11 03:36:54,736 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=prometheus HTTP/1.1" 200 None
2023-10-11 03:36:54,737 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/prometheus: SUCCESS: 
2023-10-11 03:36:54,737 DEBUG root:30 start: subiquity/SnapList/loader/fetch/juju: 
2023-10-11 03:36:55,574 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=juju HTTP/1.1" 200 None
2023-10-11 03:36:55,575 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/juju: SUCCESS: 
2023-10-11 03:36:55,575 DEBUG root:30 finish: subiquity/SnapList/loader: SUCCESS: 
2023-10-11 03:36:56,875 DEBUG subiquity.server.controllers.integrity:61 casper-md5check results: {'checksum_missmatch': [], 'result': 'pass'}
2023-10-11 03:37:48,543 DEBUG root:30 start: subiquity/Filesystem/has_rst_GET: 
2023-10-11 03:37:48,544 DEBUG root:30 finish: subiquity/Filesystem/has_rst_GET: SUCCESS: 200 false
2023-10-11 03:37:48,547 DEBUG root:30 start: subiquity/Keyboard/GET: 
2023-10-11 03:37:48,557 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2023-10-11 03:37:48,562 DEBUG root:30 start: subiquity/Keyboard/GET: 
2023-10-11 03:37:48,570 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2023-10-11 03:37:48,573 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 
2023-10-11 03:37:48,574 DEBUG subiquitycore.utils:121 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-10-11 03:37:48,627 DEBUG subiquitycore.utils:135 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-10-11 03:37:48,628 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null
2023-10-11 03:37:50,847 DEBUG root:30 start: subiquity/Keyboard/POST: 
2023-10-11 03:37:50,847 DEBUG subiquity.server.controllers.keyboard:221 KeyboardSetting(layout='us', variant='', toggle=None)
2023-10-11 03:37:50,848 DEBUG subiquity.models.subiquity:256 model keyboard for install stage is configured, to go {'network', 'filesystem', 'source'}
2023-10-11 03:37:50,848 DEBUG root:30 finish: subiquity/Keyboard/POST: SUCCESS: 200 null
2023-10-11 03:37:52,663 DEBUG root:30 start: subiquity/Refresh/GET: 
2023-10-11 03:37:52,663 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.bca6e31c", "ne...
2023-10-11 03:37:52,664 DEBUG root:30 start: subiquity/Source/GET: 
2023-10-11 03:37:52,665 DEBUG root:30 finish: subiquity/Source/GET: SUCCESS: 200 {"sources": [{"name": "Ubuntu Desktop (minimized)", "description": "A minimal...
2023-10-11 03:37:52,666 DEBUG root:30 start: subiquity/Drivers/GET: 
2023-10-11 03:37:52,666 DEBUG root:30 finish: subiquity/Drivers/GET: SUCCESS: 200 {"install": false, "drivers": null, "local_only": true, "search_drivers": false}
2023-10-11 03:37:52,666 DEBUG root:30 start: subiquity/Codecs/GET: 
2023-10-11 03:37:52,666 DEBUG root:30 finish: subiquity/Codecs/GET: SUCCESS: 200 {"install": false}
2023-10-11 03:38:03,278 DEBUG root:30 start: subiquity/Source/POST: 
2023-10-11 03:38:03,278 DEBUG subiquity.models.subiquity:256 model source for install stage is configured, to go {'network', 'filesystem'}
2023-10-11 03:38:03,278 DEBUG subiquity.server.controllers.drivers:89 source variant has been set. Querying list of drivers.
2023-10-11 03:38:03,278 DEBUG root:30 finish: subiquity/Source/POST: SUCCESS: 200 null
2023-10-11 03:38:03,278 DEBUG subiquity.server.controllers.filesystem:414 got system None for variation minimal
2023-10-11 03:38:03,279 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.enhanced-secureboot.squashfs', '///cdrom/casper/minimal.enhanced-secureboot.en.squashfs']
2023-10-11 03:38:03,279 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp5_ylu65m/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:03,285 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.squashfs', '/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:03,295 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.en.squashfs', '/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:03,320 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.en.squashfs.dir:/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.squashfs.dir:/tmp/tmp5_ylu65m/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp5_ylu65m/root.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:03,339 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'bind', '/tmp/tmp5_ylu65m/root.dir/var/lib/snapd/seed/systems', '/var/lib/snapd/seed/systems']
2023-10-11 03:38:03,343 DEBUG root:30 start: subiquity/Drivers/_list_drivers: 
2023-10-11 03:38:03,343 DEBUG root:30 start: subiquity/Drivers/_list_drivers/wait_apt: 
2023-10-11 03:38:03,344 DEBUG root:30 start: subiquity/Drivers/POST: 
2023-10-11 03:38:03,344 DEBUG subiquity.models.subiquity:256 model drivers for postinstall stage is configured, to go {'network', 'identity', 'codecs', 'timezone'}
2023-10-11 03:38:03,345 DEBUG root:30 finish: subiquity/Drivers/POST: SUCCESS: 200 null
2023-10-11 03:38:03,345 DEBUG root:30 start: subiquity/Codecs/POST: 
2023-10-11 03:38:03,345 DEBUG subiquity.models.subiquity:256 model codecs for postinstall stage is configured, to go {'network', 'identity', 'timezone'}
2023-10-11 03:38:03,345 DEBUG root:30 finish: subiquity/Codecs/POST: SUCCESS: 200 null
2023-10-11 03:38:03,346 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-10-11 03:38:03,355 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor
2023-10-11 03:38:03,356 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0']
2023-10-11 03:38:03,383 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-10-11 03:38:03,383 DEBUG subiquity.server.controllers.filesystem:1499 Triggered Probert run on udev event
2023-10-11 03:38:03,383 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-10-11 03:38:03,383 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-10-11 03:38:03,385 DEBUG asyncio:54 Using selector: EpollSelector
2023-10-11 03:38:03,396 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'bind', '/tmp/tmp5_ylu65m/root.dir/var/lib/snapd/seed/snaps/pc-kernel_1459.snap', '/var/lib/snapd/seed/snaps/pc-kernel_1459.snap']
2023-10-11 03:38:03,428 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'bind', '/tmp/tmp5_ylu65m/root.dir/var/lib/snapd/seed/snaps/pc_161.snap', '/var/lib/snapd/seed/snaps/pc_161.snap']
2023-10-11 03:38:03,453 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-10-11 03:38:03,455 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-10-11 03:38:03,617 DEBUG probert.dasd:134 Probing DASD devies
2023-10-11 03:38:03,617 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-10-11 03:38:03,985 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0
2023-10-11 03:38:03,986 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem volume name:   <none>
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Last mounted on:          /boot
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem UUID:          fae25d8a-a32c-444f-b68c-9564dd9d7951
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem magic number:  0xEF53
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem revision #:    1 (dynamic)
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem features:      has_journal ext_attr resize_inode dir_index filetype extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem flags:         signed_directory_hash 
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Default mount options:    user_xattr acl
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem state:         clean
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Errors behavior:          Continue
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem OS type:       Linux
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Inode count:              131072
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Block count:              524288
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Reserved block count:     26214
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Overhead clusters:        26150
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Free blocks:              464667
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Free inodes:              130755
2023-10-11 03:38:03,986 DEBUG probert.utils:50 First block:              0
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Block size:               4096
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Fragment size:            4096
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Group descriptor size:    64
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Reserved GDT blocks:      255
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Blocks per group:         32768
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Fragments per group:      32768
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Inodes per group:         8192
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Inode blocks per group:   512
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Flex block group size:    16
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Filesystem created:       Tue Oct 10 11:28:01 2023
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Last mount time:          Tue Oct 10 11:33:01 2023
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Last write time:          Tue Oct 10 11:35:18 2023
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Mount count:              2
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Maximum mount count:      -1
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Last checked:             Tue Oct 10 11:28:01 2023
2023-10-11 03:38:03,986 DEBUG probert.utils:50 Check interval:           0 (<none>)
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Lifetime writes:          276 MB
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Reserved blocks uid:      0 (user root)
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Reserved blocks gid:      0 (group root)
2023-10-11 03:38:03,987 DEBUG probert.utils:50 First inode:              11
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Inode size:	          256
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Required extra isize:     32
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Desired extra isize:      32
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal inode:            8
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Default directory hash:   half_md4
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Directory Hash Seed:      089c0956-f64f-480a-a3b3-a49462ba5745
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal backup:           inode blocks
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Checksum type:            crc32c
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Checksum:                 0x01f3858a
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal features:         journal_64bit journal_checksum_v3
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Total journal size:       64M
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Total journal blocks:     16384
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Max transaction length:   16384
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Fast commit length:       0
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal sequence:         0x00000146
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal start:            0
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal checksum type:    crc32c
2023-10-11 03:38:03,987 DEBUG probert.utils:50 Journal checksum:         0x33b77eaf
2023-10-11 03:38:03,987 DEBUG probert.utils:50 
2023-10-11 03:38:03,987 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:38:03,987 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:38:03,987 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:38:04,005 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0
2023-10-11 03:38:04,005 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:38:04,005 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 60709
2023-10-11 03:38:04,005 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:38:04,005 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:38:04,005 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:38:04,013 DEBUG curtin:1325 Extracting storage config from probe data
2023-10-11 03:38:04,014 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:04,014 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-10-11 03:38:04,014 DEBUG curtin:73 /dev/sda is multipath device member? False
2023-10-11 03:38:04,014 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:04,014 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:04,014 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:04,014 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:04,045 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:04,045 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:04,045 DEBUG curtin:61 /dev/sda1 is multipath device? False
2023-10-11 03:38:04,045 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:04,045 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:04,071 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:04,073 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:04,073 DEBUG curtin:61 /dev/sda2 is multipath device? False
2023-10-11 03:38:04,074 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:04,074 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:04,098 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:04,098 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:04,098 DEBUG curtin:61 /dev/sda3 is multipath device? False
2023-10-11 03:38:04,098 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:04,098 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:04,116 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:04,116 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:04,143 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:04,168 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:04,197 DEBUG curtin:1332 Sorting extracted configurations
2023-10-11 03:38:04,197 INFO curtin:1351 Validating extracted storage config components
2023-10-11 03:38:04,228 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-sda
    path: /dev/sda
    ptable: gpt
    serial: QEMU_HARDDISK_QM00003
    type: disk
-   device: disk-sda
    flag: boot
    id: partition-sda1
    number: 1
    offset: 1048576
    partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
    path: /dev/sda1
    size: 1127219200
    type: partition
    uuid: a4d92113-3f26-4a74-b067-fd3f86749584
-   device: disk-sda
    flag: linux
    id: partition-sda2
    number: 2
    offset: 1128267776
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda2
    size: 2147483648
    type: partition
    uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
-   device: disk-sda
    flag: linux
    id: partition-sda3
    number: 3
    offset: 3275751424
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda3
    size: 28935454720
    type: partition
    uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
-   fstype: vfat
    id: format-partition-sda1
    type: format
    volume: partition-sda1
-   fstype: crypto_LUKS
    id: format-partition-sda3
    preserve: true
    type: format
    uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
    volume: partition-sda3
-   fstype: ext4
    id: format-partition-sda2
    type: format
    uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
    volume: partition-sda2

2023-10-11 03:38:04,228 DEBUG curtin:1372 Generating storage config dependencies
2023-10-11 03:38:04,229 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: format-partition-sda3:SourceType:format -> (DepId:partition-sda3 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:04,237 DEBUG curtin:1378 Merging storage config dependencies
2023-10-11 03:38:04,240 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-sda
        path: /dev/sda
        ptable: gpt
        serial: QEMU_HARDDISK_QM00003
        type: disk
    -   device: disk-sda
        flag: boot
        id: partition-sda1
        number: 1
        offset: 1048576
        partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
        path: /dev/sda1
        size: 1127219200
        type: partition
        uuid: a4d92113-3f26-4a74-b067-fd3f86749584
    -   device: disk-sda
        flag: linux
        id: partition-sda2
        number: 2
        offset: 1128267776
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda2
        size: 2147483648
        type: partition
        uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
    -   device: disk-sda
        flag: linux
        id: partition-sda3
        number: 3
        offset: 3275751424
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda3
        size: 28935454720
        type: partition
        uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
    -   fstype: vfat
        id: format-partition-sda1
        type: format
        volume: partition-sda1
    -   fstype: ext4
        id: format-partition-sda2
        type: format
        uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
        volume: partition-sda2
    -   fstype: crypto_LUKS
        id: format-partition-sda3
        preserve: true
        type: format
        uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
        volume: partition-sda3
    version: 2

2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='QEMU_HARDDISK_QM00003', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:1': Partition(device=disk-sda, size=1127219200, flag='boot', number=1, preserve=True, offset=1048576, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sda1', uuid='a4d92113-3f26-4a74-b067-fd3f86749584', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=2147483648, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='aa3b7693-3951-40cb-bac4-30debb6fdc9e', id='partition-sda2', type='partition'), '8:3': Partition(device=disk-sda, size=28935454720, flag='linux', number=3, preserve=True, offset=3275751424, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda3', uuid='e26de0b8-3adc-4514-a9e6-a01c08d1ea91', id='partition-sda3', type='partition')}
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 11:0
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:45
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89
2023-10-11 03:38:04,249 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:49
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:13
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 7:14
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:47
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:63
2023-10-11 03:38:04,250 DEBUG subiquity.models.filesystem:1475 considering mount of 0:64
2023-10-11 03:38:04,250 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-10-11 03:38:04,251 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 0.9 seconds
2023-10-11 03:38:04,251 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor
2023-10-11 03:38:04,251 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-10-11 03:38:05,594 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/systems/enhanced-secureboot-desktop HTTP/1.1" 200 None
2023-10-11 03:38:05,595 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'umount', '/var/lib/snapd/seed/snaps/pc_161.snap']
2023-10-11 03:38:05,637 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'umount', '/var/lib/snapd/seed/snaps/pc-kernel_1459.snap']
2023-10-11 03:38:05,686 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'umount', '/var/lib/snapd/seed/systems']
2023-10-11 03:38:05,725 DEBUG curtin:95 Running command ['umount', '/tmp/tmp5_ylu65m/root.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:05,732 DEBUG curtin:95 Running command ['umount', '/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:05,735 DEBUG curtin:95 Running command ['umount', '/tmp/tmp5_ylu65m/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:05,766 DEBUG curtin:95 Running command ['umount', '/tmp/tmp5_ylu65m/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:05,772 DEBUG subiquity.server.controllers.filesystem:344 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=3, 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)], update=VolumeUpdate(edition=2, 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.AVAILABLE: 'available'>, storage_safety=<StorageSafety.PREFER_ENCRYPTED: 'prefer-encrypted'>, encryption_type=<EncryptionType.CRYPTSETUP: 'cryptsetup'>, unavailable_reason=''))
2023-10-11 03:38:05,772 DEBUG subiquity.server.controllers.filesystem:414 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=3, 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)], update=VolumeUpdate(edition=2, 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.AVAILABLE: 'available'>, storage_safety=<StorageSafety.PREFER_ENCRYPTED: 'prefer-encrypted'>, encryption_type=<EncryptionType.CRYPTSETUP: 'cryptsetup'>, unavailable_reason='')) for variation minimal-enhanced-secureboot
2023-10-11 03:38:05,773 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:05,782 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:05,782 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor
2023-10-11 03:38:05,783 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0']
2023-10-11 03:38:05,797 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-10-11 03:38:05,797 DEBUG subiquity.server.controllers.filesystem:1499 Triggered Probert run on udev event
2023-10-11 03:38:05,797 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2023-10-11 03:38:05,797 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-10-11 03:38:05,798 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-10-11 03:38:05,798 DEBUG asyncio:54 Using selector: EpollSelector
2023-10-11 03:38:05,817 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2023-10-11 03:38:05,818 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2023-10-11 03:38:05,873 DEBUG probert.dasd:134 Probing DASD devies
2023-10-11 03:38:05,873 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2023-10-11 03:38:06,135 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0
2023-10-11 03:38:06,135 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:38:06,135 DEBUG probert.utils:50 Filesystem volume name:   <none>
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Last mounted on:          /boot
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem UUID:          fae25d8a-a32c-444f-b68c-9564dd9d7951
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem magic number:  0xEF53
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem revision #:    1 (dynamic)
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem features:      has_journal ext_attr resize_inode dir_index filetype extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem flags:         signed_directory_hash 
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Default mount options:    user_xattr acl
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem state:         clean
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Errors behavior:          Continue
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem OS type:       Linux
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Inode count:              131072
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Block count:              524288
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Reserved block count:     26214
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Overhead clusters:        26150
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Free blocks:              464667
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Free inodes:              130755
2023-10-11 03:38:06,136 DEBUG probert.utils:50 First block:              0
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Block size:               4096
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Fragment size:            4096
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Group descriptor size:    64
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Reserved GDT blocks:      255
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Blocks per group:         32768
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Fragments per group:      32768
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Inodes per group:         8192
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Inode blocks per group:   512
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Flex block group size:    16
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Filesystem created:       Tue Oct 10 11:28:01 2023
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Last mount time:          Tue Oct 10 11:33:01 2023
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Last write time:          Tue Oct 10 11:35:18 2023
2023-10-11 03:38:06,136 DEBUG probert.utils:50 Mount count:              2
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Maximum mount count:      -1
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Last checked:             Tue Oct 10 11:28:01 2023
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Check interval:           0 (<none>)
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Lifetime writes:          276 MB
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Reserved blocks uid:      0 (user root)
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Reserved blocks gid:      0 (group root)
2023-10-11 03:38:06,137 DEBUG probert.utils:50 First inode:              11
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Inode size:	          256
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Required extra isize:     32
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Desired extra isize:      32
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal inode:            8
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Default directory hash:   half_md4
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Directory Hash Seed:      089c0956-f64f-480a-a3b3-a49462ba5745
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal backup:           inode blocks
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Checksum type:            crc32c
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Checksum:                 0x01f3858a
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal features:         journal_64bit journal_checksum_v3
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Total journal size:       64M
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Total journal blocks:     16384
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Max transaction length:   16384
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Fast commit length:       0
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal sequence:         0x00000146
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal start:            0
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal checksum type:    crc32c
2023-10-11 03:38:06,137 DEBUG probert.utils:50 Journal checksum:         0x33b77eaf
2023-10-11 03:38:06,137 DEBUG probert.utils:50 
2023-10-11 03:38:06,137 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:38:06,138 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:38:06,138 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:38:06,140 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0
2023-10-11 03:38:06,140 DEBUG probert.utils:48 stdout: ------------------------------------------
2023-10-11 03:38:06,140 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 60709
2023-10-11 03:38:06,140 DEBUG probert.utils:48 stderr: ------------------------------------------
2023-10-11 03:38:06,140 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023)
2023-10-11 03:38:06,140 DEBUG probert.utils:88 --------------------------------------------------
2023-10-11 03:38:06,143 DEBUG curtin:1325 Extracting storage config from probe data
2023-10-11 03:38:06,143 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:06,143 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-10-11 03:38:06,143 DEBUG curtin:73 /dev/sda is multipath device member? False
2023-10-11 03:38:06,143 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:06,143 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:06,143 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:06,143 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:06,152 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:06,152 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:06,152 DEBUG curtin:61 /dev/sda1 is multipath device? False
2023-10-11 03:38:06,153 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:06,153 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:06,161 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:06,161 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:06,161 DEBUG curtin:61 /dev/sda2 is multipath device? False
2023-10-11 03:38:06,161 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:06,161 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:06,169 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:06,169 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:06,170 DEBUG curtin:61 /dev/sda3 is multipath device? False
2023-10-11 03:38:06,170 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:06,170 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:06,178 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:06,178 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:06,187 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:06,195 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:06,204 DEBUG curtin:1332 Sorting extracted configurations
2023-10-11 03:38:06,204 INFO curtin:1351 Validating extracted storage config components
2023-10-11 03:38:06,216 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-sda
    path: /dev/sda
    ptable: gpt
    serial: QEMU_HARDDISK_QM00003
    type: disk
-   device: disk-sda
    flag: boot
    id: partition-sda1
    number: 1
    offset: 1048576
    partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
    path: /dev/sda1
    size: 1127219200
    type: partition
    uuid: a4d92113-3f26-4a74-b067-fd3f86749584
-   device: disk-sda
    flag: linux
    id: partition-sda2
    number: 2
    offset: 1128267776
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda2
    size: 2147483648
    type: partition
    uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
-   device: disk-sda
    flag: linux
    id: partition-sda3
    number: 3
    offset: 3275751424
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda3
    size: 28935454720
    type: partition
    uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
-   fstype: vfat
    id: format-partition-sda1
    type: format
    volume: partition-sda1
-   fstype: crypto_LUKS
    id: format-partition-sda3
    preserve: true
    type: format
    uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
    volume: partition-sda3
-   fstype: ext4
    id: format-partition-sda2
    type: format
    uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
    volume: partition-sda2

2023-10-11 03:38:06,216 DEBUG curtin:1372 Generating storage config dependencies
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: format-partition-sda3:SourceType:format -> (DepId:partition-sda3 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:06,216 DEBUG curtin:1378 Merging storage config dependencies
2023-10-11 03:38:06,218 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-sda
        path: /dev/sda
        ptable: gpt
        serial: QEMU_HARDDISK_QM00003
        type: disk
    -   device: disk-sda
        flag: boot
        id: partition-sda1
        number: 1
        offset: 1048576
        partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
        path: /dev/sda1
        size: 1127219200
        type: partition
        uuid: a4d92113-3f26-4a74-b067-fd3f86749584
    -   device: disk-sda
        flag: linux
        id: partition-sda2
        number: 2
        offset: 1128267776
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda2
        size: 2147483648
        type: partition
        uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
    -   device: disk-sda
        flag: linux
        id: partition-sda3
        number: 3
        offset: 3275751424
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda3
        size: 28935454720
        type: partition
        uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
    -   fstype: vfat
        id: format-partition-sda1
        type: format
        volume: partition-sda1
    -   fstype: ext4
        id: format-partition-sda2
        type: format
        uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
        volume: partition-sda2
    -   fstype: crypto_LUKS
        id: format-partition-sda3
        preserve: true
        type: format
        uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
        volume: partition-sda3
    version: 2

2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='QEMU_HARDDISK_QM00003', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:1': Partition(device=disk-sda, size=1127219200, flag='boot', number=1, preserve=True, offset=1048576, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sda1', uuid='a4d92113-3f26-4a74-b067-fd3f86749584', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=2147483648, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='aa3b7693-3951-40cb-bac4-30debb6fdc9e', id='partition-sda2', type='partition'), '8:3': Partition(device=disk-sda, size=28935454720, flag='linux', number=3, preserve=True, offset=3275751424, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda3', uuid='e26de0b8-3adc-4514-a9e6-a01c08d1ea91', id='partition-sda3', type='partition')}
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 11:0
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:45
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34
2023-10-11 03:38:06,219 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:49
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:47
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:63
2023-10-11 03:38:06,220 DEBUG subiquity.models.filesystem:1475 considering mount of 0:64
2023-10-11 03:38:06,220 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False
2023-10-11 03:38:06,220 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 0.4 seconds
2023-10-11 03:38:06,220 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor
2023-10-11 03:38:06,221 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2023-10-11 03:38:06,221 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:06,222 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:06,223 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2023-10-11 03:38:06,223 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:06,224 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2023-10-11 03:38:06,225 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2023-10-11 03:38:06,225 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2023-10-11 03:38:12,645 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2023-10-11 03:38:12,646 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2023-10-11 03:38:12,647 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-10-11 03:38:12,647 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,648 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:12,649 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2023-10-11 03:38:12,649 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,650 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2023-10-11 03:38:12,652 DEBUG root:30 start: subiquity/Filesystem/v2_guided_POST: 
2023-10-11 03:38:12,652 DEBUG subiquity.server.controllers.filesystem:1152 GuidedChoiceV2(target=GuidedStorageTargetReformat(disk_id='disk-sda', allowed=[<GuidedCapability.DIRECT: 2>, <GuidedCapability.LVM: 3>, <GuidedCapability.LVM_LUKS: 4>, <GuidedCapability.ZFS: 5>, <GuidedCapability.CORE_BOOT_PREFER_ENCRYPTED: 8>], disallowed=[]), capability=<GuidedCapability.DIRECT: 2>, recovery_key=None, sizing_policy=<SizingPolicy.ALL: 2>, reset_partition=False)
2023-10-11 03:38:12,652 DEBUG subiquity.models.filesystem:2105 adding fat32 to Partition(device=disk-sda, size=1127219200, wipe='superblock', flag='boot', number=1, grub_device=True, offset=1048576, id='partition-0')
2023-10-11 03:38:12,653 DEBUG subiquity.models.filesystem:2105 adding ext4 to Partition(device=disk-sda, size=31082938368, wipe='superblock', number=2, grub_device=None, offset=1128267776, id='partition-1')
2023-10-11 03:38:12,653 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,653 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": {"target": {"disk_id":...
2023-10-11 03:38:12,655 DEBUG root:30 start: subiquity/Filesystem/v2_POST: 
2023-10-11 03:38:12,655 DEBUG subiquity.models.subiquity:256 model filesystem for install stage is configured, to go {'network'}
2023-10-11 03:38:12,655 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor
2023-10-11 03:38:12,655 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,656 DEBUG root:30 finish: subiquity/Filesystem/v2_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:12,659 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2023-10-11 03:38:12,659 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,661 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:12,663 DEBUG root:30 start: subiquity/Filesystem/v2_orig_config_GET: 
2023-10-11 03:38:12,663 DEBUG curtin:1325 Extracting storage config from probe data
2023-10-11 03:38:12,663 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:12,663 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2023-10-11 03:38:12,663 DEBUG curtin:73 /dev/sda is multipath device member? False
2023-10-11 03:38:12,663 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:12,663 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:12,663 DEBUG curtin:86 /dev/sda is multipath device partition? False
2023-10-11 03:38:12,663 DEBUG curtin:61 /dev/sda is multipath device? False
2023-10-11 03:38:12,682 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:12,682 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:12,682 DEBUG curtin:61 /dev/sda1 is multipath device? False
2023-10-11 03:38:12,682 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:12,682 DEBUG curtin:86 /dev/sda1 is multipath device partition? False
2023-10-11 03:38:12,697 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:12,697 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:12,697 DEBUG curtin:61 /dev/sda2 is multipath device? False
2023-10-11 03:38:12,697 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:12,697 DEBUG curtin:86 /dev/sda2 is multipath device partition? False
2023-10-11 03:38:12,713 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:12,714 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:12,714 DEBUG curtin:61 /dev/sda3 is multipath device? False
2023-10-11 03:38:12,714 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:12,714 DEBUG curtin:86 /dev/sda3 is multipath device partition? False
2023-10-11 03:38:12,723 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2023-10-11 03:38:12,723 DEBUG curtin:73 /dev/sda1 is multipath device member? False
2023-10-11 03:38:12,731 DEBUG curtin:73 /dev/sda3 is multipath device member? False
2023-10-11 03:38:12,740 DEBUG curtin:73 /dev/sda2 is multipath device member? False
2023-10-11 03:38:12,748 DEBUG curtin:1332 Sorting extracted configurations
2023-10-11 03:38:12,748 INFO curtin:1351 Validating extracted storage config components
2023-10-11 03:38:12,759 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-sda
    path: /dev/sda
    ptable: gpt
    serial: QEMU_HARDDISK_QM00003
    type: disk
-   device: disk-sda
    flag: boot
    id: partition-sda1
    number: 1
    offset: 1048576
    partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
    path: /dev/sda1
    size: 1127219200
    type: partition
    uuid: a4d92113-3f26-4a74-b067-fd3f86749584
-   device: disk-sda
    flag: linux
    id: partition-sda2
    number: 2
    offset: 1128267776
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda2
    size: 2147483648
    type: partition
    uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
-   device: disk-sda
    flag: linux
    id: partition-sda3
    number: 3
    offset: 3275751424
    partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
    path: /dev/sda3
    size: 28935454720
    type: partition
    uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
-   fstype: vfat
    id: format-partition-sda1
    type: format
    volume: partition-sda1
-   fstype: crypto_LUKS
    id: format-partition-sda3
    preserve: true
    type: format
    uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
    volume: partition-sda3
-   fstype: ext4
    id: format-partition-sda2
    type: format
    uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
    volume: partition-sda2

2023-10-11 03:38:12,759 DEBUG curtin:1372 Generating storage config dependencies
2023-10-11 03:38:12,759 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,759 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,759 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,759 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:12,759 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,760 DEBUG curtin:238 Validate: format-partition-sda3:SourceType:format -> (DepId:partition-sda3 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:12,760 DEBUG curtin:238 Validate: partition-sda3:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,760 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'partition', 'dm_crypt', 'bcache', 'raid', 'lvm_partition', 'disk'} ? result=True
2023-10-11 03:38:12,760 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'bcache', 'raid', 'partition', 'disk'} ? result=True
2023-10-11 03:38:12,760 DEBUG curtin:1378 Merging storage config dependencies
2023-10-11 03:38:12,762 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-sda
        path: /dev/sda
        ptable: gpt
        serial: QEMU_HARDDISK_QM00003
        type: disk
    -   device: disk-sda
        flag: boot
        id: partition-sda1
        number: 1
        offset: 1048576
        partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b
        path: /dev/sda1
        size: 1127219200
        type: partition
        uuid: a4d92113-3f26-4a74-b067-fd3f86749584
    -   device: disk-sda
        flag: linux
        id: partition-sda2
        number: 2
        offset: 1128267776
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda2
        size: 2147483648
        type: partition
        uuid: aa3b7693-3951-40cb-bac4-30debb6fdc9e
    -   device: disk-sda
        flag: linux
        id: partition-sda3
        number: 3
        offset: 3275751424
        partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4
        path: /dev/sda3
        size: 28935454720
        type: partition
        uuid: e26de0b8-3adc-4514-a9e6-a01c08d1ea91
    -   fstype: vfat
        id: format-partition-sda1
        type: format
        volume: partition-sda1
    -   fstype: ext4
        id: format-partition-sda2
        type: format
        uuid: fae25d8a-a32c-444f-b68c-9564dd9d7951
        volume: partition-sda2
    -   fstype: crypto_LUKS
        id: format-partition-sda3
        preserve: true
        type: format
        uuid: 15c4a59a-22ff-4177-baff-8456dfc01a99
        volume: partition-sda3
    version: 2

2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='QEMU_HARDDISK_QM00003', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:1': Partition(device=disk-sda, size=1127219200, flag='boot', number=1, preserve=True, offset=1048576, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sda1', uuid='a4d92113-3f26-4a74-b067-fd3f86749584', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=2147483648, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='aa3b7693-3951-40cb-bac4-30debb6fdc9e', id='partition-sda2', type='partition'), '8:3': Partition(device=disk-sda, size=28935454720, flag='linux', number=3, preserve=True, offset=3275751424, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda3', uuid='e26de0b8-3adc-4514-a9e6-a01c08d1ea91', id='partition-sda3', type='partition')}
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 11:0
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 0:45
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:12,762 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:29
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:49
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:47
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:63
2023-10-11 03:38:12,763 DEBUG subiquity.models.filesystem:1475 considering mount of 0:64
2023-10-11 03:38:12,763 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.325G
2023-10-11 03:38:12,765 DEBUG root:30 finish: subiquity/Filesystem/v2_orig_config_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"...
2023-10-11 03:38:14,741 DEBUG root:30 start: subiquity/TimeZone/GET: 
2023-10-11 03:38:14,741 DEBUG root:30 finish: subiquity/TimeZone/GET: SUCCESS: 200 {"timezone": "None", "from_geoip": true}
2023-10-11 03:38:14,945 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2023-10-11 03:38:14,945 DEBUG subiquitycore.models.network:467 has_network True
2023-10-11 03:38:14,946 DEBUG subiquity.models.subiquity:256 model network for install stage is configured, to go set()
2023-10-11 03:38:14,946 DEBUG subiquity.models.subiquity:256 model network for postinstall stage is configured, to go {'identity', 'timezone'}
2023-10-11 03:38:14,946 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2023-10-11 03:38:14,948 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "NEEDS_CONFIRMATION", "confirming_tty": "", "error": null, "cloud_i...
2023-10-11 03:38:14,949 INFO root:30 start: subiquity/Meta/confirm_POST: 
2023-10-11 03:38:14,949 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'identity', 'timezone'}
2023-10-11 03:38:14,949 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'identity', 'timezone'}
2023-10-11 03:38:14,949 INFO root:30 finish: subiquity/Meta/confirm_POST: SUCCESS: 200 null
2023-10-11 03:38:14,950 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_confirmation: SUCCESS: 
2023-10-11 03:38:14,950 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_apt: 
2023-10-11 03:38:14,950 INFO root:30 start: subiquity/Install/install/configure_apt: configuring apt
2023-10-11 03:38:14,951 DEBUG root:30 start: subiquity/Mirror/waiting: 
2023-10-11 03:38:14,951 DEBUG root:30 finish: subiquity/Mirror/waiting: SUCCESS: 
2023-10-11 03:38:14,951 DEBUG subiquity.server.controllers.mirror:202 Iterating over country-mirror
2023-10-11 03:38:14,951 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.en.squashfs']
2023-10-11 03:38:14,951 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmpq1m9q86e/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:14,963 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.en.squashfs', '/tmp/tmpq1m9q86e/minimal.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:14,981 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmpq1m9q86e/minimal.en.squashfs.dir:/tmp/tmpq1m9q86e/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmpq1m9q86e/root.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:14,985 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'lowerdir=/tmp/tmpq1m9q86e/root.dir,upperdir=/tmp/tmp6ouhts6a/upper,workdir=/tmp/tmp6ouhts6a/work', '-t', 'overlay', 'overlay', '/tmp/tmp6ouhts6a/mount']
2023-10-11 03:38:14,987 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:38:14,987 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2023-10-11 03:38:14,991 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:38:15,032 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2060.1"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmp6ouhts6a/mount']
2023-10-11 03:38:16,452 DEBUG root:30 start: subiquity/Mirror/cmd-apt-config: curtin command apt-config
2023-10-11 03:38:16,885 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain
2023-10-11 03:38:16,985 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain
2023-10-11 03:38:17,086 DEBUG subiquity.server.curtin:130 waited 0.30000000000000004 seconds for events to drain
2023-10-11 03:38:17,125 DEBUG root:30 finish: subiquity/Mirror/cmd-apt-config: SUCCESS: curtin command apt-config
2023-10-11 03:38:17,187 DEBUG subiquity.server.curtin:130 waited 0.4 seconds for events to drain
2023-10-11 03:38:17,190 DEBUG subiquitycore.utils:154 astart_command called: ['apt-get', 'update', '-oAPT::Update::Error-Mode=any', '-oAPT::Sandbox::User=root', '-oAcquire::IndexTargets::deb::Packages::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::Translations::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11-icons-small::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11-icons::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11-icons-hidpi::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11-icons-large::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::DEP-11-icons-large-hidpi::DefaultEnabled=false', '-oAcquire::IndexTargets::deb::CNF::DefaultEnabled=false', '-oAcquire::IndexTargets::deb-src::Sources::DefaultEnabled=false']
2023-10-11 03:38:18,448 DEBUG root:30 start: subiquity/TimeZone/POST: 
2023-10-11 03:38:18,591 DEBUG subiquity.models.subiquity:256 model timezone for postinstall stage is configured, to go {'identity'}
2023-10-11 03:38:18,591 DEBUG root:30 finish: subiquity/TimeZone/POST: SUCCESS: 200 null
2023-10-11 03:38:18,592 DEBUG root:30 start: subiquity/Identity/GET: 
2023-10-11 03:38:18,592 DEBUG root:30 finish: subiquity/Identity/GET: SUCCESS: 200 {"realname": "", "username": "", "crypted_password": "", "hostname": ""}
2023-10-11 03:38:18,593 DEBUG root:30 start: subiquity/Ad/has_support_GET: 
2023-10-11 03:38:18,593 DEBUG root:30 finish: subiquity/Ad/has_support_GET: SUCCESS: 200 true
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:176 Mirror checking successful
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:178 APT output follows
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:180 Hit:1 http://nz.archive.ubuntu.com/ubuntu mantic InRelease
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:180 Hit:2 http://nz.archive.ubuntu.com/ubuntu mantic-updates InRelease
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:180 Get:3 http://nz.archive.ubuntu.com/ubuntu mantic-backports InRelease [90.7 kB]
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:180 Fetched 90.7 kB in 0s (195 kB/s)
2023-10-11 03:38:20,242 DEBUG subiquity.server.controllers.mirror:180 Reading package lists...
2023-10-11 03:38:20,242 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.en.squashfs']
2023-10-11 03:38:20,242 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp8wnn6xp1/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:20,246 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.en.squashfs', '/tmp/tmp8wnn6xp1/minimal.en.squashfs.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:20,260 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp8wnn6xp1/minimal.en.squashfs.dir:/tmp/tmp8wnn6xp1/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp8wnn6xp1/root.dir'] with allowed return codes [0] (capture=True)
2023-10-11 03:38:20,268 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'lowerdir=/tmp/tmp8wnn6xp1/root.dir,upperdir=/tmp/tmpgylfes8t/upper,workdir=/tmp/tmpgylfes8t/work', '-t', 'overlay', 'overlay', '/tmp/tmpgylfes8t/mount']
2023-10-11 03:38:20,310 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2060.2"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmpgylfes8t/mount']
2023-10-11 03:38:21,070 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'lowerdir=/tmp/tmpgylfes8t/upper:/tmp/tmp8wnn6xp1/root.dir,upperdir=/tmp/tmp71369fw6/upper,workdir=/tmp/tmp71369fw6/work', '-t', 'overlay', 'overlay', '/tmp/tmp71369fw6/mount']
2023-10-11 03:38:21,102 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', 'mount', '-o', 'bind', '/cdrom', '/tmp/tmp71369fw6/mount/cdrom']
2023-10-11 03:38:21,118 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2060.3"}}', 'in-target', '-t', '/tmp/tmp71369fw6/mount', '--', 'apt-get', 'update']
2023-10-11 03:38:22,125 DEBUG root:30 start: subiquity/Install/install/configure_apt/cmd-in-target: curtin command in-target
2023-10-11 03:38:22,610 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2023-10-11 03:38:22,611 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2023-10-11 03:38:22,897 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2023-10-11 03:38:22,897 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2023-10-11 03:38:23,088 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2023-10-11 03:38:23,089 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2023-10-11 03:38:23,345 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2023-10-11 03:38:23,345 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2023-10-11 03:38:39,030 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2023-10-11 03:38:39,030 DEBUG subiquity.models.subiquity:256 model active_directory for postinstall stage is configured, to go {'identity'}
2023-10-11 03:38:39,031 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2023-10-11 03:38:39,061 DEBUG root:30 start: subiquity/Identity/POST: 
2023-10-11 03:38:39,061 DEBUG subiquity.models.subiquity:256 model identity for postinstall stage is configured, to go set()
2023-10-11 03:38:39,061 DEBUG root:30 finish: subiquity/Identity/POST: SUCCESS: 200 null
2023-10-11 03:38:41,107 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:38:41,107 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2023-10-11 03:38:41,378 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:38:41,378 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2023-10-11 03:38:41,411 INFO root:30 start: subiquity/Meta/status_GET: 
2023-10-11 03:38:46,230 ERROR root:30 finish: subiquity/Install/install/configure_apt: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2060.3"}}', 'in-target', '-t', '/tmp/tmp71369fw6/mount', '--', 'apt-get', 'update']' returned non-zero exit status 100.
2023-10-11 03:38:46,230 DEBUG subiquity.common.errorreport:394 generating crash report
2023-10-11 03:38:46,267 INFO subiquity.common.errorreport:415 saving crash report 'install failed crashed with CalledProcessError' to /var/crash/1696995526.230397224.install_fail.crash
2023-10-11 03:38:46,268 ERROR root:30 finish: subiquity/Install/install: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2060', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1257/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1257/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1257/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/usr/sbin:/snap/ubuntu-desktop-installer/1257/usr/bin:/snap/ubuntu-desktop-installer/1257/sbin:/snap/ubuntu-desktop-installer/1257/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/1257/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1257/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1257', '--', '/snap/ubuntu-desktop-installer/1257/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2060.3"}}', 'in-target', '-t', '/tmp/tmp71369fw6/mount', '--', 'apt-get', 'update']' returned non-zero exit status 100.
2023-10-11 03:38:46,268 INFO root:30 start: subiquity/ErrorReporter/1696995526.230397224.install_fail/add_info: