2023-09-21 14:38:24,804 INFO subiquity:199 Starting Subiquity server revision 1243 of snap /snap/ubuntu-desktop-installer/1243 2023-09-21 14:38:24,804 INFO subiquity:200 Arguments passed: ['/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/1243/etc/subiquity/postinst.d'] 2023-09-21 14:38:24,804 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-09-21 14:38:24,804 DEBUG subiquity:202 Environment: environ({'SNAP_REVISION': '1243', 'SNAP_REAL_HOME': '/root', 'SNAP_USER_COMMON': '/root/snap/ubuntu-desktop-installer/common', 'PATH_ORIG': '/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/bin/subiquity', 'SYSTEMD_EXEC_PID': '2052', 'SNAP_CONTEXT': '4SDNiA5KCZTeBWKTa86LDv8QHssYq2PbDyfrjY3ULzKgAiHltoLc', 'LANG': 'C.UTF-8', 'SNAP_ARCH': 'amd64', 'PY3OR2_PYTHON': '/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', 'SNAP_INSTANCE_NAME': 'ubuntu-desktop-installer', 'SNAP_USER_DATA': '/root/snap/ubuntu-desktop-installer/1243', 'INVOCATION_ID': 'e017188398a846e192d53e55e6ad4864', '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/1243/lib:/snap/ubuntu-desktop-installer/1243/usr/lib:/snap/ubuntu-desktop-installer/1243/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1243/usr/lib/x86_64-linux-gnu', 'PYTHONPATH_ORIG': '', 'PYTHONPATH': '/snap/ubuntu-desktop-installer/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', 'PYTHON': '/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', 'PYTHONIOENCODING': 'utf-8', 'SNAP': '/snap/ubuntu-desktop-installer/1243', 'SNAP_COMMON': '/var/snap/ubuntu-desktop-installer/common', 'SNAP_VERSION': '0+git.bf01a899', 'DISPLAY': ':0', 'SHLVL': '1', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'SNAP_COOKIE': '4SDNiA5KCZTeBWKTa86LDv8QHssYq2PbDyfrjY3ULzKgAiHltoLc', 'SNAP_DATA': '/var/snap/ubuntu-desktop-installer/1243', 'LD_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/ubuntu-desktop-installer/1243/lib:/snap/ubuntu-desktop-installer/1243/usr/lib:/snap/ubuntu-desktop-installer/1243/lib/x86_64-linux-gnu:/snap/ubuntu-desktop-installer/1243/usr/lib/x86_64-linux-gnu', 'SNAP_NAME': 'ubuntu-desktop-installer', 'JOURNAL_STREAM': '8:20200', 'PATH': '/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/bin/subiquity', 'OLDPWD': '/var/snap/ubuntu-desktop-installer/1243', '_': '/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', 'APPORT_DATA_DIR': '/snap/ubuntu-desktop-installer/1243/bin/subiquity/share/apport'}) 2023-09-21 14:38:24,804 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-21 14:38:24,805 DEBUG subiquitycore.prober:33 Prober() init finished, data:None 2023-09-21 14:38:24,839 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True) 2023-09-21 14:38:24,847 DEBUG subiquitycore.netplan:113 config for zz-all-en = {'dhcp4': True, 'match': {'name': 'en*'}} 2023-09-21 14:38:24,847 DEBUG subiquitycore.netplan:113 config for zz-all-eth = {'dhcp4': True, 'match': {'name': 'eth*'}} 2023-09-21 14:38:24,859 DEBUG subiquitycore.utils:118 arun_command called: ['cloud-init', 'status', '--wait'] 2023-09-21 14:39:12,422 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-21 14:39:12,422 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-21 14:39:12,422 INFO aiohttp.access:206 [21/Sep/2023:14:39:12 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:13,426 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-21 14:39:13,427 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-21 14:39:13,428 INFO aiohttp.access:206 [21/Sep/2023:14:39:13 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:14,431 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-21 14:39:14,432 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-21 14:39:14,433 INFO aiohttp.access:206 [21/Sep/2023:14:39:14 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:15,435 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 2023-09-21 14:39:15,436 DEBUG curtin.reporting.finish.subiquity/Meta/status_GET:45 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "CLOUD_INIT_WAIT", "confirming_tty": "", "error": null, "cloud_init... 2023-09-21 14:39:15,436 INFO aiohttp.access:206 [21/Sep/2023:14:39:15 +0000] "GET /meta/status HTTP/1.1" 200 420 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:15,997 DEBUG subiquitycore.utils:132 arun_command ['cloud-init', 'status', '--wait'] exited with code 0 2023-09-21 14:39:15,997 DEBUG subiquity.server.server:569 waited 51.13840985298157s for cloud-init 2023-09-21 14:39:15,998 DEBUG subiquity.cloudinit:14 Loaded cloud config from /run/cloud-init/combined-cloud-config.json 2023-09-21 14:39:15,998 DEBUG subiquity.server.server:553 no autoinstall found in cloud-config 2023-09-21 14:39:15,998 DEBUG subiquitycore.utils:76 run_command called: ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys'] 2023-09-21 14:39:16,004 DEBUG subiquitycore.utils:95 run_command ['ssh-keygen', '-lf', '/home/installer/.ssh/authorized_keys'] exited with code 255 2023-09-21 14:39:16,004 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-09-21 14:39:16,004 DEBUG subiquitycore.utils:76 run_command called: chpasswd 2023-09-21 14:39:16,171 DEBUG subiquitycore.utils:95 run_command chpasswd exited with code 0 2023-09-21 14:39:16,171 DEBUG subiquity.server.server:470 load_autoinstall_config only_early True file None 2023-09-21 14:39:16,172 DEBUG subiquity.server.server:470 load_autoinstall_config only_early False file None 2023-09-21 14:39:16,172 DEBUG subiquitycore.core:118 starting controllers 2023-09-21 14:39:16,172 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic-hwe-22.04 due to /run/kernel-meta-package 2023-09-21 14:39:16,178 DEBUG subiquity.models.source:93 loaded 2 sources from '/cdrom/casper/install-sources.yaml' 2023-09-21 14:39:16,178 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'10.0.2.15/24'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 1, 'family': 10, 'scope': 200, 'local': b'fec0::4322:1cf8:e798:4b47/64'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 256, 'family': 10, 'scope': 200, 'local': b'fec0::5054:ff:fe28:8558/64'} 2023-09-21 14:39:16,179 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5054:ff:fe28:8558/64'} 2023-09-21 14:39:16,179 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'} 2023-09-21 14:39:16,223 DEBUG subiquitycore.models.network:475 new_link 1 lo lo 2023-09-21 14:39:16,223 DEBUG subiquitycore.models.network:477 ignoring based on type 2023-09-21 14:39:16,223 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'} 2023-09-21 14:39:16,267 DEBUG subiquitycore.models.network:475 new_link 2 enp1s0 eth 2023-09-21 14:39:16,267 DEBUG subiquitycore.models.network:506 new_link 2 enp1s0 with config {'dhcp4': True} 2023-09-21 14:39:16,267 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp1s0 2023-09-21 14:39:16,268 DEBUG subiquity.server.controllers.network:313 dev_info enp1s0 {'dhcp4': True} 2023-09-21 14:39:16,268 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp1s0 2023-09-21 14:39:16,268 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'} 2023-09-21 14:39:16,268 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'10.0.2.15/24'} 2023-09-21 14:39:16,268 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0 2023-09-21 14:39:16,268 DEBUG subiquity.server.controllers.network:313 dev_info enp1s0 {'dhcp4': True} 2023-09-21 14:39:16,268 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0 2023-09-21 14:39:16,268 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'} 2023-09-21 14:39:16,268 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 1, 'family': 10, 'scope': 200, 'local': b'fec0::4322:1cf8:e798:4b47/64'} 2023-09-21 14:39:16,268 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0 2023-09-21 14:39:16,268 DEBUG subiquity.server.controllers.network:313 dev_info enp1s0 {'dhcp4': True} 2023-09-21 14:39:16,269 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0 2023-09-21 14:39:16,269 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 256, 'family': 10, 'scope': 200, 'local': b'fec0::5054:ff:fe28:8558/64'} 2023-09-21 14:39:16,269 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0 2023-09-21 14:39:16,269 DEBUG subiquity.server.controllers.network:313 dev_info enp1s0 {'dhcp4': True} 2023-09-21 14:39:16,269 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0 2023-09-21 14:39:16,269 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 128, 'family': 10, 'scope': 253, 'local': b'fe80::5054:ff:fe28:8558/64'} 2023-09-21 14:39:16,269 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0 2023-09-21 14:39:16,269 DEBUG subiquity.server.controllers.network:313 dev_info enp1s0 {'dhcp4': True} 2023-09-21 14:39:16,269 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0 2023-09-21 14:39:16,269 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2} 2023-09-21 14:39:16,332 DEBUG pyroute2.ndb.140143158059904.sources.localhost:74 init 2023-09-21 14:39:16,332 DEBUG pyroute2.ndb.140143158059904.sources.localhost:384 starting the source 2023-09-21 14:39:16,332 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:74 init 2023-09-21 14:39:16,332 DEBUG pyroute2.ndb.140143158059904.sources.localhost:74 connecting 2023-09-21 14:39:16,333 DEBUG pyroute2.ndb.140143158059904.sources.localhost:74 loading 2023-09-21 14:39:16,334 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:384 starting the source 2023-09-21 14:39:16,334 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:74 connecting 2023-09-21 14:39:16,335 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:74 loading 2023-09-21 14:39:16,349 DEBUG pyroute2.ndb.140143158059904.sources.localhost:74 running 2023-09-21 14:39:16,350 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:74 running 2023-09-21 14:39:16,354 DEBUG pyroute2.ndb.140143158059904.sources.localhost:399 source shutdown 2023-09-21 14:39:16,354 DEBUG pyroute2.ndb.140143158059904.sources.localhost:374 sync 2023-09-21 14:39:16,354 DEBUG pyroute2.ndb.140143158059904.sources.localhost:369 shutdown handled by the main thread 2023-09-21 14:39:16,355 DEBUG pyroute2.ndb.140143158059904.sources.localhost:74 stopped 2023-09-21 14:39:16,355 DEBUG pyroute2.ndb.140143158059904.main:851 flush DB for the target localhost 2023-09-21 14:39:16,355 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:399 source shutdown 2023-09-21 14:39:16,369 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:374 sync 2023-09-21 14:39:16,369 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:369 shutdown handled by the main thread 2023-09-21 14:39:16,369 DEBUG pyroute2.ndb.140143158059904.sources.localhost/nsmanager:74 stopped 2023-09-21 14:39:16,369 DEBUG pyroute2.ndb.140143158059904.main:851 flush DB for the target localhost/nsmanager 2023-09-21 14:39:16,370 DEBUG subiquitycore.controllers.network:102 default routes True 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'10.0.2.0/24', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'169.254.0.0/16', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'10.0.2.15', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'10.0.2.255', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fec0::/64', 'ifindex': 2} 2023-09-21 14:39:16,370 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2} 2023-09-21 14:39:16,380 DEBUG pyroute2.ndb.140143158066672.sources.localhost:74 init 2023-09-21 14:39:16,380 DEBUG pyroute2.ndb.140143158066672.sources.localhost:384 starting the source 2023-09-21 14:39:16,381 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:74 init 2023-09-21 14:39:16,381 DEBUG pyroute2.ndb.140143158066672.sources.localhost:74 connecting 2023-09-21 14:39:16,381 DEBUG pyroute2.ndb.140143158066672.sources.localhost:74 loading 2023-09-21 14:39:16,382 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:384 starting the source 2023-09-21 14:39:16,382 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:74 connecting 2023-09-21 14:39:16,383 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:74 loading 2023-09-21 14:39:16,396 DEBUG pyroute2.ndb.140143158066672.sources.localhost:74 running 2023-09-21 14:39:16,398 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:74 running 2023-09-21 14:39:16,401 DEBUG pyroute2.ndb.140143158066672.sources.localhost:399 source shutdown 2023-09-21 14:39:16,401 DEBUG pyroute2.ndb.140143158066672.sources.localhost:374 sync 2023-09-21 14:39:16,401 DEBUG pyroute2.ndb.140143158066672.sources.localhost:369 shutdown handled by the main thread 2023-09-21 14:39:16,401 DEBUG pyroute2.ndb.140143158066672.sources.localhost:74 stopped 2023-09-21 14:39:16,402 DEBUG pyroute2.ndb.140143158066672.main:851 flush DB for the target localhost 2023-09-21 14:39:16,402 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:399 source shutdown 2023-09-21 14:39:16,403 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:374 sync 2023-09-21 14:39:16,403 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:369 shutdown handled by the main thread 2023-09-21 14:39:16,403 DEBUG pyroute2.ndb.140143158066672.sources.localhost/nsmanager:74 stopped 2023-09-21 14:39:16,403 DEBUG pyroute2.ndb.140143158066672.main:851 flush DB for the target localhost/nsmanager 2023-09-21 14:39:16,404 DEBUG subiquitycore.controllers.network:102 default routes True 2023-09-21 14:39:16,404 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1} 2023-09-21 14:39:16,404 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::5054:ff:fe28:8558', 'ifindex': 2} 2023-09-21 14:39:16,404 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fec0::4322:1cf8:e798:4b47', 'ifindex': 2} 2023-09-21 14:39:16,404 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fec0::5054:ff:fe28:8558', 'ifindex': 2} 2023-09-21 14:39:16,404 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 5, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2} 2023-09-21 14:39:16,507 DEBUG subiquitycore.core:121 controllers started 2023-09-21 14:39:16,507 INFO root:30 start: subiquity/apply_autoinstall_config: 2023-09-21 14:39:16,507 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 2023-09-21 14:39:16,508 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,508 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 2023-09-21 14:39:16,508 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,508 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 2023-09-21 14:39:16,509 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,509 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 2023-09-21 14:39:16,509 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,509 DEBUG subiquity.models.subiquity:252 model userdata for postinstall stage is configured, to go {'drivers', 'snaplist', 'ssh', 'identity', 'packages', 'locale', 'ubuntu_pro'} 2023-09-21 14:39:16,509 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 2023-09-21 14:39:16,509 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,510 DEBUG subiquity.models.subiquity:252 model packages for postinstall stage is configured, to go {'drivers', 'snaplist', 'ssh', 'identity', 'locale', 'ubuntu_pro'} 2023-09-21 14:39:16,510 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 2023-09-21 14:39:16,510 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,510 DEBUG subiquity.models.subiquity:252 model debconf_selections for install stage is configured, to go {'filesystem', 'proxy', 'kernel', 'source', 'keyboard'} 2023-09-21 14:39:16,510 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Locale as interactive 2023-09-21 14:39:16,510 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Refresh as interactive 2023-09-21 14:39:16,510 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 2023-09-21 14:39:16,510 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,510 DEBUG subiquity.models.subiquity:252 model kernel for install stage is configured, to go {'source', 'keyboard', 'filesystem', 'proxy'} 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Integrity as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Keyboard as interactive 2023-09-21 14:39:16,511 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 2023-09-21 14:39:16,511 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Source as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Network as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping UbuntuPro as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Proxy as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Mirror as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Filesystem as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Identity as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SSH as interactive 2023-09-21 14:39:16,511 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SnapList as interactive 2023-09-21 14:39:16,511 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 2023-09-21 14:39:16,511 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Codecs as interactive 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Drivers as interactive 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping OEM as interactive 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping TimeZone as interactive 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Install as interactive 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Updates as interactive 2023-09-21 14:39:16,512 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 2023-09-21 14:39:16,512 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,512 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Shutdown as interactive 2023-09-21 14:39:16,512 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 2023-09-21 14:39:16,512 DEBUG subiquity.models.subiquity:252 model locale for postinstall stage is configured, to go {'drivers', 'snaplist', 'ssh', 'identity', 'ubuntu_pro'} 2023-09-21 14:39:16,512 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 2023-09-21 14:39:16,512 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 2023-09-21 14:39:16,513 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-09-21 14:39:16,543 DEBUG subiquitycore.utils:118 arun_command called: ['/usr/sbin/realm', 'discover'] 2023-09-21 14:39:16,558 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 2023-09-21 14:39:16,558 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 2023-09-21 14:39:16,558 DEBUG root:30 start: subiquity/Install/install: 2023-09-21 14:39:16,559 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps 2023-09-21 14:39:16,577 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1560 2023-09-21 14:39:16,641 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps 2023-09-21 14:39:16,641 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-09-21 14:39:16,642 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-09-21 14:39:16,642 DEBUG root:30 start: subiquity/Refresh/check_for_update: 2023-09-21 14:39:16,642 DEBUG root:30 start: subiquity/SnapList/loader: 2023-09-21 14:39:16,643 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-09-21 14:39:16,645 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-21 14:39:16,646 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:39:16,647 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-21 14:39:16,647 INFO aiohttp.access:206 [21/Sep/2023:14:39:16 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:16,648 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled 2023-09-21 14:39:16,649 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.bf01a899' 2023-09-21 14:39:16,650 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info 2023-09-21 14:39:16,650 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 2023-09-21 14:39:16,651 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled 2023-09-21 14:39:16,651 DEBUG root:30 start: subiquity/SnapList/loader/list: 2023-09-21 14:39:16,653 WARNING subiquity.server.geoip:113 geoip lookup failed: ClientConnectorError(ConnectionKey(host='geoip.ubuntu.com', port=443, is_ssl=True, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=None), gaierror(-3, 'Temporary failure in name resolution')) 2023-09-21 14:39:16,658 INFO root:30 start: subiquity/Meta/client_variant_POST: 2023-09-21 14:39:16,658 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null 2023-09-21 14:39:16,659 INFO aiohttp.access:206 [21/Sep/2023:14:39:16 +0000] "POST /meta/client_variant?variant=%22desktop%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:16,661 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:39:16,662 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-21 14:39:16,662 INFO aiohttp.access:206 [21/Sep/2023:14:39:16 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:16,663 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-09-21 14:39:16,664 DEBUG subiquity.models.subiquity:252 model ubuntu_pro for postinstall stage is configured, to go {'drivers', 'codecs', 'snaplist', 'ssh', 'identity', 'timezone', 'network'} 2023-09-21 14:39:16,664 DEBUG subiquity.models.subiquity:252 model proxy for install stage is configured, to go {'filesystem', 'mirror', 'network', 'source', 'keyboard'} 2023-09-21 14:39:16,665 DEBUG subiquity.models.subiquity:252 model mirror for install stage is configured, to go {'source', 'keyboard', 'network', 'filesystem'} 2023-09-21 14:39:16,665 DEBUG subiquity.models.subiquity:252 model ssh for postinstall stage is configured, to go {'drivers', 'codecs', 'snaplist', 'timezone', 'identity', 'network'} 2023-09-21 14:39:16,665 DEBUG subiquity.models.subiquity:252 model snaplist for postinstall stage is configured, to go {'drivers', 'codecs', 'timezone', 'identity', 'network'} 2023-09-21 14:39:16,666 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-09-21 14:39:16,666 INFO aiohttp.access:206 [21/Sep/2023:14:39:16 +0000] "POST /meta/mark_configured?endpoint_names=%5B%22mirror%22%2C%22proxy%22%2C%22ssh%22%2C%22snaplist%22%2C%22ubuntu_pro%22%5D HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:39:16,667 DEBUG subiquitycore.utils:132 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1 2023-09-21 14:39:16,733 DEBUG root:30 start: subiquity/Refresh/GET: 2023-09-21 14:39:17,492 DEBUG probert.dasd:134 Probing DASD devies 2023-09-21 14:39:17,492 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-09-21 14:39:17,596 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-09-21 14:39:17,597 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-09-21 14:39:18,010 DEBUG curtin:1321 Extracting storage config from probe data 2023-09-21 14:39:18,010 DEBUG curtin:73 /dev/vda is multipath device member? False 2023-09-21 14:39:18,010 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:39:18,010 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:39:18,010 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:39:18,010 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:39:18,022 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:39:18,022 DEBUG curtin:86 /dev/sr0 is multipath device partition? False 2023-09-21 14:39:18,022 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:39:18,022 DEBUG curtin:1328 Sorting extracted configurations 2023-09-21 14:39:18,022 INFO curtin:1347 Validating extracted storage config components 2023-09-21 14:39:18,033 DEBUG curtin:1364 Extracted (unmerged) storage config: storage: - id: disk-vda path: /dev/vda type: disk 2023-09-21 14:39:18,034 DEBUG curtin:1368 Generating storage config dependencies 2023-09-21 14:39:18,034 DEBUG curtin:1374 Merging storage config dependencies 2023-09-21 14:39:18,034 DEBUG curtin:1379 Merged storage config: storage: config: - id: disk-vda path: /dev/vda type: disk version: 2 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')} 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0 2023-09-21 14:39:18,034 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:44 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 0:47 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:39:18,035 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:50 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:88 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:39:18,036 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:39:18,036 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-09-21 14:39:18,036 DEBUG subiquity.server.controllers.filesystem:1295 block probing took 1.4 seconds 2023-09-21 14:39:18,036 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-09-21 14:39:27,961 DEBUG subiquity.server.controllers.integrity:61 casper-md5check results: {'checksum_missmatch': [], 'result': 'pass'} 2023-09-21 14:39:48,899 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 400 162 2023-09-21 14:39:48,902 ERROR root:30 finish: subiquity/SnapList/loader/list: FAIL: 2023-09-21 14:39:48,902 ERROR subiquity.server.controllers.snaplist:89 loading list of snaps failed Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/server/controllers/snaplist.py", line 103, in _load_list result = await self.snapd.get("v2/find", section=self.store_section) File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquitycore/snapd.py", line 198, in get response.raise_for_status() File "/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages/requests/models.py", line 943, in raise_for_status raise HTTPError(http_error_msg, response=self) requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: http+unix://%2Frun%2Fsnapd.socket/v2/find?section=server During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/server/controllers/snaplist.py", line 87, in _start await task File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquitycore/context.py", line 149, in decorated_async return await meth(self, **kw) File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/server/controllers/snaplist.py", line 105, in _load_list raise SnapListFetchError subiquity.server.controllers.snaplist.SnapListFetchError 2023-09-21 14:39:48,978 DEBUG root:30 finish: subiquity/SnapList/loader: SUCCESS: 2023-09-21 14:39:49,019 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 500 234 2023-09-21 14:39:49,020 ERROR subiquity.server.controllers.refresh:197 checking for snap update failed Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/server/controllers/refresh.py", line 195, in check_for_update result = await self.app.snapdapi.v2.find.GET(select="refresh") File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/common/api/client.py", line 47, in impl async with make_request( File "/snap/ubuntu-desktop-installer/1243/usr/lib/python3.10/contextlib.py", line 199, in __aenter__ return await anext(self.gen) File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquity/server/snapdapi.py", line 298, in make_request content = await async_snapd.get(path[1:], **params) File "/snap/ubuntu-desktop-installer/1243/bin/subiquity/subiquitycore/snapd.py", line 198, in get response.raise_for_status() File "/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages/requests/models.py", line 943, in raise_for_status raise HTTPError(http_error_msg, response=self) requests.exceptions.HTTPError: 500 Server Error: Internal Server Error for url: http+unix://%2Frun%2Fsnapd.socket/v2/find?select=refresh 2023-09-21 14:39:49,054 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: checking for snap update failed 2023-09-21 14:39:49,055 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNKNOWN", "current_snap_version": "0+git.bf01a899", "new_sn... 2023-09-21 14:39:49,055 INFO aiohttp.access:206 [21/Sep/2023:14:39:16 +0000] "GET /refresh?wait=true HTTP/1.1" 200 280 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:01,803 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:40:01,803 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-21 14:40:01,803 INFO aiohttp.access:206 [21/Sep/2023:14:40:01 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:01,804 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:40:01,804 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2023-09-21 14:40:01,804 INFO aiohttp.access:206 [21/Sep/2023:14:40:01 +0000] "GET /meta/status HTTP/1.1" 200 412 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:01,804 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:40:01,805 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 2023-09-21 14:40:01,805 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null 2023-09-21 14:40:01,805 INFO aiohttp.access:206 [21/Sep/2023:14:40:01 +0000] "GET /meta/interactive_sections HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:01,806 DEBUG root:30 start: subiquity/Locale/GET: 2023-09-21 14:40:01,807 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8" 2023-09-21 14:40:01,807 INFO aiohttp.access:206 [21/Sep/2023:14:40:01 +0000] "GET /locale HTTP/1.1" 200 195 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:12,793 DEBUG root:30 start: subiquity/Locale/POST: 2023-09-21 14:40:12,793 DEBUG subiquity.server.controllers.locale:68 fr_FR.UTF-8 2023-09-21 14:40:12,794 DEBUG subiquity.models.subiquity:252 model locale for postinstall stage is configured, to go {'drivers', 'codecs', 'timezone', 'identity', 'network'} 2023-09-21 14:40:12,794 DEBUG root:30 finish: subiquity/Locale/POST: SUCCESS: 200 null 2023-09-21 14:40:12,794 INFO aiohttp.access:206 [21/Sep/2023:14:40:12 +0000] "POST /locale HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:12,794 DEBUG subiquitycore.utils:118 arun_command called: ['localectl', 'set-locale', 'fr_FR.UTF-8'] 2023-09-21 14:40:13,506 DEBUG subiquitycore.utils:132 arun_command ['localectl', 'set-locale', 'fr_FR.UTF-8'] exited with code 0 2023-09-21 14:40:15,096 DEBUG root:30 start: subiquity/Filesystem/has_rst_GET: 2023-09-21 14:40:15,097 DEBUG root:30 finish: subiquity/Filesystem/has_rst_GET: SUCCESS: 200 false 2023-09-21 14:40:15,097 INFO aiohttp.access:206 [21/Sep/2023:14:40:15 +0000] "GET /storage/has_rst HTTP/1.1" 200 191 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:15,099 DEBUG root:30 start: subiquity/Keyboard/GET: 2023-09-21 14:40:15,123 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "fr", "variant": "latin9", "toggle": null}, "layouts":... 2023-09-21 14:40:15,123 INFO aiohttp.access:206 [21/Sep/2023:14:40:15 +0000] "GET /keyboard HTTP/1.1" 200 44555 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:15,126 DEBUG root:30 start: subiquity/Keyboard/GET: 2023-09-21 14:40:15,136 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "fr", "variant": "latin9", "toggle": null}, "layouts":... 2023-09-21 14:40:15,136 INFO aiohttp.access:206 [21/Sep/2023:14:40:15 +0000] "GET /keyboard HTTP/1.1" 200 44555 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:15,138 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 2023-09-21 14:40:15,139 DEBUG subiquitycore.utils:118 arun_command called: ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','fr+latin9')]"] 2023-09-21 14:40:15,194 DEBUG subiquitycore.utils:132 arun_command ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','fr+latin9')]"] exited with code 0 2023-09-21 14:40:15,194 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null 2023-09-21 14:40:15,195 INFO aiohttp.access:206 [21/Sep/2023:14:40:15 +0000] "POST /keyboard/input_source?user=%22ubuntu%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:20,815 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 2023-09-21 14:40:20,816 DEBUG subiquitycore.utils:118 arun_command called: ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','fr+azerty')]"] 2023-09-21 14:40:20,861 DEBUG subiquitycore.utils:132 arun_command ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','fr+azerty')]"] exited with code 0 2023-09-21 14:40:20,861 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null 2023-09-21 14:40:20,861 INFO aiohttp.access:206 [21/Sep/2023:14:40:20 +0000] "POST /keyboard/input_source?user=%22ubuntu%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:21,877 DEBUG root:30 start: subiquity/Keyboard/POST: 2023-09-21 14:40:21,877 DEBUG subiquity.server.controllers.keyboard:221 KeyboardSetting(layout='fr', variant='azerty', toggle=None) 2023-09-21 14:40:21,878 DEBUG subiquitycore.utils:118 arun_command called: ['setupcon', '--save', '--force', '--keyboard-only'] 2023-09-21 14:40:22,431 DEBUG subiquitycore.utils:132 arun_command ['setupcon', '--save', '--force', '--keyboard-only'] exited with code 0 2023-09-21 14:40:22,431 DEBUG subiquitycore.utils:118 arun_command called: ['/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin/subiquity-loadkeys'] 2023-09-21 14:40:22,440 DEBUG subiquitycore.utils:132 arun_command ['/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin/subiquity-loadkeys'] exited with code 0 2023-09-21 14:40:22,440 DEBUG subiquity.models.subiquity:252 model keyboard for install stage is configured, to go {'source', 'network', 'filesystem'} 2023-09-21 14:40:22,440 DEBUG root:30 finish: subiquity/Keyboard/POST: SUCCESS: 200 null 2023-09-21 14:40:22,441 INFO aiohttp.access:206 [21/Sep/2023:14:40:21 +0000] "POST /keyboard HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:32,573 DEBUG root:30 start: subiquity/Refresh/GET: 2023-09-21 14:40:32,573 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNKNOWN", "current_snap_version": "0+git.bf01a899", "new_sn... 2023-09-21 14:40:32,574 INFO aiohttp.access:206 [21/Sep/2023:14:40:32 +0000] "GET /refresh?wait=true HTTP/1.1" 200 280 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:32,575 DEBUG root:30 start: subiquity/Source/GET: 2023-09-21 14:40:32,576 DEBUG root:30 finish: subiquity/Source/GET: SUCCESS: 200 {"sources": [{"name": "Ubuntu Desktop (minimized)", "description": "A minimal... 2023-09-21 14:40:32,576 INFO aiohttp.access:206 [21/Sep/2023:14:40:32 +0000] "GET /source HTTP/1.1" 200 614 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:32,578 DEBUG root:30 start: subiquity/Drivers/GET: 2023-09-21 14:40:32,579 DEBUG root:30 finish: subiquity/Drivers/GET: SUCCESS: 200 {"install": false, "drivers": null, "local_only": true, "search_drivers": false} 2023-09-21 14:40:32,579 INFO aiohttp.access:206 [21/Sep/2023:14:40:32 +0000] "GET /drivers HTTP/1.1" 200 267 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:32,580 DEBUG root:30 start: subiquity/Codecs/GET: 2023-09-21 14:40:32,580 DEBUG root:30 finish: subiquity/Codecs/GET: SUCCESS: 200 {"install": false} 2023-09-21 14:40:32,581 INFO aiohttp.access:206 [21/Sep/2023:14:40:32 +0000] "GET /codecs HTTP/1.1" 200 205 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:34,611 DEBUG root:30 start: subiquity/Source/POST: 2023-09-21 14:40:34,611 DEBUG subiquity.models.subiquity:252 model source for install stage is configured, to go {'network', 'filesystem'} 2023-09-21 14:40:34,611 DEBUG subiquity.server.controllers.drivers:89 source variant has been set. Querying list of drivers. 2023-09-21 14:40:34,612 DEBUG root:30 finish: subiquity/Source/POST: SUCCESS: 200 null 2023-09-21 14:40:34,612 INFO aiohttp.access:206 [21/Sep/2023:14:40:34 +0000] "POST /source?source_id=%22ubuntu-desktop-minimal%22&search_drivers=false HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:34,613 DEBUG root:30 start: subiquity/Drivers/POST: 2023-09-21 14:40:34,613 DEBUG subiquity.models.subiquity:252 model drivers for postinstall stage is configured, to go {'network', 'codecs', 'timezone', 'identity'} 2023-09-21 14:40:34,614 DEBUG root:30 finish: subiquity/Drivers/POST: SUCCESS: 200 null 2023-09-21 14:40:34,614 INFO aiohttp.access:206 [21/Sep/2023:14:40:34 +0000] "POST /drivers HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:34,614 DEBUG root:30 start: subiquity/Codecs/POST: 2023-09-21 14:40:34,614 DEBUG subiquity.models.subiquity:252 model codecs for postinstall stage is configured, to go {'network', 'timezone', 'identity'} 2023-09-21 14:40:34,615 DEBUG root:30 finish: subiquity/Codecs/POST: SUCCESS: 200 null 2023-09-21 14:40:34,615 INFO aiohttp.access:206 [21/Sep/2023:14:40:34 +0000] "POST /codecs HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:34,615 DEBUG subiquity.server.controllers.filesystem:412 got system None for variation minimal 2023-09-21 14:40:34,615 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmprohtilqn/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:34,630 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.squashfs', '/tmp/tmprohtilqn/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:34,651 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.enhanced-secureboot.fr.squashfs', '/tmp/tmprohtilqn/minimal.enhanced-secureboot.fr.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:34,662 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmprohtilqn/minimal.enhanced-secureboot.fr.squashfs.dir:/tmp/tmprohtilqn/minimal.enhanced-secureboot.squashfs.dir:/tmp/tmprohtilqn/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmprohtilqn/root.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:34,669 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'mount', '-o', 'bind', '/tmp/tmprohtilqn/root.dir/var/lib/snapd/seed/systems', '/var/lib/snapd/seed/systems'] 2023-09-21 14:40:34,670 DEBUG root:30 start: subiquity/Drivers/_list_drivers: 2023-09-21 14:40:34,671 DEBUG root:30 start: subiquity/Drivers/_list_drivers/wait_apt: 2023-09-21 14:40:34,671 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-09-21 14:40:34,694 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-21 14:40:34,706 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-21 14:40:34,706 DEBUG subiquity.server.controllers.filesystem:1497 _udev_event add Device('/sys/devices/virtual/block/loop14') 2023-09-21 14:40:34,706 DEBUG subiquity.server.controllers.filesystem:1480 Triggered Probert run on udev event 2023-09-21 14:40:34,706 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-09-21 14:40:34,707 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-09-21 14:40:34,708 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-21 14:40:34,728 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'mount', '-o', 'bind', '/tmp/tmprohtilqn/root.dir/var/lib/snapd/seed/snaps/pc-kernel_1415.snap', '/var/lib/snapd/seed/snaps/pc-kernel_1415.snap'] 2023-09-21 14:40:34,747 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'mount', '-o', 'bind', '/tmp/tmprohtilqn/root.dir/var/lib/snapd/seed/snaps/pc_154.snap', '/var/lib/snapd/seed/snaps/pc_154.snap'] 2023-09-21 14:40:35,220 DEBUG probert.dasd:134 Probing DASD devies 2023-09-21 14:40:35,220 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-09-21 14:40:35,286 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-09-21 14:40:35,287 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-09-21 14:40:35,291 DEBUG curtin:1321 Extracting storage config from probe data 2023-09-21 14:40:35,291 DEBUG curtin:73 /dev/vda is multipath device member? False 2023-09-21 14:40:35,291 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:35,291 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:35,291 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:35,291 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:35,306 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:35,306 DEBUG curtin:86 /dev/sr0 is multipath device partition? False 2023-09-21 14:40:35,306 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:35,306 DEBUG curtin:1328 Sorting extracted configurations 2023-09-21 14:40:35,306 INFO curtin:1347 Validating extracted storage config components 2023-09-21 14:40:35,321 DEBUG curtin:1364 Extracted (unmerged) storage config: storage: - id: disk-vda path: /dev/vda type: disk 2023-09-21 14:40:35,321 DEBUG curtin:1368 Generating storage config dependencies 2023-09-21 14:40:35,321 DEBUG curtin:1374 Merging storage config dependencies 2023-09-21 14:40:35,321 DEBUG curtin:1379 Merged storage config: storage: config: - id: disk-vda path: /dev/vda type: disk version: 2 2023-09-21 14:40:35,321 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')} 2023-09-21 14:40:35,321 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:44 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:89 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39 2023-09-21 14:40:35,322 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:47 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:13 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 7:14 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:89 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:50 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:88 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:35,323 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:35,323 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-09-21 14:40:35,324 DEBUG subiquity.server.controllers.filesystem:1295 block probing took 0.6 seconds 2023-09-21 14:40:35,324 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-09-21 14:40:37,432 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/systems/enhanced-secureboot-desktop HTTP/1.1" 200 None 2023-09-21 14:40:37,434 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'umount', '/var/lib/snapd/seed/snaps/pc_154.snap'] 2023-09-21 14:40:37,493 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'umount', '/var/lib/snapd/seed/snaps/pc-kernel_1415.snap'] 2023-09-21 14:40:37,524 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'umount', '/var/lib/snapd/seed/systems'] 2023-09-21 14:40:37,564 DEBUG curtin:95 Running command ['umount', '/tmp/tmprohtilqn/root.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:37,568 DEBUG curtin:95 Running command ['umount', '/tmp/tmprohtilqn/minimal.enhanced-secureboot.fr.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:37,572 DEBUG curtin:95 Running command ['umount', '/tmp/tmprohtilqn/minimal.enhanced-secureboot.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:37,602 DEBUG curtin:95 Running command ['umount', '/tmp/tmprohtilqn/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:40:37,607 DEBUG subiquity.server.controllers.filesystem:343 got system SystemDetails(current=False, volumes={'pc': Volume(schema='gpt', bootloader='grub', id='', structure=[VolumeStructure(name='EFI System partition', label='ubuntu-seed', offset=1048576, offset_write=None, size=786432000, type='C12A7328-F81F-11D2-BA4B-00A0C93EC93B', role='system-seed-null', id='', filesystem='vfat', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=2, preserve=None)), VolumeStructure(name='ubuntu-boot', label='ubuntu-boot', offset=787480576, offset_write=None, size=786432000, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-boot', id='', filesystem='ext4', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=1, preserve=None)), VolumeStructure(name='ubuntu-save', label='ubuntu-save', offset=1573912576, offset_write=None, size=33554432, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-save', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None)), VolumeStructure(name='ubuntu-data', label='ubuntu-data', offset=1607467008, offset_write=None, size=4294967296, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-data', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None))])}, storage_encryption=StorageEncryption(support=, storage_safety=, encryption_type=, unavailable_reason='not encrypting device storage as checking TPM gave: not a supported EFI system')) 2023-09-21 14:40:37,607 DEBUG subiquity.server.controllers.filesystem:412 got system SystemDetails(current=False, volumes={'pc': Volume(schema='gpt', bootloader='grub', id='', structure=[VolumeStructure(name='EFI System partition', label='ubuntu-seed', offset=1048576, offset_write=None, size=786432000, type='C12A7328-F81F-11D2-BA4B-00A0C93EC93B', role='system-seed-null', id='', filesystem='vfat', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=2, preserve=None)), VolumeStructure(name='ubuntu-boot', label='ubuntu-boot', offset=787480576, offset_write=None, size=786432000, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-boot', id='', filesystem='ext4', content=[VolumeContent(source='grubx64.efi', target='EFI/boot/grubx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False), VolumeContent(source='shim.efi.signed', target='EFI/boot/bootx64.efi', image='', offset=None, offset_write=None, size=0, unpack=False)], update=VolumeUpdate(edition=1, preserve=None)), VolumeStructure(name='ubuntu-save', label='ubuntu-save', offset=1573912576, offset_write=None, size=33554432, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-save', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None)), VolumeStructure(name='ubuntu-data', label='ubuntu-data', offset=1607467008, offset_write=None, size=4294967296, type='0FC63DAF-8483-4772-8E79-3D69D8477DE4', role='system-data', id='', filesystem='ext4', content=None, update=VolumeUpdate(edition=0, preserve=None))])}, storage_encryption=StorageEncryption(support=, storage_safety=, encryption_type=, unavailable_reason='not encrypting device storage as checking TPM gave: not a supported EFI system')) for variation minimal-enhanced-secureboot 2023-09-21 14:40:37,607 DEBUG subiquity.server.controllers.filesystem:421 Disabling core boot based install options on non-UEFI system 2023-09-21 14:40:37,607 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:37,608 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:37,608 INFO aiohttp.access:206 [21/Sep/2023:14:40:34 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 697 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:37,608 DEBUG subiquitycore.utils:76 run_command called: ['udevadm', 'settle', '-t', '0'] 2023-09-21 14:40:37,633 DEBUG subiquitycore.utils:95 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0 2023-09-21 14:40:37,633 DEBUG subiquity.server.controllers.filesystem:1497 _udev_event change Device('/sys/devices/virtual/block/loop14') 2023-09-21 14:40:37,634 DEBUG subiquity.server.controllers.filesystem:1497 _udev_event change Device('/sys/devices/virtual/block/loop14') 2023-09-21 14:40:37,634 DEBUG subiquity.server.controllers.filesystem:1497 _udev_event change Device('/sys/devices/virtual/block/loop13') 2023-09-21 14:40:37,634 DEBUG subiquity.server.controllers.filesystem:1497 _udev_event change Device('/sys/devices/virtual/block/loop13') 2023-09-21 14:40:37,634 DEBUG subiquity.server.controllers.filesystem:1480 Triggered Probert run on udev event 2023-09-21 14:40:37,634 DEBUG root:30 start: subiquity/Filesystem/_probe: 2023-09-21 14:40:37,635 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False 2023-09-21 14:40:37,635 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-09-21 14:40:37,636 DEBUG asyncio:54 Using selector: EpollSelector 2023-09-21 14:40:37,994 DEBUG probert.dasd:134 Probing DASD devies 2023-09-21 14:40:37,994 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64 2023-09-21 14:40:38,052 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2023-09-21 14:40:38,053 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2023-09-21 14:40:38,056 DEBUG curtin:1321 Extracting storage config from probe data 2023-09-21 14:40:38,056 DEBUG curtin:73 /dev/vda is multipath device member? False 2023-09-21 14:40:38,057 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:38,057 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:38,057 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:38,057 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:38,067 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:38,067 DEBUG curtin:86 /dev/sr0 is multipath device partition? False 2023-09-21 14:40:38,067 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:38,067 DEBUG curtin:1328 Sorting extracted configurations 2023-09-21 14:40:38,068 INFO curtin:1347 Validating extracted storage config components 2023-09-21 14:40:38,078 DEBUG curtin:1364 Extracted (unmerged) storage config: storage: - id: disk-vda path: /dev/vda type: disk 2023-09-21 14:40:38,078 DEBUG curtin:1368 Generating storage config dependencies 2023-09-21 14:40:38,078 DEBUG curtin:1374 Merging storage config dependencies 2023-09-21 14:40:38,079 DEBUG curtin:1379 Merged storage config: storage: config: - id: disk-vda path: /dev/vda type: disk version: 2 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')} 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:44 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40 2023-09-21 14:40:38,079 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:47 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:50 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:88 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:38,080 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:38,080 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=False 2023-09-21 14:40:38,080 DEBUG subiquity.server.controllers.filesystem:1295 block probing took 0.4 seconds 2023-09-21 14:40:38,080 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 2023-09-21 14:40:38,080 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:38,081 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:38,081 INFO aiohttp.access:206 [21/Sep/2023:14:40:37 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 697 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:38,082 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 2023-09-21 14:40:38,082 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:38,083 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di... 2023-09-21 14:40:38,083 INFO aiohttp.access:206 [21/Sep/2023:14:40:38 +0000] "GET /storage/v2/guided?wait=true HTTP/1.1" 200 788 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:38,084 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 2023-09-21 14:40:38,084 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 [] 2023-09-21 14:40:38,084 INFO aiohttp.access:206 [21/Sep/2023:14:40:38 +0000] "GET /storage/has_bitlocker HTTP/1.1" 200 188 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,256 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 2023-09-21 14:40:40,256 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 [] 2023-09-21 14:40:40,257 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "GET /storage/has_bitlocker HTTP/1.1" 200 188 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,258 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-09-21 14:40:40,258 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,259 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:40,259 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 697 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,261 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 2023-09-21 14:40:40,262 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,264 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di... 2023-09-21 14:40:40,264 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "GET /storage/v2/guided?wait=true HTTP/1.1" 200 788 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,266 DEBUG root:30 start: subiquity/Filesystem/v2_guided_POST: 2023-09-21 14:40:40,267 DEBUG subiquity.server.controllers.filesystem:1150 GuidedChoiceV2(target=GuidedStorageTargetReformat(disk_id='disk-vda', allowed=[, , , ], disallowed=[GuidedDisallowedCapability(capability=, reason=, message='not encrypting device storage as checking TPM gave: not a supported EFI system'), GuidedDisallowedCapability(capability=, reason=, message='Enhanced secure boot options only available on UEFI systems.')]), capability=, recovery_key=None, sizing_policy=, reset_partition=False) 2023-09-21 14:40:40,267 DEBUG subiquity.models.filesystem:2094 adding ext4 to Partition(device=disk-vda, size=16102981632, wipe='superblock', number=2, grub_device=None, offset=2097152, id='partition-1') 2023-09-21 14:40:40,268 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,269 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": {"target": {"disk_id":... 2023-09-21 14:40:40,269 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "POST /storage/v2/guided HTTP/1.1" 200 1355 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,271 DEBUG root:30 start: subiquity/Filesystem/v2_POST: 2023-09-21 14:40:40,271 DEBUG subiquity.models.subiquity:252 model filesystem for install stage is configured, to go {'network'} 2023-09-21 14:40:40,271 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,272 DEBUG root:30 finish: subiquity/Filesystem/v2_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:40,273 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "POST /storage/v2 HTTP/1.1" 200 1285 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,273 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 2023-09-21 14:40:40,274 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,274 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:40,275 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "GET /storage/v2?wait=true HTTP/1.1" 200 1285 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:40,278 DEBUG root:30 start: subiquity/Filesystem/v2_orig_config_GET: 2023-09-21 14:40:40,279 DEBUG curtin:1321 Extracting storage config from probe data 2023-09-21 14:40:40,279 DEBUG curtin:73 /dev/vda is multipath device member? False 2023-09-21 14:40:40,279 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:40,279 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:40,279 DEBUG curtin:86 /dev/vda is multipath device partition? False 2023-09-21 14:40:40,279 DEBUG curtin:61 /dev/vda is multipath device? False 2023-09-21 14:40:40,296 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:40,297 DEBUG curtin:86 /dev/sr0 is multipath device partition? False 2023-09-21 14:40:40,297 DEBUG curtin:73 /dev/sr0 is multipath device member? False 2023-09-21 14:40:40,297 DEBUG curtin:1328 Sorting extracted configurations 2023-09-21 14:40:40,297 INFO curtin:1347 Validating extracted storage config components 2023-09-21 14:40:40,314 DEBUG curtin:1364 Extracted (unmerged) storage config: storage: - id: disk-vda path: /dev/vda type: disk 2023-09-21 14:40:40,314 DEBUG curtin:1368 Generating storage config dependencies 2023-09-21 14:40:40,314 DEBUG curtin:1374 Merging storage config dependencies 2023-09-21 14:40:40,314 DEBUG curtin:1379 Merged storage config: storage: config: - id: disk-vda path: /dev/vda type: disk version: 2 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1452 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')} 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:22 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:23 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:5 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 11:0 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:0 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:44 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:28 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:6 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:35 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:36 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:37 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:12 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:7 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:21 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:40 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:38 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:24 2023-09-21 14:40:40,315 DEBUG subiquity.models.filesystem:1464 considering mount of 0:33 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:20 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:39 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:34 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:41 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:42 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:43 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:62 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:25 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:45 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:47 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:4 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:6 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:5 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:3 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:7 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:12 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:11 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:8 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:9 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 7:10 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:50 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:63 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:88 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:40,316 DEBUG subiquity.models.filesystem:1464 considering mount of 0:4 2023-09-21 14:40:40,316 DEBUG subiquity.server.controllers.filesystem:994 suggested install minimum size: 8.277G 2023-09-21 14:40:40,317 DEBUG root:30 finish: subiquity/Filesystem/v2_orig_config_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"... 2023-09-21 14:40:40,317 INFO aiohttp.access:206 [21/Sep/2023:14:40:40 +0000] "GET /storage/v2/orig_config HTTP/1.1" 200 697 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,486 DEBUG root:30 start: subiquity/TimeZone/GET: 2023-09-21 14:40:41,606 DEBUG root:30 finish: subiquity/TimeZone/GET: SUCCESS: 200 {"timezone": "Etc/UTC", "from_geoip": false} 2023-09-21 14:40:41,607 INFO aiohttp.access:206 [21/Sep/2023:14:40:41 +0000] "GET /timezone HTTP/1.1" 200 231 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,687 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-09-21 14:40:41,688 DEBUG subiquitycore.models.network:467 has_network True 2023-09-21 14:40:41,688 DEBUG subiquity.models.subiquity:252 model network for install stage is configured, to go set() 2023-09-21 14:40:41,688 DEBUG subiquity.models.subiquity:252 model network for postinstall stage is configured, to go {'timezone', 'identity'} 2023-09-21 14:40:41,688 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-09-21 14:40:41,689 INFO aiohttp.access:206 [21/Sep/2023:14:40:41 +0000] "POST /meta/mark_configured?endpoint_names=%5B%22network%22%5D HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,689 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "NEEDS_CONFIRMATION", "confirming_tty": "", "error": null, "cloud_i... 2023-09-21 14:40:41,690 INFO aiohttp.access:206 [21/Sep/2023:14:40:01 +0000] "GET /meta/status?cur=%22WAITING%22 HTTP/1.1" 200 423 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,690 INFO root:30 start: subiquity/Meta/confirm_POST: 2023-09-21 14:40:41,691 DEBUG subiquity.models.subiquity:252 model ssh for postinstall stage is configured, to go {'timezone', 'identity'} 2023-09-21 14:40:41,691 DEBUG subiquity.models.subiquity:252 model snaplist for postinstall stage is configured, to go {'timezone', 'identity'} 2023-09-21 14:40:41,691 INFO root:30 finish: subiquity/Meta/confirm_POST: SUCCESS: 200 null 2023-09-21 14:40:41,691 INFO aiohttp.access:206 [21/Sep/2023:14:40:41 +0000] "POST /meta/confirm?tty=%22%2Fdev%2Ftty1%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,692 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_confirmation: SUCCESS: 2023-09-21 14:40:41,692 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_apt: 2023-09-21 14:40:41,693 INFO root:30 start: subiquity/Install/install/configure_apt: configuring apt 2023-09-21 14:40:41,693 DEBUG root:30 start: subiquity/Mirror/waiting: 2023-09-21 14:40:41,693 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:40:41,694 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-09-21 14:40:41,694 INFO aiohttp.access:206 [21/Sep/2023:14:40:41 +0000] "GET /meta/status?cur=%22NEEDS_CONFIRMATION%22 HTTP/1.1" 200 421 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:41,695 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:40:46,042 DEBUG root:30 start: subiquity/TimeZone/POST: 2023-09-21 14:40:46,074 DEBUG subiquity.models.subiquity:252 model timezone for postinstall stage is configured, to go {'identity'} 2023-09-21 14:40:46,074 DEBUG root:30 finish: subiquity/TimeZone/POST: SUCCESS: 200 null 2023-09-21 14:40:46,075 INFO aiohttp.access:206 [21/Sep/2023:14:40:46 +0000] "POST /timezone?tz=%22Europe%2FParis%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:46,076 DEBUG root:30 start: subiquity/Identity/GET: 2023-09-21 14:40:46,076 DEBUG root:30 finish: subiquity/Identity/GET: SUCCESS: 200 {"realname": "", "username": "", "crypted_password": "", "hostname": ""} 2023-09-21 14:40:46,077 INFO aiohttp.access:206 [21/Sep/2023:14:40:46 +0000] "GET /identity HTTP/1.1" 200 259 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:46,079 DEBUG root:30 start: subiquity/Ad/has_support_GET: 2023-09-21 14:40:46,079 DEBUG root:30 finish: subiquity/Ad/has_support_GET: SUCCESS: 200 true 2023-09-21 14:40:46,079 INFO aiohttp.access:206 [21/Sep/2023:14:40:46 +0000] "GET /active_directory/has_support HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:47,630 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:47,632 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:47,633 INFO aiohttp.access:206 [21/Sep/2023:14:40:47 +0000] "GET /identity/validate_username?username=%22j%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:47,712 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:47,713 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:47,713 INFO aiohttp.access:206 [21/Sep/2023:14:40:47 +0000] "GET /identity/validate_username?username=%22je%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:47,799 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:47,800 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:47,800 INFO aiohttp.access:206 [21/Sep/2023:14:40:47 +0000] "GET /identity/validate_username?username=%22jer%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:47,897 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:47,897 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:47,897 INFO aiohttp.access:206 [21/Sep/2023:14:40:47 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:48,047 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:48,049 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:48,050 INFO aiohttp.access:206 [21/Sep/2023:14:40:48 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:48,341 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:48,342 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:48,343 INFO aiohttp.access:206 [21/Sep/2023:14:40:48 +0000] "GET /identity/validate_username?username=%22jere-y%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:48,833 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:48,834 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:48,835 INFO aiohttp.access:206 [21/Sep/2023:14:40:48 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:48,992 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:48,993 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:48,994 INFO aiohttp.access:206 [21/Sep/2023:14:40:48 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:49,524 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:49,524 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:49,525 INFO aiohttp.access:206 [21/Sep/2023:14:40:49 +0000] "GET /identity/validate_username?username=%22jerem%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:49,873 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:49,873 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:49,874 INFO aiohttp.access:206 [21/Sep/2023:14:40:49 +0000] "GET /identity/validate_username?username=%22jeremy%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:50,460 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:50,461 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:50,462 INFO aiohttp.access:206 [21/Sep/2023:14:40:50 +0000] "GET /identity/validate_username?username=%22jeremy%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:50,640 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:50,641 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:50,641 INFO aiohttp.access:206 [21/Sep/2023:14:40:50 +0000] "GET /identity/validate_username?username=%22jeremy-b%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:50,779 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:50,780 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:50,781 INFO aiohttp.access:206 [21/Sep/2023:14:40:50 +0000] "GET /identity/validate_username?username=%22jeremy-bi%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:50,866 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:50,867 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:50,867 INFO aiohttp.access:206 [21/Sep/2023:14:40:50 +0000] "GET /identity/validate_username?username=%22jeremy-bic%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:50,980 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:50,981 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:50,982 INFO aiohttp.access:206 [21/Sep/2023:14:40:50 +0000] "GET /identity/validate_username?username=%22jeremy-bich%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:51,142 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:51,143 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:51,144 INFO aiohttp.access:206 [21/Sep/2023:14:40:51 +0000] "GET /identity/validate_username?username=%22jeremy-bichq%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:51,694 ERROR root:30 finish: subiquity/Mirror/waiting: FAIL: 2023-09-21 14:40:51,694 DEBUG subiquity.server.controllers.mirror:202 Iterating over country-mirror 2023-09-21 14:40:51,694 DEBUG subiquity.server.controllers.mirror:208 Skipping unresolved country mirror 2023-09-21 14:40:51,694 DEBUG subiquity.server.controllers.mirror:202 Iterating over {'uri': 'http://archive.ubuntu.com/ubuntu/', 'arches': ['amd64', 'i386']} 2023-09-21 14:40:51,694 DEBUG subiquity.server.controllers.mirror:205 Will check next candiate mirror after 10 seconds. 2023-09-21 14:40:54,978 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:54,979 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:54,980 INFO aiohttp.access:206 [21/Sep/2023:14:40:54 +0000] "GET /identity/validate_username?username=%22jeremy-bich%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:55,162 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:55,163 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:55,165 INFO aiohttp.access:206 [21/Sep/2023:14:40:55 +0000] "GET /identity/validate_username?username=%22jeremy-bicha%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:57,099 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:57,100 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:57,101 INFO aiohttp.access:206 [21/Sep/2023:14:40:57 +0000] "GET /identity/validate_username?username=%22j%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:57,208 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:57,209 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:57,210 INFO aiohttp.access:206 [21/Sep/2023:14:40:57 +0000] "GET /identity/validate_username?username=%22je%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:57,327 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:57,328 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:57,329 INFO aiohttp.access:206 [21/Sep/2023:14:40:57 +0000] "GET /identity/validate_username?username=%22jer%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:57,409 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:57,410 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:57,410 INFO aiohttp.access:206 [21/Sep/2023:14:40:57 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:58,141 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:58,142 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:58,142 INFO aiohttp.access:206 [21/Sep/2023:14:40:58 +0000] "GET /identity/validate_username?username=%22jere%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:58,482 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:58,483 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:58,484 INFO aiohttp.access:206 [21/Sep/2023:14:40:58 +0000] "GET /identity/validate_username?username=%22jerem%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:40:58,736 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 2023-09-21 14:40:58,737 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK" 2023-09-21 14:40:58,737 INFO aiohttp.access:206 [21/Sep/2023:14:40:58 +0000] "GET /identity/validate_username?username=%22jeremy%22 HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:41:01,698 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp41vn2l98/minimal.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:41:01,713 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.fr.squashfs', '/tmp/tmp41vn2l98/minimal.fr.squashfs.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:41:01,746 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp41vn2l98/minimal.fr.squashfs.dir:/tmp/tmp41vn2l98/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp41vn2l98/root.dir'] with allowed return codes [0] (capture=True) 2023-09-21 14:41:01,751 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'mount', '-o', 'lowerdir=/tmp/tmp41vn2l98/root.dir,upperdir=/tmp/tmpzn6753ss/upper,workdir=/tmp/tmpzn6753ss/work', '-t', 'overlay', 'overlay', '/tmp/tmpzn6753ss/mount'] 2023-09-21 14:41:01,805 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', '/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2069.1"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmpzn6753ss/mount'] 2023-09-21 14:41:03,407 DEBUG root:30 start: subiquity/Mirror/cmd-apt-config: curtin command apt-config 2023-09-21 14:41:03,633 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-09-21 14:41:03,715 DEBUG root:30 finish: subiquity/Mirror/cmd-apt-config: SUCCESS: curtin command apt-config 2023-09-21 14:41:03,735 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-09-21 14:41:03,739 DEBUG subiquitycore.utils:151 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-09-21 14:41:10,325 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2023-09-21 14:41:10,325 DEBUG subiquity.models.subiquity:252 model active_directory for postinstall stage is configured, to go {'identity'} 2023-09-21 14:41:10,326 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2023-09-21 14:41:10,326 INFO aiohttp.access:206 [21/Sep/2023:14:41:10 +0000] "POST /meta/mark_configured?endpoint_names=%5B%22active_directory%22%5D HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:41:10,368 DEBUG root:30 start: subiquity/Identity/POST: 2023-09-21 14:41:10,368 DEBUG subiquity.models.subiquity:252 model identity for postinstall stage is configured, to go set() 2023-09-21 14:41:10,368 DEBUG root:30 finish: subiquity/Identity/POST: SUCCESS: 200 null 2023-09-21 14:41:10,369 INFO aiohttp.access:206 [21/Sep/2023:14:41:10 +0000] "POST /identity HTTP/1.1" 200 190 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:41:11,173 WARNING subiquity.server.controllers.mirror:173 Mirror checking failed 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:178 APT output follows 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Err :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Err :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Err :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 Lecture des listes de paquets… 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic-updates/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic-backports/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:180 E: Le téléchargement de quelques fichiers d'index a échoué, ils ont été ignorés, ou les anciens ont été utilisés à la place. 2023-09-21 14:41:11,174 DEBUG subiquity.server.controllers.mirror:214 Retrying in 10 seconds... 2023-09-21 14:41:13,565 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:41:13,566 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-09-21 14:41:13,568 INFO aiohttp.access:206 [21/Sep/2023:14:41:13 +0000] "GET /meta/status HTTP/1.1" 200 421 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:41:13,902 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:41:13,902 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2023-09-21 14:41:13,902 INFO aiohttp.access:206 [21/Sep/2023:14:41:13 +0000] "GET /meta/status HTTP/1.1" 200 421 "-" "Dart/3.0 (dart:io)" 2023-09-21 14:41:13,950 INFO root:30 start: subiquity/Meta/status_GET: 2023-09-21 14:41:21,181 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', 'mount', '-o', 'lowerdir=/tmp/tmp41vn2l98/root.dir,upperdir=/tmp/tmpxqohrsai/upper,workdir=/tmp/tmpxqohrsai/work', '-t', 'overlay', 'overlay', '/tmp/tmpxqohrsai/mount'] 2023-09-21 14:41:21,232 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2069', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1243/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1243/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1243/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/usr/sbin:/snap/ubuntu-desktop-installer/1243/usr/bin:/snap/ubuntu-desktop-installer/1243/sbin:/snap/ubuntu-desktop-installer/1243/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/1243/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1243/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1243', '--', '/snap/ubuntu-desktop-installer/1243/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2069.2"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmpxqohrsai/mount'] 2023-09-21 14:41:22,894 DEBUG root:30 start: subiquity/Mirror/cmd-apt-config: curtin command apt-config 2023-09-21 14:41:23,125 DEBUG subiquity.server.curtin:130 waited 0.1 seconds for events to drain 2023-09-21 14:41:23,210 DEBUG root:30 finish: subiquity/Mirror/cmd-apt-config: SUCCESS: curtin command apt-config 2023-09-21 14:41:23,225 DEBUG subiquity.server.curtin:130 waited 0.2 seconds for events to drain 2023-09-21 14:41:23,227 DEBUG subiquitycore.utils:151 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-09-21 14:41:30,488 WARNING subiquity.server.controllers.mirror:173 Mirror checking failed 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:178 APT output follows 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:30,488 DEBUG subiquity.server.controllers.mirror:180 Ign :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Err :1 http://archive.ubuntu.com/ubuntu mantic InRelease 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Err :2 http://archive.ubuntu.com/ubuntu mantic-updates InRelease 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Err :3 http://archive.ubuntu.com/ubuntu mantic-backports InRelease 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 Lecture des listes de paquets… 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic-updates/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 E: Impossible de récupérer http://archive.ubuntu.com/ubuntu/dists/mantic-backports/InRelease Erreur temporaire de résolution de « archive.ubuntu.com » 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:180 E: Le téléchargement de quelques fichiers d'index a échoué, ils ont été ignorés, ou les anciens ont été utilisés à la place. 2023-09-21 14:41:30,489 DEBUG subiquity.server.controllers.mirror:222 Mirror is not usable. 2023-09-21 14:41:30,489 ERROR subiquity.server.controllers.mirror:234 aborting the install since no primary mirror is usable 2023-09-21 14:41:30,490 ERROR root:30 finish: subiquity/Install/install/configure_apt: FAIL: aborting install since no mirror is usable 2023-09-21 14:41:30,490 DEBUG subiquity.common.errorreport:394 generating crash report 2023-09-21 14:41:30,506 INFO subiquity.common.errorreport:415 saving crash report 'install failed crashed with RuntimeError' to /var/crash/1695307290.491036892.install_fail.crash 2023-09-21 14:41:30,506 ERROR root:30 finish: subiquity/Install/install: FAIL: aborting install since no mirror is usable 2023-09-21 14:41:30,507 INFO root:30 start: subiquity/ErrorReporter/1695307290.491036892.install_fail/add_info: