2023-11-04 09:13:47,958 INFO subiquity:199 Starting Subiquity server revision 1269 of snap /snap/ubuntu-desktop-installer/1269 2023-11-04 09:13:47,958 INFO subiquity:200 Arguments passed: ['/snap/ubuntu-desktop-installer/1269/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/1269/etc/subiquity/postinst.d'] 2023-11-04 09:13:47,958 DEBUG subiquity:201 Kernel commandline: CommandLineParams(_raw='BOOT_IMAGE=/casper/vmlinuz layerfs-path=minimal.standard.live.squashfs --- quiet splash\n', _tokens={'---', 'splash', 'quiet'}, _values={'BOOT_IMAGE': '/casper/vmlinuz', 'layerfs-path': 'minimal.standard.live.squashfs'}) 2023-11-04 09:13:47,958 DEBUG subiquity:202 Environment: environ({'SNAP_REVISION': '1269', 'SNAP_REAL_HOME': '/root', 'SNAP_USER_COMMON': '/root/snap/ubuntu-desktop-installer/common', 'PATH_ORIG': '/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/bin/subiquity', 'SYSTEMD_EXEC_PID': '2017', 'SNAP_CONTEXT': 'jfGIKB9t4ZwZDoVQT4hejXzE1lWT1BLRX0A8jaJeVYddHpjndpii', 'LANG': 'C.UTF-8', 'SNAP_ARCH': 'amd64', 'PY3OR2_PYTHON': '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', 'SNAP_INSTANCE_NAME': 'ubuntu-desktop-installer', 'SNAP_USER_DATA': '/root/snap/ubuntu-desktop-installer/1269', 'INVOCATION_ID': '6bf18c25f9d5413e911c4355ce44cc0c', '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/1269/lib:/snap/ubuntu-desktop-installer/1269/usr/lib:/snap/ubuntu-desktop-installer/1269/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1269/usr/lib/x86_64-linux-gnu', 'PYTHONPATH_ORIG': '', 'PYTHONPATH': '/snap/ubuntu-desktop-installer/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', 'PYTHON': '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', 'PYTHONIOENCODING': 'utf-8', 'SNAP': '/snap/ubuntu-desktop-installer/1269', 'SNAP_COMMON': '/var/snap/ubuntu-desktop-installer/common', 'SNAP_VERSION': '0+git.1c719695', 'DISPLAY': ':0', 'SHLVL': '1', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'SNAP_COOKIE': 'jfGIKB9t4ZwZDoVQT4hejXzE1lWT1BLRX0A8jaJeVYddHpjndpii', 'SNAP_DATA': '/var/snap/ubuntu-desktop-installer/1269', 'LD_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/ubuntu-desktop-installer/1269/lib:/snap/ubuntu-desktop-installer/1269/usr/lib:/snap/ubuntu-desktop-installer/1269/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1269/usr/lib/x86_64-linux-gnu', 'SNAP_NAME': 'ubuntu-desktop-installer', 'JOURNAL_STREAM': '8:28764', 'PATH': '/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/bin/subiquity', 'OLDPWD': '/var/snap/ubuntu-desktop-installer/1269', '_': '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', 'APPORT_DATA_DIR': '/snap/ubuntu-desktop-installer/1269/bin/subiquity/share/apport'}) 2023-11-04 09:13:47,958 DEBUG asyncio:54 Using selector: EpollSelector 2023-11-04 09:13:47,960 DEBUG subiquitycore.prober:33 Prober() init finished, data:None 2023-11-04 09:13:48,042 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True) 2023-11-04 09:13:48,079 DEBUG subiquitycore.netplan:113 config for zz-all-en = {'dhcp4': True, 'match': {'name': 'en*'}} 2023-11-04 09:13:48,080 DEBUG subiquitycore.netplan:113 config for zz-all-eth = {'dhcp4': True, 'match': {'name': 'eth*'}} 2023-11-04 09:13:48,098 DEBUG subiquitycore.utils:121 arun_command called: ['cloud-init', 'status', '--wait'] 2023-11-04 09:14:05,663 DEBUG subiquitycore.utils:135 arun_command ['cloud-init', 'status', '--wait'] exited with code 0 2023-11-04 09:14:05,663 DEBUG subiquity.server.server:569 waited 17.564880847930908s for cloud-init 2023-11-04 09:14:05,664 DEBUG subiquity.cloudinit:14 Loaded cloud config from /run/cloud-init/combined-cloud-config.json 2023-11-04 09:14:05,664 DEBUG subiquity.server.server:553 no autoinstall found in cloud-config 2023-11-04 09:14:05,664 DEBUG subiquitycore.utils:79 run_command called: ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys'] 2023-11-04 09:14:05,675 DEBUG subiquitycore.utils:98 run_command ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys'] exited with code 255 2023-11-04 09:14:05,675 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-11-04 09:14:05,676 DEBUG subiquitycore.utils:79 run_command called: chpasswd 2023-11-04 09:14:05,906 DEBUG subiquitycore.utils:98 run_command chpasswd exited with code 0 2023-11-04 09:14:05,910 DEBUG subiquity.server.server:470 load_autoinstall_config only_early True file None 2023-11-04 09:14:05,910 DEBUG subiquity.server.server:470 load_autoinstall_config only_early False file None 2023-11-04 09:14:05,911 DEBUG subiquitycore.core:118 starting controllers 2023-11-04 09:14:05,916 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic-hwe-22.04 due to /etc/subiquity/kernel-meta-package 2023-11-04 09:14:05,929 DEBUG subiquity.models.source:93 loaded 2 sources from '/cdrom/casper/install-sources.yaml' 2023-11-04 09:14:05,930 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-11-04 09:14:05,930 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp2s0'} 2023-11-04 09:14:05,931 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp0s12f0'} 2023-11-04 09:14:05,931 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-11-04 09:14:05,931 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.1.116/24'} 2023-11-04 09:14:05,931 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-11-04 09:14:05,931 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5e85:7eff:fe45:7845/64'} 2023-11-04 09:14:05,931 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-11-04 09:14:06,103 DEBUG subiquitycore.models.network:475 new_link 1 lo lo 2023-11-04 09:14:06,103 DEBUG subiquitycore.models.network:477 ignoring based on type 2023-11-04 09:14:06,103 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp2s0'} 2023-11-04 09:14:06,278 DEBUG subiquitycore.models.network:475 new_link 2 enp2s0 eth 2023-11-04 09:14:06,279 DEBUG subiquitycore.models.network:506 new_link 2 enp2s0 with config {'dhcp4': True} 2023-11-04 09:14:06,279 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp2s0 2023-11-04 09:14:06,279 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp2s0 2023-11-04 09:14:06,280 DEBUG probert.network:672 link_change NEW {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp0s12f0'} 2023-11-04 09:14:06,452 DEBUG subiquitycore.models.network:475 new_link 3 wlp0s12f0 wlan 2023-11-04 09:14:06,452 DEBUG subiquitycore.models.network:506 new_link 3 wlp0s12f0 with config {} 2023-11-04 09:14:06,452 DEBUG subiquity.server.controllers.network:100 maybe_start_install_wpasupplicant 2023-11-04 09:14:06,453 DEBUG root:30 start: subiquity/Network/_send_update: NEW wlp0s12f0 2023-11-04 09:14:06,453 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW wlp0s12f0 2023-11-04 09:14:06,453 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'} 2023-11-04 09:14:06,453 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'192.168.1.116/24'} 2023-11-04 09:14:06,454 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp2s0 2023-11-04 09:14:06,454 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp2s0 2023-11-04 09:14:06,454 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-11-04 09:14:06,454 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5e85:7eff:fe45:7845/64'} 2023-11-04 09:14:06,454 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp2s0 2023-11-04 09:14:06,454 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp2s0 2023-11-04 09:14:06,454 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2} 2023-11-04 09:14:06,619 DEBUG pyroute2.ndb.140670354144464.sources.localhost:74 init 2023-11-04 09:14:06,619 DEBUG pyroute2.ndb.140670354144464.sources.localhost:384 starting the source 2023-11-04 09:14:06,620 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:74 init 2023-11-04 09:14:06,620 DEBUG pyroute2.ndb.140670354144464.sources.localhost:74 connecting 2023-11-04 09:14:06,620 DEBUG pyroute2.ndb.140670354144464.sources.localhost:74 loading 2023-11-04 09:14:06,621 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:384 starting the source 2023-11-04 09:14:06,621 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:74 connecting 2023-11-04 09:14:06,624 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:74 loading 2023-11-04 09:14:06,648 DEBUG pyroute2.ndb.140670354144464.sources.localhost:74 running 2023-11-04 09:14:06,650 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:74 running 2023-11-04 09:14:06,652 DEBUG pyroute2.ndb.140670354144464.sources.localhost:399 source shutdown 2023-11-04 09:14:06,652 DEBUG pyroute2.ndb.140670354144464.sources.localhost:374 sync 2023-11-04 09:14:06,652 DEBUG pyroute2.ndb.140670354144464.sources.localhost:369 shutdown handled by the main thread 2023-11-04 09:14:06,652 DEBUG pyroute2.ndb.140670354144464.sources.localhost:74 stopped 2023-11-04 09:14:06,652 DEBUG pyroute2.ndb.140670354144464.main:851 flush DB for the target localhost 2023-11-04 09:14:06,654 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:399 source shutdown 2023-11-04 09:14:06,669 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:374 sync 2023-11-04 09:14:06,669 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:369 shutdown handled by the main thread 2023-11-04 09:14:06,669 DEBUG pyroute2.ndb.140670354144464.sources.localhost/nsmanager:74 stopped 2023-11-04 09:14:06,669 DEBUG pyroute2.ndb.140670354144464.main:851 flush DB for the target localhost/nsmanager 2023-11-04 09:14:06,671 DEBUG subiquitycore.controllers.network:102 default routes True 2023-11-04 09:14:06,671 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'169.254.0.0/16', 'ifindex': 2} 2023-11-04 09:14:06,671 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'192.168.1.0/24', 'ifindex': 2} 2023-11-04 09:14:06,671 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'192.168.1.116', 'ifindex': 2} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'192.168.1.255', 'ifindex': 2} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::5e85:7eff:fe45:7845', 'ifindex': 2} 2023-11-04 09:14:06,672 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 5, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2} 2023-11-04 09:14:06,672 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_INTERFACE', 'ifindex': -1} 2023-11-04 09:14:06,673 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_INTERFACE', 'ifindex': 3, 'ssids': []} 2023-11-04 09:14:06,697 DEBUG subiquitycore.core:121 controllers started 2023-11-04 09:14:06,697 INFO root:30 start: subiquity/apply_autoinstall_config: 2023-11-04 09:14:06,697 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 2023-11-04 09:14:06,698 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,698 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 2023-11-04 09:14:06,698 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,699 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 2023-11-04 09:14:06,699 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,699 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 2023-11-04 09:14:06,699 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,700 DEBUG subiquity.models.subiquity:256 model userdata for postinstall stage is configured, to go {'identity', 'ubuntu_pro', 'ssh', 'packages', 'drivers', 'locale', 'snaplist'} 2023-11-04 09:14:06,700 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 2023-11-04 09:14:06,700 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,700 DEBUG subiquity.models.subiquity:256 model packages for postinstall stage is configured, to go {'identity', 'ubuntu_pro', 'ssh', 'drivers', 'locale', 'snaplist'} 2023-11-04 09:14:06,700 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 2023-11-04 09:14:06,701 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,701 DEBUG subiquity.models.subiquity:256 model debconf_selections for install stage is configured, to go {'kernel', 'source', 'filesystem', 'proxy', 'keyboard'} 2023-11-04 09:14:06,701 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Locale as interactive 2023-11-04 09:14:06,701 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Refresh as interactive 2023-11-04 09:14:06,701 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 2023-11-04 09:14:06,701 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,702 DEBUG subiquity.models.subiquity:256 model kernel for install stage is configured, to go {'proxy', 'keyboard', 'filesystem', 'source'} 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Integrity as interactive 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Keyboard as interactive 2023-11-04 09:14:06,702 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 2023-11-04 09:14:06,702 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Source as interactive 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Network as interactive 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping UbuntuPro as interactive 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Proxy as interactive 2023-11-04 09:14:06,702 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Mirror as interactive 2023-11-04 09:14:06,703 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Filesystem as interactive 2023-11-04 09:14:06,703 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Identity as interactive 2023-11-04 09:14:06,703 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SSH as interactive 2023-11-04 09:14:06,703 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SnapList as interactive 2023-11-04 09:14:06,703 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 2023-11-04 09:14:06,703 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Codecs as interactive 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Drivers as interactive 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping OEM as interactive 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping TimeZone as interactive 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Install as interactive 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Updates as interactive 2023-11-04 09:14:06,704 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 2023-11-04 09:14:06,704 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,704 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Shutdown as interactive 2023-11-04 09:14:06,704 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 2023-11-04 09:14:06,705 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'identity', 'ubuntu_pro', 'ssh', 'drivers', 'snaplist'} 2023-11-04 09:14:06,705 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 2023-11-04 09:14:06,705 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 2023-11-04 09:14:06,706 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-11-04 09:14:06,709 DEBUG subiquitycore.utils:121 arun_command called: ['/usr/sbin/realm', 'discover'] 2023-11-04 09:14:06,736 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 2023-11-04 09:14:06,736 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 2023-11-04 09:14:06,736 DEBUG root:30 start: subiquity/Install/install: 2023-11-04 09:14:06,737 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:06,799 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:14:06,799 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:14:06,800 DEBUG subiquity.server.pkghelper:65 checking if wpasupplicant is available 2023-11-04 09:14:06,895 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1560 2023-11-04 09:14:15,010 DEBUG subiquity.server.pkghelper:71 wpasupplicant already installed 2023-11-04 09:14:15,011 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps 2023-11-04 09:14:15,120 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-11-04 09:14:15,120 DEBUG subiquity.server.controllers.network:112 wlan_support_install_finished PackageInstallState.DONE 2023-11-04 09:14:15,122 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-11-04 09:14:15,122 DEBUG root:30 start: subiquity/SnapList/loader: 2023-11-04 09:14:15,122 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-11-04 09:14:15,127 DEBUG asyncio:54 Using selector: EpollSelector 2023-11-04 09:14:15,129 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:15,129 DEBUG probert.dasd:134 Probing DASD devies 2023-11-04 09:14:15,135 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-11-04 09:14:15,139 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:14:15,140 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'NOVA-K6LAQ9', 'no status'), (b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status'), (b'Vodafone-UwWV', 'no status')]} 2023-11-04 09:14:15,140 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:15,149 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:14:15,149 DEBUG probert.network:585 event for link_change: CHANGE {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp0s12f0'} 2023-11-04 09:14:15,150 DEBUG probert.network:672 link_change CHANGE {'ifindex': 3, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'wlp0s12f0'} 2023-11-04 09:14:15,150 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE wlp0s12f0 2023-11-04 09:14:15,150 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE wlp0s12f0 2023-11-04 09:14:15,152 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.1c719695' 2023-11-04 09:14:15,153 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info 2023-11-04 09:14:15,155 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 2023-11-04 09:14:15,156 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled 2023-11-04 09:14:15,156 DEBUG root:30 start: subiquity/SnapList/loader/list: 2023-11-04 09:14:15,162 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:14:15,164 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-11-04 09:14:15,165 DEBUG subiquitycore.utils:135 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1 2023-11-04 09:14:15,269 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:14:15,270 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-11-04 09:14:15,271 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:14:15,272 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-11-04 09:14:15,273 INFO root:30 start: subiquity/Meta/client_variant_POST: 2023-11-04 09:14:15,277 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null 2023-11-04 09:14:15,279 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:14:15,280 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 2023-11-04 09:14:15,281 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null 2023-11-04 09:14:15,283 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:14:15,283 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-11-04 09:14:15,284 DEBUG root:30 start: subiquity/Locale/GET: 2023-11-04 09:14:15,285 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8" 2023-11-04 09:14:15,290 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-11-04 09:14:15,291 DEBUG subiquity.models.subiquity:256 model ubuntu_pro for postinstall stage is configured, to go {'timezone', 'identity', 'codecs', 'network', 'ssh', 'drivers', 'snaplist'} 2023-11-04 09:14:15,291 DEBUG subiquity.models.subiquity:256 model proxy for install stage is configured, to go {'source', 'network', 'filesystem', 'mirror', 'keyboard'} 2023-11-04 09:14:15,291 DEBUG subiquity.models.subiquity:256 model mirror for install stage is configured, to go {'source', 'keyboard', 'filesystem', 'network'} 2023-11-04 09:14:15,291 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'timezone', 'identity', 'codecs', 'network', 'drivers', 'snaplist'} 2023-11-04 09:14:15,292 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'timezone', 'identity', 'codecs', 'network', 'drivers'} 2023-11-04 09:14:15,293 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-11-04 09:14:15,508 DEBUG root:30 start: subiquity/Refresh/GET: 2023-11-04 09:14:15,650 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 200 None 2023-11-04 09:14:15,654 DEBUG root:30 finish: subiquity/SnapList/loader/list: SUCCESS: 2023-11-04 09:14:15,654 DEBUG subiquity.server.controllers.snaplist:92 fetched list of 22 snaps 2023-11-04 09:14:15,655 DEBUG root:30 start: subiquity/SnapList/loader/fetch/microk8s: 2023-11-04 09:14:15,853 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 200 59 2023-11-04 09:14:15,855 DEBUG subiquity.server.controllers.refresh:201 check_for_update received [] 2023-11-04 09:14:15,855 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: no new version of snap available 2023-11-04 09:14:15,856 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.1c719695", "ne... 2023-11-04 09:14:16,098 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=microk8s HTTP/1.1" 200 None 2023-11-04 09:14:16,156 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/microk8s: SUCCESS: 2023-11-04 09:14:16,177 DEBUG root:30 start: subiquity/SnapList/loader/fetch/nextcloud: 2023-11-04 09:14:16,465 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=nextcloud HTTP/1.1" 200 None 2023-11-04 09:14:16,468 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/nextcloud: SUCCESS: 2023-11-04 09:14:16,468 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wekan: 2023-11-04 09:14:16,650 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wekan HTTP/1.1" 200 None 2023-11-04 09:14:16,652 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wekan: SUCCESS: 2023-11-04 09:14:16,652 DEBUG root:30 start: subiquity/SnapList/loader/fetch/kata-containers: 2023-11-04 09:14:16,810 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=kata-containers HTTP/1.1" 200 None 2023-11-04 09:14:16,812 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/kata-containers: SUCCESS: 2023-11-04 09:14:16,812 DEBUG root:30 start: subiquity/SnapList/loader/fetch/docker: 2023-11-04 09:14:16,874 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-11-04 09:14:16,876 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-11-04 09:14:16,893 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0 2023-11-04 09:14:16,893 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:14:16,893 DEBUG probert.utils:50 Filesystem volume name: 2023-11-04 09:14:16,893 DEBUG probert.utils:50 Last mounted on: / 2023-11-04 09:14:16,893 DEBUG probert.utils:50 Filesystem UUID: dba65023-a29a-4357-a7b5-643df2960ee4 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:14:16,894 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-11-04 09:14:16,894 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Inode count: 7749632 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Block count: 30982912 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Reserved block count: 1549145 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Overhead clusters: 632916 2023-11-04 09:14:16,894 DEBUG probert.utils:50 Free blocks: 27757623 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Free inodes: 7511051 2023-11-04 09:14:16,895 DEBUG probert.utils:50 First block: 0 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Inodes per group: 8192 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Inode blocks per group: 512 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:14:16,895 DEBUG probert.utils:50 Filesystem created: Fri Nov 3 18:59:47 2023 2023-11-04 09:14:16,896 DEBUG probert.utils:50 Last mount time: Fri Nov 3 19:42:38 2023 2023-11-04 09:14:16,896 DEBUG probert.utils:50 Last write time: Fri Nov 3 19:42:37 2023 2023-11-04 09:14:16,896 DEBUG probert.utils:50 Mount count: 2 2023-11-04 09:14:16,896 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:14:16,896 DEBUG probert.utils:50 Last checked: Fri Nov 3 18:59:47 2023 2023-11-04 09:14:16,897 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:14:16,897 DEBUG probert.utils:50 Lifetime writes: 9 GB 2023-11-04 09:14:16,897 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:14:16,897 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:14:16,898 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Directory Hash Seed: e484c3e8-7003-4d0a-a7f9-e571800d56b8 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Checksum: 0x4850f4d7 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Journal features: journal_incompat_revoke journal_64bit journal_checksum_v3 2023-11-04 09:14:16,898 DEBUG probert.utils:50 Total journal size: 512M 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Total journal blocks: 131072 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Max transaction length: 131072 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Journal sequence: 0x00000be4 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Journal start: 0 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:14:16,899 DEBUG probert.utils:50 Journal checksum: 0x2cb1136e 2023-11-04 09:14:16,899 DEBUG probert.utils:50 2023-11-04 09:14:16,899 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:14:16,899 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:14:16,899 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:14:16,954 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=docker HTTP/1.1" 200 None 2023-11-04 09:14:16,956 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/docker: SUCCESS: 2023-11-04 09:14:16,957 DEBUG root:30 start: subiquity/SnapList/loader/fetch/canonical-livepatch: 2023-11-04 09:14:16,962 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sdb4` exited with result: 0 2023-11-04 09:14:16,963 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem volume name: writable 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Last mounted on: /root/var/crash 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem UUID: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem features: has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:14:16,963 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Inode count: 1594320 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Block count: 6373632 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Reserved block count: 318681 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Overhead clusters: 144122 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Free blocks: 6229504 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Free inodes: 1594309 2023-11-04 09:14:16,964 DEBUG probert.utils:50 First block: 0 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:14:16,964 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Inodes per group: 8176 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Inode blocks per group: 511 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Filesystem created: Sat Nov 4 09:12:26 2023 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Last mount time: Sat Nov 4 09:12:37 2023 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Last write time: Sat Nov 4 09:12:37 2023 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Mount count: 1 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Last checked: Sat Nov 4 09:12:26 2023 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Lifetime writes: 4170 kB 2023-11-04 09:14:16,965 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:14:16,966 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Directory Hash Seed: ab849d65-1210-44a5-aed3-7209cc390ec9 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Checksum: 0xa507f22c 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Journal features: journal_64bit journal_checksum_v3 2023-11-04 09:14:16,966 DEBUG probert.utils:50 Total journal size: 128M 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Total journal blocks: 32768 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Max transaction length: 32768 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Journal sequence: 0x00000002 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Journal start: 1 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:14:16,967 DEBUG probert.utils:50 Journal checksum: 0x8f5f0ca5 2023-11-04 09:14:16,967 DEBUG probert.utils:50 2023-11-04 09:14:16,967 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:14:16,967 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:14:16,967 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:14:16,972 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0 2023-11-04 09:14:16,972 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:14:16,972 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 2903967 2023-11-04 09:14:16,972 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:14:16,973 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:14:16,973 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:14:16,977 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sdb4` exited with result: 0 2023-11-04 09:14:16,977 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:14:16,977 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 48991 2023-11-04 09:14:16,977 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:14:16,978 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:14:16,978 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:14:17,132 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=canonical-livepatch HTTP/1.1" 200 None 2023-11-04 09:14:17,134 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/canonical-livepatch: SUCCESS: 2023-11-04 09:14:17,135 DEBUG root:30 start: subiquity/SnapList/loader/fetch/rocketchat-server: 2023-11-04 09:14:17,334 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=rocketchat-server HTTP/1.1" 200 None 2023-11-04 09:14:17,336 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/rocketchat-server: SUCCESS: 2023-11-04 09:14:17,336 DEBUG root:30 start: subiquity/SnapList/loader/fetch/mosquitto: 2023-11-04 09:14:17,489 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=mosquitto HTTP/1.1" 200 None 2023-11-04 09:14:17,490 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/mosquitto: SUCCESS: 2023-11-04 09:14:17,491 DEBUG root:30 start: subiquity/SnapList/loader/fetch/etcd: 2023-11-04 09:14:17,670 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=etcd HTTP/1.1" 200 None 2023-11-04 09:14:17,673 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/etcd: SUCCESS: 2023-11-04 09:14:17,673 DEBUG root:30 start: subiquity/SnapList/loader/fetch/powershell: 2023-11-04 09:14:17,830 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=powershell HTTP/1.1" 200 None 2023-11-04 09:14:17,831 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/powershell: SUCCESS: 2023-11-04 09:14:17,832 DEBUG root:30 start: subiquity/SnapList/loader/fetch/sabnzbd: 2023-11-04 09:14:18,028 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=sabnzbd HTTP/1.1" 200 None 2023-11-04 09:14:18,030 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/sabnzbd: SUCCESS: 2023-11-04 09:14:18,031 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wormhole: 2023-11-04 09:14:18,182 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=wormhole HTTP/1.1" 200 None 2023-11-04 09:14:18,184 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wormhole: SUCCESS: 2023-11-04 09:14:18,185 DEBUG root:30 start: subiquity/SnapList/loader/fetch/aws-cli: 2023-11-04 09:14:18,407 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=aws-cli HTTP/1.1" 200 None 2023-11-04 09:14:18,408 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/aws-cli: SUCCESS: 2023-11-04 09:14:18,409 DEBUG root:30 start: subiquity/SnapList/loader/fetch/google-cloud-sdk: 2023-11-04 09:14:18,487 DEBUG curtin:1325 Extracting storage config from probe data 2023-11-04 09:14:18,488 DEBUG curtin:73 /dev/sda is multipath device member? False 2023-11-04 09:14:18,488 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:14:18,488 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:14:18,488 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:14:18,488 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:14:18,518 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:14:18,519 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:14:18,519 DEBUG curtin:61 /dev/sda1 is multipath device? False 2023-11-04 09:14:18,519 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:14:18,519 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:14:18,546 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:14:18,546 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:14:18,546 DEBUG curtin:61 /dev/sda2 is multipath device? False 2023-11-04 09:14:18,546 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:14:18,546 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:14:18,572 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:14:18,572 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:14:18,573 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:14:18,573 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:14:18,573 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:14:18,599 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:14:18,599 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:14:18,599 DEBUG curtin:61 /dev/sdb1 is multipath device? False 2023-11-04 09:14:18,599 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:14:18,600 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:14:18,625 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:14:18,626 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:14:18,626 DEBUG curtin:61 /dev/sdb2 is multipath device? False 2023-11-04 09:14:18,626 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:14:18,626 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:14:18,634 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=google-cloud-sdk HTTP/1.1" 200 1799 2023-11-04 09:14:18,658 DEBUG curtin:73 /dev/sdb3 is multipath device member? False 2023-11-04 09:14:18,659 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:14:18,659 DEBUG curtin:61 /dev/sdb3 is multipath device? False 2023-11-04 09:14:18,659 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:14:18,659 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:14:18,687 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:14:18,687 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:14:18,687 DEBUG curtin:61 /dev/sdb4 is multipath device? False 2023-11-04 09:14:18,687 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:14:18,687 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:14:18,716 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:14:18,745 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:14:18,772 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:14:18,800 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:14:18,829 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:14:18,856 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:14:18,911 DEBUG curtin:1332 Sorting extracted configurations 2023-11-04 09:14:18,911 INFO curtin:1351 Validating extracted storage config components 2023-11-04 09:14:18,962 DEBUG curtin:1368 Extracted (unmerged) storage config: storage: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount 2023-11-04 09:14:18,962 DEBUG curtin:1372 Generating storage config dependencies 2023-11-04 09:14:18,962 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,962 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: partition-sdb3:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,963 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: format-disk-sdb:SourceType:format -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: format-partition-sdb2:SourceType:format -> (DepId:partition-sdb2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,964 DEBUG curtin:238 Validate: format-partition-sdb4:SourceType:format -> (DepId:partition-sdb4 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,965 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,965 DEBUG curtin:238 Validate: mount-partition-sdb1:SourceType:mount -> (DepId:format-partition-sdb1 DepType:format) in SourceDeps:{'format'} ? result=True 2023-11-04 09:14:18,965 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:14:18,965 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:14:18,965 DEBUG curtin:1378 Merging storage config dependencies 2023-11-04 09:14:18,978 DEBUG curtin:1383 Merged storage config: storage: config: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 type: disk - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount version: 2 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='FORESEE_128GB_SSD_K44700J003729', wwn='0x502b2a201d1c1b1a', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:16': Disk(ptable='gpt', serial='Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0', path='/dev/sdb', preserve=True, id='disk-sdb', 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='0e39f173-0767-412b-83d7-fd6dc6130ef8', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=126906007552, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='7f8a493b-1a79-4503-b572-c3bc67bf3615', id='partition-sda2', type='partition'), '8:17': Partition(device=disk-sdb, size=4882786304, number=1, preserve=True, offset=32768, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb1', uuid='3417995c-5bfb-493f-befa-2f58410ff177', id='partition-sdb1', type='partition'), '8:18': Partition(device=disk-sdb, size=5138432, flag='boot', number=2, preserve=True, offset=4882819072, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sdb2', uuid='3417995c-5bfb-493f-bef9-2f58410ff177', id='partition-sdb2', type='partition'), '8:19': Partition(device=disk-sdb, size=307200, number=3, preserve=True, offset=4887957504, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb3', uuid='3417995c-5bfb-493f-bef8-2f58410ff177', id='partition-sdb3', type='partition'), '8:20': Partition(device=disk-sdb, size=26106396672, flag='linux', number=4, preserve=True, offset=4888461312, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sdb4', uuid='82f5e486-652d-46d3-89ec-01ed752e28ff', id='partition-sdb4', type='partition')} 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:14:18,979 DEBUG subiquity.models.filesystem:1475 considering mount of 8:17 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1480 /dev/sdb1 is mounted 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:14:18,980 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35 2023-11-04 09:14:18,981 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:33 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:48 2023-11-04 09:14:18,982 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:51 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90 2023-11-04 09:14:18,983 DEBUG subiquity.models.filesystem:1475 considering mount of 0:91 2023-11-04 09:14:18,984 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-11-04 09:14:18,985 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/google-cloud-sdk: SUCCESS: 2023-11-04 09:14:18,985 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 3.9 seconds 2023-11-04 09:14:18,985 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor 2023-11-04 09:14:18,986 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-11-04 09:14:18,987 DEBUG root:30 start: subiquity/SnapList/loader/fetch/slcli: 2023-11-04 09:14:19,183 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=slcli HTTP/1.1" 200 None 2023-11-04 09:14:19,185 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/slcli: SUCCESS: 2023-11-04 09:14:19,185 DEBUG root:30 start: subiquity/SnapList/loader/fetch/doctl: 2023-11-04 09:14:19,352 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=doctl HTTP/1.1" 200 None 2023-11-04 09:14:19,354 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/doctl: SUCCESS: 2023-11-04 09:14:19,354 DEBUG root:30 start: subiquity/SnapList/loader/fetch/conjure-up: 2023-11-04 09:14:19,518 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=conjure-up HTTP/1.1" 200 None 2023-11-04 09:14:19,519 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/conjure-up: SUCCESS: 2023-11-04 09:14:19,519 DEBUG root:30 start: subiquity/SnapList/loader/fetch/postgresql10: 2023-11-04 09:14:19,679 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=postgresql10 HTTP/1.1" 200 1523 2023-11-04 09:14:19,680 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/postgresql10: SUCCESS: 2023-11-04 09:14:19,680 DEBUG root:30 start: subiquity/SnapList/loader/fetch/heroku: 2023-11-04 09:14:19,825 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=heroku HTTP/1.1" 200 None 2023-11-04 09:14:19,826 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/heroku: SUCCESS: 2023-11-04 09:14:19,826 DEBUG root:30 start: subiquity/SnapList/loader/fetch/keepalived: 2023-11-04 09:14:19,968 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=keepalived HTTP/1.1" 200 None 2023-11-04 09:14:19,970 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/keepalived: SUCCESS: 2023-11-04 09:14:19,970 DEBUG root:30 start: subiquity/SnapList/loader/fetch/prometheus: 2023-11-04 09:14:20,190 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=prometheus HTTP/1.1" 200 None 2023-11-04 09:14:20,192 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/prometheus: SUCCESS: 2023-11-04 09:14:20,192 DEBUG root:30 start: subiquity/SnapList/loader/fetch/juju: 2023-11-04 09:14:20,441 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?name=juju HTTP/1.1" 200 None 2023-11-04 09:14:20,443 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/juju: SUCCESS: 2023-11-04 09:14:20,443 DEBUG root:30 finish: subiquity/SnapList/loader: SUCCESS: 2023-11-04 09:14:30,982 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:30,997 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:14:30,998 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:14:32,017 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:32,024 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:14:32,024 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'NOVA-K6LAQ9', 'no status'), (b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status'), (b'Vodafone-UwWV', 'no status')]} 2023-11-04 09:14:32,024 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:14:32,045 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:13,473 DEBUG subiquity.server.controllers.integrity:61 casper-md5check results: {'checksum_missmatch': [], 'result': 'pass'} 2023-11-04 09:15:13,985 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:14,010 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:14,010 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:15:14,906 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:14,925 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:14,926 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'NOVA-K6LAQ9', 'no status'), (b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status'), (b'HUAWEI-V3FCRP', 'no status')]} 2023-11-04 09:15:14,926 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:14,946 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:27,124 DEBUG root:30 start: subiquity/Locale/POST: 2023-11-04 09:15:27,125 DEBUG subiquity.server.controllers.locale:68 en_US.UTF-8 2023-11-04 09:15:27,125 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'timezone', 'identity', 'codecs', 'network', 'drivers'} 2023-11-04 09:15:27,125 DEBUG root:30 finish: subiquity/Locale/POST: SUCCESS: 200 null 2023-11-04 09:15:27,126 DEBUG subiquitycore.utils:121 arun_command called: ['localectl', 'set-locale', 'en_US.UTF-8'] 2023-11-04 09:15:28,290 DEBUG subiquitycore.utils:135 arun_command ['localectl', 'set-locale', 'en_US.UTF-8'] exited with code 0 2023-11-04 09:15:48,791 DEBUG root:30 start: subiquity/Filesystem/has_rst_GET: 2023-11-04 09:15:48,792 DEBUG root:30 finish: subiquity/Filesystem/has_rst_GET: SUCCESS: 200 false 2023-11-04 09:15:48,794 DEBUG root:30 start: subiquity/Keyboard/GET: 2023-11-04 09:15:48,819 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co... 2023-11-04 09:15:48,831 DEBUG root:30 start: subiquity/Keyboard/GET: 2023-11-04 09:15:48,854 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co... 2023-11-04 09:15:48,862 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 2023-11-04 09:15:48,862 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-11-04 09:15:48,944 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-11-04 09:15:48,945 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null 2023-11-04 09:15:53,739 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 2023-11-04 09:15:53,740 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','is')]"] 2023-11-04 09:15:53,803 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','is')]"] exited with code 0 2023-11-04 09:15:53,803 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null 2023-11-04 09:15:55,284 DEBUG root:30 start: subiquity/Keyboard/POST: 2023-11-04 09:15:55,285 DEBUG subiquity.server.controllers.keyboard:221 KeyboardSetting(layout='is', variant='', toggle=None) 2023-11-04 09:15:55,287 DEBUG subiquitycore.utils:121 arun_command called: ['setupcon', '--save', '--force', '--keyboard-only'] 2023-11-04 09:15:56,123 DEBUG subiquitycore.utils:135 arun_command ['setupcon', '--save', '--force', '--keyboard-only'] exited with code 0 2023-11-04 09:15:56,123 DEBUG subiquitycore.utils:121 arun_command called: ['/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin/subiquity-loadkeys'] 2023-11-04 09:15:56,127 DEBUG subiquitycore.utils:135 arun_command ['/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin/subiquity-loadkeys'] exited with code 0 2023-11-04 09:15:56,127 DEBUG subiquity.models.subiquity:256 model keyboard for install stage is configured, to go {'source', 'filesystem', 'network'} 2023-11-04 09:15:56,128 DEBUG root:30 finish: subiquity/Keyboard/POST: SUCCESS: 200 null 2023-11-04 09:15:56,201 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:56,225 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:56,226 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:15:57,463 DEBUG root:30 start: subiquity/Refresh/GET: 2023-11-04 09:15:57,464 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.1c719695", "ne... 2023-11-04 09:15:57,469 DEBUG root:30 start: subiquity/Source/GET: 2023-11-04 09:15:57,470 DEBUG root:30 finish: subiquity/Source/GET: SUCCESS: 200 {"sources": [{"name": "Ubuntu Desktop (minimized)", "description": "A minimal... 2023-11-04 09:15:57,475 DEBUG root:30 start: subiquity/Drivers/GET: 2023-11-04 09:15:57,476 DEBUG root:30 finish: subiquity/Drivers/GET: SUCCESS: 200 {"install": false, "drivers": null, "local_only": true, "search_drivers": false} 2023-11-04 09:15:57,477 DEBUG root:30 start: subiquity/Codecs/GET: 2023-11-04 09:15:57,478 DEBUG root:30 finish: subiquity/Codecs/GET: SUCCESS: 200 {"install": false} 2023-11-04 09:15:59,205 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:59,225 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:59,226 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'NOVA-K6LAQ9', 'no status'), (b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status')]} 2023-11-04 09:15:59,226 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:59,249 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:59,256 DEBUG root:30 start: subiquity/Source/POST: 2023-11-04 09:15:59,257 DEBUG subiquity.models.subiquity:256 model source for install stage is configured, to go {'filesystem', 'network'} 2023-11-04 09:15:59,257 DEBUG subiquity.server.controllers.drivers:89 source variant has been set. Querying list of drivers. 2023-11-04 09:15:59,257 DEBUG root:30 finish: subiquity/Source/POST: SUCCESS: 200 null 2023-11-04 09:15:59,258 DEBUG subiquity.server.controllers.filesystem:414 got system None for variation minimal 2023-11-04 09:15:59,258 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-11-04 09:15:59,259 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp4o3cc1m0/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:15:59,269 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.squashfs', '/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:15:59,288 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.en.squashfs', '/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:15:59,305 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.en.squashfs.dir:/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.squashfs.dir:/tmp/tmp4o3cc1m0/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp4o3cc1m0/root.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:15:59,316 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'bind', '/tmp/tmp4o3cc1m0/root.dir/var/lib/snapd/seed/systems', '/var/lib/snapd/seed/systems'] 2023-11-04 09:15:59,321 DEBUG root:30 start: subiquity/Drivers/_list_drivers: 2023-11-04 09:15:59,321 DEBUG root:30 start: subiquity/Drivers/_list_drivers/wait_apt: 2023-11-04 09:15:59,323 DEBUG root:30 start: subiquity/Drivers/POST: 2023-11-04 09:15:59,323 DEBUG subiquity.models.subiquity:256 model drivers for postinstall stage is configured, to go {'timezone', 'codecs', 'identity', 'network'} 2023-11-04 09:15:59,323 DEBUG root:30 finish: subiquity/Drivers/POST: SUCCESS: 200 null 2023-11-04 09:15:59,324 DEBUG root:30 start: subiquity/Codecs/POST: 2023-11-04 09:15:59,325 DEBUG subiquity.models.subiquity:256 model codecs for postinstall stage is configured, to go {'timezone', 'identity', 'network'} 2023-11-04 09:15:59,333 DEBUG root:30 finish: subiquity/Codecs/POST: SUCCESS: 200 null 2023-11-04 09:15:59,334 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-11-04 09:15:59,404 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor 2023-11-04 09:15:59,405 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:15:59,425 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:15:59,426 DEBUG subiquity.server.controllers.filesystem:1499 Triggered Probert run on udev event 2023-11-04 09:15:59,426 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-11-04 09:15:59,426 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-11-04 09:15:59,430 DEBUG asyncio:54 Using selector: EpollSelector 2023-11-04 09:15:59,431 DEBUG probert.dasd:134 Probing DASD devies 2023-11-04 09:15:59,431 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-11-04 09:15:59,438 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'bind', '/tmp/tmp4o3cc1m0/root.dir/var/lib/snapd/seed/snaps/pc-kernel_1500.snap', '/var/lib/snapd/seed/snaps/pc-kernel_1500.snap'] 2023-11-04 09:15:59,489 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'bind', '/tmp/tmp4o3cc1m0/root.dir/var/lib/snapd/seed/snaps/pc_161.snap', '/var/lib/snapd/seed/snaps/pc_161.snap'] 2023-11-04 09:16:00,036 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-11-04 09:16:00,039 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-11-04 09:16:00,051 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0 2023-11-04 09:16:00,051 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:00,051 DEBUG probert.utils:50 Filesystem volume name: 2023-11-04 09:16:00,051 DEBUG probert.utils:50 Last mounted on: / 2023-11-04 09:16:00,051 DEBUG probert.utils:50 Filesystem UUID: dba65023-a29a-4357-a7b5-643df2960ee4 2023-11-04 09:16:00,051 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:16:00,052 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-11-04 09:16:00,052 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Inode count: 7749632 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Block count: 30982912 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Reserved block count: 1549145 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Overhead clusters: 632916 2023-11-04 09:16:00,052 DEBUG probert.utils:50 Free blocks: 27757623 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Free inodes: 7511051 2023-11-04 09:16:00,053 DEBUG probert.utils:50 First block: 0 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Inodes per group: 8192 2023-11-04 09:16:00,053 DEBUG probert.utils:50 Inode blocks per group: 512 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Filesystem created: Fri Nov 3 18:59:47 2023 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Last mount time: Fri Nov 3 19:42:38 2023 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Last write time: Fri Nov 3 19:42:37 2023 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Mount count: 2 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Last checked: Fri Nov 3 18:59:47 2023 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Lifetime writes: 9 GB 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:16:00,054 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:16:00,054 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Directory Hash Seed: e484c3e8-7003-4d0a-a7f9-e571800d56b8 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Checksum: 0x4850f4d7 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Journal features: journal_incompat_revoke journal_64bit journal_checksum_v3 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Total journal size: 512M 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Total journal blocks: 131072 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Max transaction length: 131072 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:16:00,055 DEBUG probert.utils:50 Journal sequence: 0x00000be4 2023-11-04 09:16:00,056 DEBUG probert.utils:50 Journal start: 0 2023-11-04 09:16:00,056 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:16:00,056 DEBUG probert.utils:50 Journal checksum: 0x2cb1136e 2023-11-04 09:16:00,056 DEBUG probert.utils:50 2023-11-04 09:16:00,056 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:00,056 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:00,056 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:00,059 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sdb4` exited with result: 0 2023-11-04 09:16:00,059 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:00,059 DEBUG probert.utils:50 Filesystem volume name: writable 2023-11-04 09:16:00,059 DEBUG probert.utils:50 Last mounted on: /root/var/crash 2023-11-04 09:16:00,059 DEBUG probert.utils:50 Filesystem UUID: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 2023-11-04 09:16:00,059 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Filesystem features: has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Inode count: 1594320 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Block count: 6373632 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Reserved block count: 318681 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Overhead clusters: 144122 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Free blocks: 6229504 2023-11-04 09:16:00,060 DEBUG probert.utils:50 Free inodes: 1594309 2023-11-04 09:16:00,061 DEBUG probert.utils:50 First block: 0 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Inodes per group: 8176 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Inode blocks per group: 511 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Filesystem created: Sat Nov 4 09:12:26 2023 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Last mount time: Sat Nov 4 09:12:37 2023 2023-11-04 09:16:00,061 DEBUG probert.utils:50 Last write time: Sat Nov 4 09:12:37 2023 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Mount count: 1 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Last checked: Sat Nov 4 09:12:26 2023 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Lifetime writes: 4170 kB 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:16:00,062 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:16:00,062 DEBUG probert.utils:50 Directory Hash Seed: ab849d65-1210-44a5-aed3-7209cc390ec9 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Checksum: 0xa507f22c 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal features: journal_incompat_revoke journal_64bit journal_checksum_v3 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Total journal size: 128M 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Total journal blocks: 32768 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Max transaction length: 32768 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal sequence: 0x00000002 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal start: 1 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:16:00,063 DEBUG probert.utils:50 Journal checksum: 0x8f5f0ca5 2023-11-04 09:16:00,063 DEBUG probert.utils:50 2023-11-04 09:16:00,064 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:00,064 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:00,064 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:00,066 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0 2023-11-04 09:16:00,067 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:00,067 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 2903967 2023-11-04 09:16:00,067 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:00,067 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:00,067 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:00,070 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sdb4` exited with result: 0 2023-11-04 09:16:00,070 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:00,070 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 49054 2023-11-04 09:16:00,070 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:00,070 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:00,070 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:00,076 DEBUG curtin:1325 Extracting storage config from probe data 2023-11-04 09:16:00,077 DEBUG curtin:73 /dev/sda is multipath device member? False 2023-11-04 09:16:00,077 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:00,077 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:00,077 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:00,077 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:00,101 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:00,102 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:00,102 DEBUG curtin:61 /dev/sda1 is multipath device? False 2023-11-04 09:16:00,102 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:00,102 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:00,126 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:00,126 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:00,127 DEBUG curtin:61 /dev/sda2 is multipath device? False 2023-11-04 09:16:00,127 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:00,127 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:00,152 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:00,152 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:00,152 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:00,152 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:00,152 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:00,177 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:00,178 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:00,178 DEBUG curtin:61 /dev/sdb1 is multipath device? False 2023-11-04 09:16:00,178 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:00,178 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:00,203 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:00,204 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:00,204 DEBUG curtin:61 /dev/sdb2 is multipath device? False 2023-11-04 09:16:00,204 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:00,204 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:00,230 DEBUG curtin:73 /dev/sdb3 is multipath device member? False 2023-11-04 09:16:00,230 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:00,230 DEBUG curtin:61 /dev/sdb3 is multipath device? False 2023-11-04 09:16:00,230 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:00,230 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:00,255 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:00,256 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:00,256 DEBUG curtin:61 /dev/sdb4 is multipath device? False 2023-11-04 09:16:00,256 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:00,256 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:00,282 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:00,309 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:00,334 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:00,361 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:00,387 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:00,413 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:00,465 DEBUG curtin:1332 Sorting extracted configurations 2023-11-04 09:16:00,466 INFO curtin:1351 Validating extracted storage config components 2023-11-04 09:16:00,514 DEBUG curtin:1368 Extracted (unmerged) storage config: storage: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount 2023-11-04 09:16:00,514 DEBUG curtin:1372 Generating storage config dependencies 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sdb3:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,515 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: format-disk-sdb:SourceType:format -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: format-partition-sdb2:SourceType:format -> (DepId:partition-sdb2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,516 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: format-partition-sdb4:SourceType:format -> (DepId:partition-sdb4 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: mount-partition-sdb1:SourceType:mount -> (DepId:format-partition-sdb1 DepType:format) in SourceDeps:{'format'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:00,517 DEBUG curtin:1378 Merging storage config dependencies 2023-11-04 09:16:00,530 DEBUG curtin:1383 Merged storage config: storage: config: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 type: disk - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount version: 2 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='FORESEE_128GB_SSD_K44700J003729', wwn='0x502b2a201d1c1b1a', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:16': Disk(ptable='gpt', serial='Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0', path='/dev/sdb', preserve=True, id='disk-sdb', 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='0e39f173-0767-412b-83d7-fd6dc6130ef8', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=126906007552, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='7f8a493b-1a79-4503-b572-c3bc67bf3615', id='partition-sda2', type='partition'), '8:17': Partition(device=disk-sdb, size=4882786304, number=1, preserve=True, offset=32768, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb1', uuid='3417995c-5bfb-493f-befa-2f58410ff177', id='partition-sdb1', type='partition'), '8:18': Partition(device=disk-sdb, size=5138432, flag='boot', number=2, preserve=True, offset=4882819072, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sdb2', uuid='3417995c-5bfb-493f-bef9-2f58410ff177', id='partition-sdb2', type='partition'), '8:19': Partition(device=disk-sdb, size=307200, number=3, preserve=True, offset=4887957504, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb3', uuid='3417995c-5bfb-493f-bef8-2f58410ff177', id='partition-sdb3', type='partition'), '8:20': Partition(device=disk-sdb, size=26106396672, flag='linux', number=4, preserve=True, offset=4888461312, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sdb4', uuid='82f5e486-652d-46d3-89ec-01ed752e28ff', id='partition-sdb4', type='partition')} 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 8:17 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1480 /dev/sdb1 is mounted 2023-11-04 09:16:00,531 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:00,532 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 0:88 2023-11-04 09:16:00,533 DEBUG subiquity.models.filesystem:1475 considering mount of 0:88 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:88 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:33 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34 2023-11-04 09:16:00,534 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:48 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:00,535 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 7:13 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 7:14 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:88 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:51 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90 2023-11-04 09:16:00,536 DEBUG subiquity.models.filesystem:1475 considering mount of 0:91 2023-11-04 09:16:00,537 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-11-04 09:16:00,537 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 1.1 seconds 2023-11-04 09:16:00,537 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor 2023-11-04 09:16:00,537 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-11-04 09:16:02,871 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/systems/enhanced-secureboot-desktop HTTP/1.1" 200 None 2023-11-04 09:16:02,874 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'umount', '/var/lib/snapd/seed/snaps/pc_161.snap'] 2023-11-04 09:16:02,945 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'umount', '/var/lib/snapd/seed/snaps/pc-kernel_1500.snap'] 2023-11-04 09:16:03,009 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'umount', '/var/lib/snapd/seed/systems'] 2023-11-04 09:16:03,066 DEBUG curtin:95 Running command ['umount', '/tmp/tmp4o3cc1m0/root.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:03,073 DEBUG curtin:95 Running command ['umount', '/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.en.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:03,081 DEBUG curtin:95 Running command ['umount', '/tmp/tmp4o3cc1m0/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:03,125 DEBUG curtin:95 Running command ['umount', '/tmp/tmp4o3cc1m0/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:03,135 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=, storage_safety=, encryption_type=, unavailable_reason='not encrypting device storage as checking TPM gave: the TPM is in DA lockout mode')) 2023-11-04 09:16:03,136 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=, storage_safety=, encryption_type=, unavailable_reason='not encrypting device storage as checking TPM gave: the TPM is in DA lockout mode')) for variation minimal-enhanced-secureboot 2023-11-04 09:16:03,136 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:03,150 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:03,151 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor 2023-11-04 09:16:03,151 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:16:03,166 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:16:03,166 DEBUG subiquity.server.controllers.filesystem:1499 Triggered Probert run on udev event 2023-11-04 09:16:03,166 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-11-04 09:16:03,167 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-11-04 09:16:03,168 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-11-04 09:16:03,169 DEBUG asyncio:54 Using selector: EpollSelector 2023-11-04 09:16:03,171 DEBUG probert.dasd:134 Probing DASD devies 2023-11-04 09:16:03,171 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-11-04 09:16:03,838 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-11-04 09:16:03,840 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-11-04 09:16:03,850 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sda2` exited with result: 0 2023-11-04 09:16:03,850 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem volume name: 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Last mounted on: / 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem UUID: dba65023-a29a-4357-a7b5-643df2960ee4 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:16:03,850 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-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:16:03,850 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Inode count: 7749632 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Block count: 30982912 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Reserved block count: 1549145 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Overhead clusters: 632916 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Free blocks: 27757623 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Free inodes: 7511051 2023-11-04 09:16:03,851 DEBUG probert.utils:50 First block: 0 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:16:03,851 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Inodes per group: 8192 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Inode blocks per group: 512 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Filesystem created: Fri Nov 3 18:59:47 2023 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Last mount time: Fri Nov 3 19:42:38 2023 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Last write time: Fri Nov 3 19:42:37 2023 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Mount count: 2 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Last checked: Fri Nov 3 18:59:47 2023 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Lifetime writes: 9 GB 2023-11-04 09:16:03,852 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:16:03,853 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Directory Hash Seed: e484c3e8-7003-4d0a-a7f9-e571800d56b8 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:16:03,853 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Checksum: 0x4850f4d7 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Journal features: journal_incompat_revoke journal_64bit journal_checksum_v3 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Total journal size: 512M 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Total journal blocks: 131072 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Max transaction length: 131072 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Journal sequence: 0x00000be4 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Journal start: 0 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:16:03,854 DEBUG probert.utils:50 Journal checksum: 0x2cb1136e 2023-11-04 09:16:03,854 DEBUG probert.utils:50 2023-11-04 09:16:03,854 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:03,854 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:03,854 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:03,856 DEBUG probert.utils:85 Command `/usr/sbin/dumpe2fs -h /dev/sdb4` exited with result: 0 2023-11-04 09:16:03,856 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem volume name: writable 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Last mounted on: /root/var/crash 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem UUID: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem magic number: 0xEF53 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem revision #: 1 (dynamic) 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem features: has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem flags: signed_directory_hash 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Default mount options: user_xattr acl 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Filesystem state: clean 2023-11-04 09:16:03,857 DEBUG probert.utils:50 Errors behavior: Continue 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Filesystem OS type: Linux 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Inode count: 1594320 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Block count: 6373632 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Reserved block count: 318681 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Overhead clusters: 144122 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Free blocks: 6229504 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Free inodes: 1594309 2023-11-04 09:16:03,858 DEBUG probert.utils:50 First block: 0 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Block size: 4096 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Fragment size: 4096 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Group descriptor size: 64 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Reserved GDT blocks: 1024 2023-11-04 09:16:03,858 DEBUG probert.utils:50 Blocks per group: 32768 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Fragments per group: 32768 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Inodes per group: 8176 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Inode blocks per group: 511 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Flex block group size: 16 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Filesystem created: Sat Nov 4 09:12:26 2023 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Last mount time: Sat Nov 4 09:12:37 2023 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Last write time: Sat Nov 4 09:12:37 2023 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Mount count: 1 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Maximum mount count: -1 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Last checked: Sat Nov 4 09:12:26 2023 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Check interval: 0 () 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Lifetime writes: 4170 kB 2023-11-04 09:16:03,859 DEBUG probert.utils:50 Reserved blocks uid: 0 (user root) 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Reserved blocks gid: 0 (group root) 2023-11-04 09:16:03,860 DEBUG probert.utils:50 First inode: 11 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Inode size: 256 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Required extra isize: 32 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Desired extra isize: 32 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Journal inode: 8 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Default directory hash: half_md4 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Directory Hash Seed: ab849d65-1210-44a5-aed3-7209cc390ec9 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Journal backup: inode blocks 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Checksum type: crc32c 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Checksum: 0xa507f22c 2023-11-04 09:16:03,860 DEBUG probert.utils:50 Journal features: journal_incompat_revoke journal_64bit journal_checksum_v3 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Total journal size: 128M 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Total journal blocks: 32768 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Max transaction length: 32768 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Fast commit length: 0 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Journal sequence: 0x00000002 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Journal start: 1 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Journal checksum type: crc32c 2023-11-04 09:16:03,861 DEBUG probert.utils:50 Journal checksum: 0x8f5f0ca5 2023-11-04 09:16:03,861 DEBUG probert.utils:50 2023-11-04 09:16:03,861 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:03,861 DEBUG probert.utils:50 dumpe2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:03,861 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:03,864 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sda2` exited with result: 0 2023-11-04 09:16:03,864 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:03,864 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 2903967 2023-11-04 09:16:03,864 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:03,864 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:03,864 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:03,865 DEBUG probert.utils:85 Command `/usr/sbin/resize2fs -P /dev/sdb4` exited with result: 0 2023-11-04 09:16:03,865 DEBUG probert.utils:48 stdout: ------------------------------------------ 2023-11-04 09:16:03,865 DEBUG probert.utils:50 Estimated minimum size of the filesystem: 49067 2023-11-04 09:16:03,866 DEBUG probert.utils:48 stderr: ------------------------------------------ 2023-11-04 09:16:03,866 DEBUG probert.utils:50 resize2fs 1.47.0 (5-Feb-2023) 2023-11-04 09:16:03,866 DEBUG probert.utils:88 -------------------------------------------------- 2023-11-04 09:16:03,871 DEBUG curtin:1325 Extracting storage config from probe data 2023-11-04 09:16:03,871 DEBUG curtin:73 /dev/sda is multipath device member? False 2023-11-04 09:16:03,871 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:03,871 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:03,871 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:03,871 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:03,894 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:03,895 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:03,895 DEBUG curtin:61 /dev/sda1 is multipath device? False 2023-11-04 09:16:03,895 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:03,895 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:03,917 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:03,917 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:03,917 DEBUG curtin:61 /dev/sda2 is multipath device? False 2023-11-04 09:16:03,917 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:03,917 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:03,941 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:03,941 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:03,941 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:03,941 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:03,941 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:03,964 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:03,964 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:03,964 DEBUG curtin:61 /dev/sdb1 is multipath device? False 2023-11-04 09:16:03,964 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:03,964 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:03,986 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:03,986 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:03,986 DEBUG curtin:61 /dev/sdb2 is multipath device? False 2023-11-04 09:16:03,986 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:03,987 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:04,008 DEBUG curtin:73 /dev/sdb3 is multipath device member? False 2023-11-04 09:16:04,009 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:04,009 DEBUG curtin:61 /dev/sdb3 is multipath device? False 2023-11-04 09:16:04,009 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:04,009 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:04,031 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:04,031 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:04,031 DEBUG curtin:61 /dev/sdb4 is multipath device? False 2023-11-04 09:16:04,031 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:04,031 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:04,053 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:04,076 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:04,097 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:04,118 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:04,140 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:04,162 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:04,206 DEBUG curtin:1332 Sorting extracted configurations 2023-11-04 09:16:04,206 INFO curtin:1351 Validating extracted storage config components 2023-11-04 09:16:04,248 DEBUG curtin:1368 Extracted (unmerged) storage config: storage: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount 2023-11-04 09:16:04,248 DEBUG curtin:1372 Generating storage config dependencies 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sdb3:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,249 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: format-disk-sdb:SourceType:format -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: format-partition-sdb2:SourceType:format -> (DepId:partition-sdb2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,250 DEBUG curtin:238 Validate: format-partition-sdb4:SourceType:format -> (DepId:partition-sdb4 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,251 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,251 DEBUG curtin:238 Validate: mount-partition-sdb1:SourceType:mount -> (DepId:format-partition-sdb1 DepType:format) in SourceDeps:{'format'} ? result=True 2023-11-04 09:16:04,251 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:04,251 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:04,251 DEBUG curtin:1378 Merging storage config dependencies 2023-11-04 09:16:04,262 DEBUG curtin:1383 Merged storage config: storage: config: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 type: disk - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount version: 2 2023-11-04 09:16:04,262 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='FORESEE_128GB_SSD_K44700J003729', wwn='0x502b2a201d1c1b1a', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:16': Disk(ptable='gpt', serial='Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0', path='/dev/sdb', preserve=True, id='disk-sdb', 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='0e39f173-0767-412b-83d7-fd6dc6130ef8', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=126906007552, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='7f8a493b-1a79-4503-b572-c3bc67bf3615', id='partition-sda2', type='partition'), '8:17': Partition(device=disk-sdb, size=4882786304, number=1, preserve=True, offset=32768, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb1', uuid='3417995c-5bfb-493f-befa-2f58410ff177', id='partition-sdb1', type='partition'), '8:18': Partition(device=disk-sdb, size=5138432, flag='boot', number=2, preserve=True, offset=4882819072, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sdb2', uuid='3417995c-5bfb-493f-bef9-2f58410ff177', id='partition-sdb2', type='partition'), '8:19': Partition(device=disk-sdb, size=307200, number=3, preserve=True, offset=4887957504, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb3', uuid='3417995c-5bfb-493f-bef8-2f58410ff177', id='partition-sdb3', type='partition'), '8:20': Partition(device=disk-sdb, size=26106396672, flag='linux', number=4, preserve=True, offset=4888461312, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sdb4', uuid='82f5e486-652d-46d3-89ec-01ed752e28ff', id='partition-sdb4', type='partition')} 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 8:17 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1480 /dev/sdb1 is mounted 2023-11-04 09:16:04,263 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:04,264 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:33 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34 2023-11-04 09:16:04,265 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:48 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:51 2023-11-04 09:16:04,266 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:04,267 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:04,267 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:04,267 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:04,267 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90 2023-11-04 09:16:04,267 DEBUG subiquity.models.filesystem:1475 considering mount of 0:91 2023-11-04 09:16:04,267 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-11-04 09:16:04,267 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 1.1 seconds 2023-11-04 09:16:04,267 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor 2023-11-04 09:16:04,268 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-11-04 09:16:04,268 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:04,273 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:04,275 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 2023-11-04 09:16:04,276 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:04,279 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di... 2023-11-04 09:16:04,281 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 2023-11-04 09:16:04,281 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 [] 2023-11-04 09:16:15,947 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 2023-11-04 09:16:15,947 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 [] 2023-11-04 09:16:15,949 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-11-04 09:16:15,949 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:15,956 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:15,958 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 2023-11-04 09:16:15,959 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:15,962 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di... 2023-11-04 09:16:15,965 DEBUG root:30 start: subiquity/Filesystem/v2_guided_POST: 2023-11-04 09:16:15,965 DEBUG subiquity.server.controllers.filesystem:1152 GuidedChoiceV2(target=GuidedStorageTargetReformat(disk_id='disk-sda', allowed=[, , , , ], disallowed=[GuidedDisallowedCapability(capability=, reason=, message='not encrypting device storage as checking TPM gave: the TPM is in DA lockout mode')]), capability=, recovery_key=None, sizing_policy=, reset_partition=False) 2023-11-04 09:16:15,967 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-11-04 09:16:15,967 DEBUG subiquity.models.filesystem:2105 adding ext4 to Partition(device=disk-sda, size=126906007552, wipe='superblock', number=2, grub_device=None, offset=1128267776, id='partition-1') 2023-11-04 09:16:15,967 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:15,970 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": {"target": {"disk_id":... 2023-11-04 09:16:15,973 DEBUG root:30 start: subiquity/Filesystem/v2_POST: 2023-11-04 09:16:15,973 DEBUG subiquity.models.subiquity:256 model filesystem for install stage is configured, to go {'network'} 2023-11-04 09:16:15,973 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor 2023-11-04 09:16:15,974 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:15,979 DEBUG root:30 finish: subiquity/Filesystem/v2_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:15,982 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-11-04 09:16:15,982 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:15,988 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:15,990 DEBUG root:30 start: subiquity/Filesystem/v2_orig_config_GET: 2023-11-04 09:16:15,991 DEBUG curtin:1325 Extracting storage config from probe data 2023-11-04 09:16:15,991 DEBUG curtin:73 /dev/sda is multipath device member? False 2023-11-04 09:16:15,991 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:15,991 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:15,991 DEBUG curtin:86 /dev/sda is multipath device partition? False 2023-11-04 09:16:15,991 DEBUG curtin:61 /dev/sda is multipath device? False 2023-11-04 09:16:16,016 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:16,017 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:16,017 DEBUG curtin:61 /dev/sda1 is multipath device? False 2023-11-04 09:16:16,017 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:16,017 DEBUG curtin:86 /dev/sda1 is multipath device partition? False 2023-11-04 09:16:16,042 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:16,043 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:16,043 DEBUG curtin:61 /dev/sda2 is multipath device? False 2023-11-04 09:16:16,043 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:16,043 DEBUG curtin:86 /dev/sda2 is multipath device partition? False 2023-11-04 09:16:16,068 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:16,068 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:16,068 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:16,068 DEBUG curtin:86 /dev/sdb is multipath device partition? False 2023-11-04 09:16:16,069 DEBUG curtin:61 /dev/sdb is multipath device? False 2023-11-04 09:16:16,094 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:16,095 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:16,095 DEBUG curtin:61 /dev/sdb1 is multipath device? False 2023-11-04 09:16:16,095 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:16,095 DEBUG curtin:86 /dev/sdb1 is multipath device partition? False 2023-11-04 09:16:16,120 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:16,120 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:16,120 DEBUG curtin:61 /dev/sdb2 is multipath device? False 2023-11-04 09:16:16,120 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:16,120 DEBUG curtin:86 /dev/sdb2 is multipath device partition? False 2023-11-04 09:16:16,145 DEBUG curtin:73 /dev/sdb3 is multipath device member? False 2023-11-04 09:16:16,145 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:16,145 DEBUG curtin:61 /dev/sdb3 is multipath device? False 2023-11-04 09:16:16,145 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:16,145 DEBUG curtin:86 /dev/sdb3 is multipath device partition? False 2023-11-04 09:16:16,171 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:16,171 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:16,171 DEBUG curtin:61 /dev/sdb4 is multipath device? False 2023-11-04 09:16:16,172 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:16,172 DEBUG curtin:86 /dev/sdb4 is multipath device partition? False 2023-11-04 09:16:16,196 DEBUG curtin:73 /dev/sda1 is multipath device member? False 2023-11-04 09:16:16,220 DEBUG curtin:73 /dev/sdb is multipath device member? False 2023-11-04 09:16:16,245 DEBUG curtin:73 /dev/sdb1 is multipath device member? False 2023-11-04 09:16:16,269 DEBUG curtin:73 /dev/sdb2 is multipath device member? False 2023-11-04 09:16:16,294 DEBUG curtin:73 /dev/sda2 is multipath device member? False 2023-11-04 09:16:16,318 DEBUG curtin:73 /dev/sdb4 is multipath device member? False 2023-11-04 09:16:16,367 DEBUG curtin:1332 Sorting extracted configurations 2023-11-04 09:16:16,367 INFO curtin:1351 Validating extracted storage config components 2023-11-04 09:16:16,413 DEBUG curtin:1368 Extracted (unmerged) storage config: storage: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount 2023-11-04 09:16:16,413 DEBUG curtin:1372 Generating storage config dependencies 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sdb3:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,414 DEBUG curtin:238 Validate: format-partition-sda1:SourceType:format -> (DepId:partition-sda1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: partition-sda1:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: format-disk-sdb:SourceType:format -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: format-partition-sdb2:SourceType:format -> (DepId:partition-sdb2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: partition-sdb2:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: format-partition-sda2:SourceType:format -> (DepId:partition-sda2 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,415 DEBUG curtin:238 Validate: partition-sda2:SourceType:partition -> (DepId:disk-sda DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:238 Validate: format-partition-sdb4:SourceType:format -> (DepId:partition-sdb4 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:238 Validate: partition-sdb4:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:238 Validate: mount-partition-sdb1:SourceType:mount -> (DepId:format-partition-sdb1 DepType:format) in SourceDeps:{'format'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:238 Validate: format-partition-sdb1:SourceType:format -> (DepId:partition-sdb1 DepType:partition) in SourceDeps:{'dm_crypt', 'partition', 'raid', 'bcache', 'disk', 'lvm_partition'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:238 Validate: partition-sdb1:SourceType:partition -> (DepId:disk-sdb DepType:disk) in SourceDeps:{'disk', 'partition', 'raid', 'bcache'} ? result=True 2023-11-04 09:16:16,416 DEBUG curtin:1378 Merging storage config dependencies 2023-11-04 09:16:16,427 DEBUG curtin:1383 Merged storage config: storage: config: - id: disk-sda path: /dev/sda ptable: gpt serial: FORESEE_128GB_SSD_K44700J003729 type: disk wwn: '0x502b2a201d1c1b1a' - id: disk-sdb path: /dev/sdb ptable: gpt serial: Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0 type: disk - fstype: iso9660 id: format-disk-sdb type: format volume: disk-sdb - 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: 0e39f173-0767-412b-83d7-fd6dc6130ef8 - device: disk-sda flag: linux id: partition-sda2 number: 2 offset: 1128267776 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sda2 size: 126906007552 type: partition uuid: 7f8a493b-1a79-4503-b572-c3bc67bf3615 - fstype: vfat id: format-partition-sda1 type: format volume: partition-sda1 - fstype: ext4 id: format-partition-sda2 type: format uuid: dba65023-a29a-4357-a7b5-643df2960ee4 volume: partition-sda2 - device: disk-sdb id: partition-sdb1 number: 1 offset: 32768 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb1 size: 4882786304 type: partition uuid: 3417995c-5bfb-493f-befa-2f58410ff177 - device: disk-sdb flag: boot id: partition-sdb2 number: 2 offset: 4882819072 partition_type: c12a7328-f81f-11d2-ba4b-00a0c93ec93b path: /dev/sdb2 size: 5138432 type: partition uuid: 3417995c-5bfb-493f-bef9-2f58410ff177 - device: disk-sdb id: partition-sdb3 number: 3 offset: 4887957504 partition_type: ebd0a0a2-b9e5-4433-87c0-68b6b72699c7 path: /dev/sdb3 size: 307200 type: partition uuid: 3417995c-5bfb-493f-bef8-2f58410ff177 - device: disk-sdb flag: linux id: partition-sdb4 number: 4 offset: 4888461312 partition_type: 0fc63daf-8483-4772-8e79-3d69d8477de4 path: /dev/sdb4 size: 26106396672 type: partition uuid: 82f5e486-652d-46d3-89ec-01ed752e28ff - fstype: iso9660 id: format-partition-sdb1 type: format volume: partition-sdb1 - fstype: vfat id: format-partition-sdb2 type: format volume: partition-sdb2 - fstype: ext4 id: format-partition-sdb4 type: format uuid: 08fe881e-0b56-4c2c-9cef-2bf00d225cc0 volume: partition-sdb4 - device: format-partition-sdb1 id: mount-partition-sdb1 path: /cdrom type: mount version: 2 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'8:0': Disk(ptable='gpt', serial='FORESEE_128GB_SSD_K44700J003729', wwn='0x502b2a201d1c1b1a', path='/dev/sda', preserve=True, id='disk-sda', type='disk'), '8:16': Disk(ptable='gpt', serial='Kingston_DataTraveler_3.0_40B0767E21E6157106584887-0:0', path='/dev/sdb', preserve=True, id='disk-sdb', 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='0e39f173-0767-412b-83d7-fd6dc6130ef8', id='partition-sda1', type='partition'), '8:2': Partition(device=disk-sda, size=126906007552, flag='linux', number=2, preserve=True, offset=1128267776, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sda2', uuid='7f8a493b-1a79-4503-b572-c3bc67bf3615', id='partition-sda2', type='partition'), '8:17': Partition(device=disk-sdb, size=4882786304, number=1, preserve=True, offset=32768, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb1', uuid='3417995c-5bfb-493f-befa-2f58410ff177', id='partition-sdb1', type='partition'), '8:18': Partition(device=disk-sdb, size=5138432, flag='boot', number=2, preserve=True, offset=4882819072, partition_type='c12a7328-f81f-11d2-ba4b-00a0c93ec93b', path='/dev/sdb2', uuid='3417995c-5bfb-493f-bef9-2f58410ff177', id='partition-sdb2', type='partition'), '8:19': Partition(device=disk-sdb, size=307200, number=3, preserve=True, offset=4887957504, partition_type='ebd0a0a2-b9e5-4433-87c0-68b6b72699c7', path='/dev/sdb3', uuid='3417995c-5bfb-493f-bef8-2f58410ff177', id='partition-sdb3', type='partition'), '8:20': Partition(device=disk-sdb, size=26106396672, flag='linux', number=4, preserve=True, offset=4888461312, partition_type='0fc63daf-8483-4772-8e79-3d69d8477de4', path='/dev/sdb4', uuid='82f5e486-652d-46d3-89ec-01ed752e28ff', id='partition-sdb4', type='partition')} 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 0:22 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 0:23 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 0:5 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:16,428 DEBUG subiquity.models.filesystem:1475 considering mount of 8:17 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1480 /dev/sdb1 is mounted 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:0 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 8:20 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1480 /dev/sdb4 is mounted 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 0:44 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:16,429 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:28 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:26 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:6 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:35 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:36 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:37 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:12 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:7 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:40 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:21 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:38 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:24 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:33 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:20 2023-11-04 09:16:16,430 DEBUG subiquity.models.filesystem:1475 considering mount of 0:39 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:34 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:41 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:42 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:43 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:25 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:46 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:48 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:89 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:4 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:5 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:6 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:3 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:9 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:11 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:7 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:12 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:10 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 7:8 2023-11-04 09:16:16,431 DEBUG subiquity.models.filesystem:1475 considering mount of 0:51 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:4 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:90 2023-11-04 09:16:16,432 DEBUG subiquity.models.filesystem:1475 considering mount of 0:91 2023-11-04 09:16:16,432 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 8.286G 2023-11-04 09:16:16,437 DEBUG root:30 finish: subiquity/Filesystem/v2_orig_config_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-sda", "label"... 2023-11-04 09:16:17,837 DEBUG root:30 start: subiquity/TimeZone/GET: 2023-11-04 09:16:17,838 DEBUG root:30 finish: subiquity/TimeZone/GET: SUCCESS: 200 {"timezone": "Atlantic/Reykjavik", "from_geoip": true} 2023-11-04 09:16:17,995 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:16:18,021 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:16:18,022 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:16:18,037 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-11-04 09:16:18,038 DEBUG subiquitycore.models.network:467 has_network True 2023-11-04 09:16:18,038 DEBUG subiquity.models.subiquity:256 model network for install stage is configured, to go set() 2023-11-04 09:16:18,038 DEBUG subiquity.models.subiquity:256 model network for postinstall stage is configured, to go {'timezone', 'identity'} 2023-11-04 09:16:18,039 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-11-04 09:16:18,041 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "NEEDS_CONFIRMATION", "confirming_tty": "", "error": null, "cloud_i... 2023-11-04 09:16:18,044 INFO root:30 start: subiquity/Meta/confirm_POST: 2023-11-04 09:16:18,045 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'timezone', 'identity'} 2023-11-04 09:16:18,046 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'timezone', 'identity'} 2023-11-04 09:16:18,046 INFO root:30 finish: subiquity/Meta/confirm_POST: SUCCESS: 200 null 2023-11-04 09:16:18,047 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_confirmation: SUCCESS: 2023-11-04 09:16:18,047 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_apt: 2023-11-04 09:16:18,048 INFO root:30 start: subiquity/Install/install/configure_apt: configuring apt 2023-11-04 09:16:18,050 DEBUG root:30 start: subiquity/Mirror/waiting: 2023-11-04 09:16:18,051 DEBUG root:30 finish: subiquity/Mirror/waiting: SUCCESS: 2023-11-04 09:16:18,051 DEBUG subiquity.server.controllers.mirror:202 Iterating over country-mirror 2023-11-04 09:16:18,051 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.en.squashfs'] 2023-11-04 09:16:18,051 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmpu8vk5jsg/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:18,062 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.en.squashfs', '/tmp/tmpu8vk5jsg/minimal.en.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:18,073 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmpu8vk5jsg/minimal.en.squashfs.dir:/tmp/tmpu8vk5jsg/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmpu8vk5jsg/root.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:18,091 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'lowerdir=/tmp/tmpu8vk5jsg/root.dir,upperdir=/tmp/tmp0yauwcfv/upper,workdir=/tmp/tmp0yauwcfv/work', '-t', 'overlay', 'overlay', '/tmp/tmp0yauwcfv/mount'] 2023-11-04 09:16:18,111 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:16:18,112 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-11-04 09:16:18,115 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:16:18,206 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.1"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmp0yauwcfv/mount'] 2023-11-04 09:16:18,929 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:16:18,961 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:16:18,962 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'NOVA-K6LAQ9', 'no status'), (b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status')]} 2023-11-04 09:16:18,962 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:16:18,981 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:16:19,301 DEBUG root:30 start: subiquity/TimeZone/POST: 2023-11-04 09:16:19,504 DEBUG subiquity.models.subiquity:256 model timezone for postinstall stage is configured, to go {'identity'} 2023-11-04 09:16:19,504 DEBUG root:30 finish: subiquity/TimeZone/POST: SUCCESS: 200 null 2023-11-04 09:16:19,508 DEBUG root:30 start: subiquity/Identity/GET: 2023-11-04 09:16:19,508 DEBUG root:30 finish: subiquity/Identity/GET: SUCCESS: 200 {"realname": "", "username": "", "crypted_password": "", "hostname": ""} 2023-11-04 09:16:19,512 DEBUG root:30 start: subiquity/Ad/has_support_GET: 2023-11-04 09:16:19,514 DEBUG root:30 finish: subiquity/Ad/has_support_GET: SUCCESS: 200 true 2023-11-04 09:16:20,439 DEBUG root:30 start: subiquity/Mirror/cmd-apt-config: curtin command apt-config 2023-11-04 09:16:20,975 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:16:21,076 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:16:21,177 DEBUG subiquity.server.curtin:130 waited 0.30000000000000004 seconds for events to drain 2023-11-04 09:16:21,228 DEBUG root:30 finish: subiquity/Mirror/cmd-apt-config: SUCCESS: curtin command apt-config 2023-11-04 09:16:21,279 DEBUG subiquity.server.curtin:130 waited 0.4 seconds for events to drain 2023-11-04 09:16:21,283 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-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:176 Mirror checking successful 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:178 APT output follows 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:180 Get:1 https://is.archive.ubuntu.com/ubuntu noble InRelease [213 kB] 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:180 Hit:2 https://is.archive.ubuntu.com/ubuntu noble-updates InRelease 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:180 Get:3 https://is.archive.ubuntu.com/ubuntu noble-backports InRelease [74.9 kB] 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:180 Fetched 288 kB in 1s (338 kB/s) 2023-11-04 09:16:22,857 DEBUG subiquity.server.controllers.mirror:180 Reading package lists... 2023-11-04 09:16:22,857 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.en.squashfs'] 2023-11-04 09:16:22,858 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp2mc8u9z9/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:22,884 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.en.squashfs', '/tmp/tmp2mc8u9z9/minimal.en.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:22,903 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp2mc8u9z9/minimal.en.squashfs.dir:/tmp/tmp2mc8u9z9/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp2mc8u9z9/root.dir'] with allowed return codes [0] (capture=True) 2023-11-04 09:16:22,927 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'lowerdir=/tmp/tmp2mc8u9z9/root.dir,upperdir=/tmp/tmp36cs24bi/upper,workdir=/tmp/tmp36cs24bi/work', '-t', 'overlay', 'overlay', '/tmp/tmp36cs24bi/mount'] 2023-11-04 09:16:22,997 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.2"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmp36cs24bi/mount'] 2023-11-04 09:16:23,975 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-11-04 09:16:23,976 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-11-04 09:16:24,888 DEBUG root:30 start: subiquity/Mirror/cmd-apt-config: curtin command apt-config 2023-11-04 09:16:24,926 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-11-04 09:16:24,927 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-11-04 09:16:25,186 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:16:25,226 DEBUG root:30 finish: subiquity/Mirror/cmd-apt-config: SUCCESS: curtin command apt-config 2023-11-04 09:16:25,287 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:16:25,288 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'lowerdir=/tmp/tmp36cs24bi/upper:/tmp/tmp2mc8u9z9/root.dir,upperdir=/tmp/tmpaer8kg27/upper,workdir=/tmp/tmpaer8kg27/work', '-t', 'overlay', 'overlay', '/tmp/tmpaer8kg27/mount'] 2023-11-04 09:16:25,363 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'bind', '/cdrom', '/tmp/tmpaer8kg27/mount/cdrom'] 2023-11-04 09:16:25,440 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.3"}}', 'in-target', '-t', '/tmp/tmpaer8kg27/mount', '--', 'apt-get', 'update'] 2023-11-04 09:16:27,220 DEBUG root:30 start: subiquity/Install/install/configure_apt/cmd-in-target: curtin command in-target 2023-11-04 09:16:30,017 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-11-04 09:16:30,018 DEBUG subiquity.models.subiquity:256 model active_directory for postinstall stage is configured, to go {'identity'} 2023-11-04 09:16:30,018 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-11-04 09:16:30,097 DEBUG root:30 start: subiquity/Identity/POST: 2023-11-04 09:16:30,098 DEBUG subiquity.models.subiquity:256 model identity for postinstall stage is configured, to go set() 2023-11-04 09:16:30,098 DEBUG root:30 finish: subiquity/Identity/POST: SUCCESS: 200 null 2023-11-04 09:16:30,952 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:16:30,953 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-11-04 09:16:31,076 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:16:31,077 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-11-04 09:16:31,459 INFO root:30 start: subiquity/Meta/status_GET: 2023-11-04 09:16:36,791 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:16:36,892 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:16:36,973 DEBUG root:30 finish: subiquity/Install/install/configure_apt/cmd-in-target: SUCCESS: curtin command in-target 2023-11-04 09:16:36,992 DEBUG subiquity.server.curtin:130 waited 0.30000000000000004 seconds for events to drain 2023-11-04 09:16:36,993 INFO root:30 finish: subiquity/Install/install/configure_apt: SUCCESS: configuring apt 2023-11-04 09:16:36,994 INFO root:30 start: subiquity/Install/install/curtin_install: installing system 2023-11-04 09:16:36,995 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step: executing curtin install initial step 2023-11-04 09:16:36,998 DEBUG root:30 finish: subiquity/Drivers/_list_drivers/wait_apt: SUCCESS: 2023-11-04 09:16:36,998 DEBUG root:30 finish: subiquity/Drivers/_list_drivers: SUCCESS: 2023-11-04 09:16:36,998 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_apt: SUCCESS: 2023-11-04 09:16:36,999 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'lowerdir=/tmp/tmpaer8kg27/upper:/tmp/tmp36cs24bi/upper:/tmp/tmp2mc8u9z9/root.dir,upperdir=/tmp/tmpe9ntd3q9/upper,workdir=/tmp/tmpe9ntd3q9/work', '-t', 'overlay', 'overlay', '/tmp/tmpe9ntd3q9/mount'] 2023-11-04 09:16:37,001 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.4"}}', '-c', '/var/log/installer/curtin-install/subiquity-initial.conf', 'install', '--set', 'json:stages=[]'] 2023-11-04 09:16:37,065 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'chroot', '/tmp/tmpe9ntd3q9/mount', 'sh', '-c', 'command -v ubuntu-drivers'] 2023-11-04 09:16:37,104 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--property', 'PrivateMounts=yes', '--pipe', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.5"}}', 'in-target', '-t', '/tmp/tmpe9ntd3q9/mount', '--', 'ubuntu-drivers', 'list-oem'] 2023-11-04 09:16:39,103 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step: SUCCESS: executing curtin install initial step 2023-11-04 09:16:39,103 DEBUG subiquity.models.filesystem:1838 mountpoints {'/boot/efi': 'mount-0', '/': 'mount-1'} 2023-11-04 09:16:39,104 DEBUG subiquity.models.filesystem:1828 cannot emit action to mount /boot/efi until that for / is emitted 2023-11-04 09:16:39,104 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step: executing curtin install partitioning step 2023-11-04 09:16:39,114 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.6"}}', '-c', '/var/log/installer/curtin-install/subiquity-partitioning.conf', 'install', '--set', 'json:stages=["partitioning"]', 'cp:///tmp/tmpaer8kg27/mount'] 2023-11-04 09:16:39,473 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/cmd-in-target: curtin command in-target 2023-11-04 09:16:41,472 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install: curtin command install 2023-11-04 09:16:41,474 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning: configuring storage 2023-11-04 09:16:41,476 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin: running 'curtin block-meta simple' 2023-11-04 09:16:42,829 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:16:42,903 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: curtin command block-meta 2023-11-04 09:16:42,903 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/cmd-in-target: SUCCESS: curtin command in-target 2023-11-04 09:16:42,931 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:16:42,935 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'umount', '/tmp/tmpe9ntd3q9/mount'] 2023-11-04 09:16:43,011 DEBUG subiquity.server.controllers.oem:192 OEM meta-packages to install: [] 2023-11-04 09:16:43,011 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list: SUCCESS: 2023-11-04 09:16:43,976 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: removing previous storage devices 2023-11-04 09:16:44,743 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: SUCCESS: removing previous storage devices 2023-11-04 09:16:44,744 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta/: configuring disk: disk-sda 2023-11-04 09:16:46,165 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta/: SUCCESS: configuring disk: disk-sda 2023-11-04 09:16:46,166 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring partition: partition-0 2023-11-04 09:16:46,418 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring partition: partition-0 2023-11-04 09:16:46,419 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring format: format-0 2023-11-04 09:16:46,977 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring format: format-0 2023-11-04 09:16:46,978 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring partition: partition-1 2023-11-04 09:16:47,230 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring partition: partition-1 2023-11-04 09:16:47,231 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring format: format-1 2023-11-04 09:16:51,767 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring format: format-1 2023-11-04 09:16:51,768 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring mount: mount-1 2023-11-04 09:16:52,037 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring mount: mount-1 2023-11-04 09:16:52,038 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring mount: mount-0 2023-11-04 09:16:52,320 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring mount: mount-0 2023-11-04 09:16:52,321 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning/builtin: SUCCESS: running 'curtin block-meta simple' 2023-11-04 09:16:52,321 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-partitioning: SUCCESS: configuring storage 2023-11-04 09:16:52,322 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install: SUCCESS: curtin command install 2023-11-04 09:16:52,324 DEBUG subiquity.server.controllers.filesystem:504 recording path '/dev/sda' for device disk-sda 2023-11-04 09:16:52,324 DEBUG subiquity.server.controllers.filesystem:504 recording path '/dev/sda1' for device partition-0 2023-11-04 09:16:52,324 DEBUG subiquity.server.controllers.filesystem:504 recording path '/dev/sda2' for device partition-1 2023-11-04 09:16:52,325 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step: SUCCESS: executing curtin install partitioning step 2023-11-04 09:16:52,325 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,326 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,326 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,327 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,327 DEBUG subiquity.cloudinit:14 Loaded cloud config from /run/cloud-init/combined-cloud-config.json 2023-11-04 09:16:52,328 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,329 DEBUG subiquity.models.filesystem:1838 mountpoints {'/boot/efi': 'mount-0', '/': 'mount-1'} 2023-11-04 09:16:52,329 DEBUG subiquity.models.filesystem:1828 cannot emit action to mount /boot/efi until that for / is emitted 2023-11-04 09:16:52,330 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,330 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,331 DEBUG subiquity.models.subiquity:532 merging config from 2023-11-04 09:16:52,331 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step: executing curtin install extract step 2023-11-04 09:16:52,345 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.7"}}', '-c', '/var/log/installer/curtin-install/subiquity-extract.conf', 'install', '--set', 'json:stages=["extract"]', 'cp:///tmp/tmpaer8kg27/mount'] 2023-11-04 09:16:54,471 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install: curtin command install 2023-11-04 09:16:54,472 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract: writing install sources to disk 2023-11-04 09:16:54,474 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract/builtin: running 'curtin extract' 2023-11-04 09:16:56,221 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract/builtin/cmd-extract: curtin command extract 2023-11-04 09:16:56,221 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract/builtin/cmd-extract/: acquiring and extracting image from cp:///tmp/tmpaer8kg27/mount 2023-11-04 09:17:52,987 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:17:53,009 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:17:53,010 DEBUG probert.network:741 wlan_event {'cmd': 'TRIGGER_SCAN', 'ifindex': 3} 2023-11-04 09:17:53,917 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:17:53,941 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:17:53,942 DEBUG probert.network:741 wlan_event {'cmd': 'NEW_SCAN_RESULTS', 'ifindex': 3, 'ssids': [(b'Hringdu-7WWf', 'no status'), (b'Vodafone-UwWV', 'no status')]} 2023-11-04 09:17:53,942 DEBUG subiquitycore.utils:79 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-11-04 09:17:53,965 DEBUG subiquitycore.utils:98 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-11-04 09:19:23,897 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:19:23,971 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract/builtin/cmd-extract/: SUCCESS: acquiring and extracting image from cp:///tmp/tmpaer8kg27/mount 2023-11-04 09:19:23,972 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract/builtin: SUCCESS: running 'curtin extract' 2023-11-04 09:19:23,973 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install/stage-extract: SUCCESS: writing install sources to disk 2023-11-04 09:19:23,973 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step/cmd-install: SUCCESS: curtin command install 2023-11-04 09:19:23,999 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:19:24,000 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step: SUCCESS: executing curtin install extract step 2023-11-04 09:19:24,003 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', 'mount', '-o', 'bind', '/cdrom', '/target/cdrom'] 2023-11-04 09:19:24,081 DEBUG root:30 start: subiquity/Install/install/curtin_install/setup_target: configuring keyboard 2023-11-04 09:19:24,083 DEBUG subiquitycore.utils:154 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2034', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1269/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1269/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1269/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/usr/sbin:/snap/ubuntu-desktop-installer/1269/usr/bin:/snap/ubuntu-desktop-installer/1269/sbin:/snap/ubuntu-desktop-installer/1269/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/1269/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1269/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1269', '--', '/snap/ubuntu-desktop-installer/1269/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2034.8"}}', 'in-target', '-t', '/target', '--', 'setupcon', '--save-only'] 2023-11-04 09:19:26,472 DEBUG root:30 start: subiquity/Install/install/curtin_install/setup_target/cmd-in-target: curtin command in-target 2023-11-04 09:19:27,093 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-11-04 09:19:27,194 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-11-04 09:19:27,223 DEBUG root:30 finish: subiquity/Install/install/curtin_install/setup_target/cmd-in-target: SUCCESS: curtin command in-target 2023-11-04 09:19:27,297 DEBUG subiquity.server.curtin:130 waited 0.30000000000000004 seconds for events to drain 2023-11-04 09:19:27,297 DEBUG root:30 finish: subiquity/Install/install/curtin_install/setup_target: SUCCESS: configuring keyboard 2023-11-04 09:19:27,298 DEBUG subiquitycore.utils:121 arun_command called: ['grep-status', '--whole-pkg', '-FProvides', 'linux-image', '--and', '-FStatus', 'installed', '--show-field=Package', '--no-field-names', '/target/var/lib/dpkg/status'] 2023-11-04 09:19:27,305 ERROR root:30 finish: subiquity/Install/install/curtin_install: FAIL: [Errno 2] No such file or directory: 'grep-status' 2023-11-04 09:19:27,306 DEBUG subiquity.common.errorreport:394 generating crash report 2023-11-04 09:19:27,318 INFO subiquity.common.errorreport:415 saving crash report 'install failed crashed with FileNotFoundError' to /var/crash/1699089567.306310892.install_fail.crash 2023-11-04 09:19:27,318 ERROR root:30 finish: subiquity/Install/install: FAIL: [Errno 2] No such file or directory: 'grep-status' 2023-11-04 09:19:27,319 INFO root:30 start: subiquity/ErrorReporter/1699089567.306310892.install_fail/add_info: 2023-11-04 09:19:27,319 ERROR subiquity.server.server:415 top level error Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1269/bin/subiquity/subiquity/server/controllers/shutdown.py", line 73, in _wait_install await self.app.controllers.Install.install_task FileNotFoundError: [Errno 2] No such file or directory: 'grep-status' 2023-11-04 09:19:27,321 ERROR subiquity.server.server:415 top level error Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1269/bin/subiquity/subiquity/server/controllers/shutdown.py", line 73, in _wait_install await self.app.controllers.Install.install_task FileNotFoundError: [Errno 2] No such file or directory: 'grep-status' 2023-11-04 09:19:27,322 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "/dev/tty1", "error": {"state": "INCOMPL... 2023-11-04 09:19:27,323 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "/dev/tty1", "error": {"state": "INCOMPL... 2023-11-04 09:19:27,324 INFO root:30 start: subiquity/Meta/status_GET: