2024-01-19 00:37:46,583 INFO subiquity:199 Starting Subiquity server revision 13 of snap /snap/edubuntu-desktop-installer/13
2024-01-19 00:37:46,583 INFO subiquity:200 Arguments passed: ['/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/edubuntu-desktop-installer/13/etc/subiquity/postinst.d']
2024-01-19 00:37:46,583 DEBUG subiquity:201 Kernel commandline: CommandLineParams(_raw='BOOT_IMAGE=/casper/vmlinuz layerfs-path=minimal.standard.live.squashfs --- quiet splash\n', _tokens={'---', 'quiet', 'splash'}, _values={'BOOT_IMAGE': '/casper/vmlinuz', 'layerfs-path': 'minimal.standard.live.squashfs'})
2024-01-19 00:37:46,583 DEBUG subiquity:202 Environment: environ({'SNAP_REVISION': '13', 'SNAP_REAL_HOME': '/root', 'SNAP_USER_COMMON': '/root/snap/edubuntu-desktop-installer/common', 'PATH_ORIG': '/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/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/edubuntu-desktop-installer/13/bin/subiquity', 'SYSTEMD_EXEC_PID': '3177', 'SNAP_CONTEXT': 'eZB8dSpyPUuzvRWmBxFjHMfvuOTV7PiBxrekwN_I8kqoAtitzqeN', 'LANG': 'C.UTF-8', 'SNAP_ARCH': 'amd64', 'PY3OR2_PYTHON': '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', 'SNAP_INSTANCE_NAME': 'edubuntu-desktop-installer', 'SNAP_USER_DATA': '/root/snap/edubuntu-desktop-installer/13', 'INVOCATION_ID': '3fa20f4fa23f4090ae3bbff73176bc02', 'SNAP_REEXEC': '', 'SNAP_UID': '0', 'LD_LIBRARY_PATH_ORIG': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/edubuntu-desktop-installer/13/lib:/snap/edubuntu-desktop-installer/13/usr/lib:/snap/edubuntu-desktop-installer/13/lib/x86_64-linux-gnu:/snap/edubuntu-desktop-installer/13/usr/lib/x86_64-linux-gnu', 'PYTHONPATH_ORIG': '', 'PYTHONPATH': '/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', 'PYTHON': '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', 'PYTHONIOENCODING': 'utf-8', 'SNAP': '/snap/edubuntu-desktop-installer/13', 'SNAP_COMMON': '/var/snap/edubuntu-desktop-installer/common', 'SNAP_VERSION': '0+git.96739f1', 'DISPLAY': ':0', 'SHLVL': '1', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'SNAP_COOKIE': 'eZB8dSpyPUuzvRWmBxFjHMfvuOTV7PiBxrekwN_I8kqoAtitzqeN', 'SNAP_DATA': '/var/snap/edubuntu-desktop-installer/13', 'LD_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void:/snap/edubuntu-desktop-installer/13/lib:/snap/edubuntu-desktop-installer/13/usr/lib:/snap/edubuntu-desktop-installer/13/lib/x86_64-linux-gnu:/snap/edubuntu-desktop-installer/13/usr/lib/x86_64-linux-gnu', 'SNAP_NAME': 'edubuntu-desktop-installer', 'JOURNAL_STREAM': '8:6141', 'PATH': '/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', 'SUBIQUITY_ROOT': '/snap/edubuntu-desktop-installer/13/bin/subiquity', 'OLDPWD': '/var/snap/edubuntu-desktop-installer/13', '_': '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', 'APPORT_DATA_DIR': '/snap/edubuntu-desktop-installer/13/bin/subiquity/share/apport'})
2024-01-19 00:37:46,584 DEBUG asyncio:54 Using selector: EpollSelector
2024-01-19 00:37:46,585 DEBUG subiquitycore.prober:33 Prober() init finished, data:None
2024-01-19 00:37:46,659 DEBUG curtin:95 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
2024-01-19 00:37:46,710 DEBUG subiquitycore.utils:118 arun_command called: ['cloud-init', 'status', '--wait']
2024-01-19 00:37:47,260 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:47,261 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...
2024-01-19 00:37:48,264 DEBUG curtin.reporting.start.subiquity/Meta/status_GET:45 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:48,264 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...
2024-01-19 00:37:48,953 DEBUG subiquitycore.utils:132 arun_command ['cloud-init', 'status', '--wait'] exited with code 0
2024-01-19 00:37:48,954 DEBUG subiquity.server.server:569 waited 2.243342399597168s for cloud-init
2024-01-19 00:37:48,954 DEBUG subiquity.server.server:573 cloud-init status: '\nstatus: disabled\n', assumed disabled
2024-01-19 00:37:48,956 DEBUG subiquity.server.server:470 load_autoinstall_config only_early True file None
2024-01-19 00:37:48,956 DEBUG subiquity.server.server:470 load_autoinstall_config only_early False file None
2024-01-19 00:37:48,957 DEBUG subiquitycore.core:118 starting controllers
2024-01-19 00:37:48,962 DEBUG subiquity.server.controllers.kernel:63 Using kernel linux-generic due to /etc/subiquity/kernel-meta-package
2024-01-19 00:37:48,965 DEBUG subiquity.models.source:93 loaded 2 sources from '/cdrom/casper/install-sources.yaml'
2024-01-19 00:37:48,969 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2024-01-19 00:37:48,969 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2024-01-19 00:37:48,969 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2024-01-19 00:37:48,969 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'10.0.2.15/24'}
2024-01-19 00:37:48,970 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2024-01-19 00:37:48,970 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 1, 'family': 10, 'scope': 200, 'local': b'fec0::80fd:9525:30cd:595b/64'}
2024-01-19 00:37:48,970 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 200, 'local': b'fec0::9953:2a6e:da19:8584/64'}
2024-01-19 00:37:48,970 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 2, 'flags': 640, 'family': 10, 'scope': 253, 'local': b'fe80::10a4:a52e:bcce:c311/64'}
2024-01-19 00:37:48,970 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2024-01-19 00:37:49,045 DEBUG subiquitycore.models.network:475 new_link 1 lo lo
2024-01-19 00:37:49,045 DEBUG subiquitycore.models.network:477 ignoring based on type
2024-01-19 00:37:49,045 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 69699, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'enp1s0'}
2024-01-19 00:37:49,110 DEBUG subiquitycore.models.network:475 new_link 2 enp1s0 eth
2024-01-19 00:37:49,110 DEBUG subiquitycore.models.network:506 new_link 2 enp1s0 with config {}
2024-01-19 00:37:49,110 DEBUG root:30 start: subiquity/Network/_send_update: NEW enp1s0
2024-01-19 00:37:49,110 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: NEW enp1s0
2024-01-19 00:37:49,110 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2024-01-19 00:37:49,110 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 512, 'family': 2, 'scope': 0, 'local': b'10.0.2.15/24'}
2024-01-19 00:37:49,111 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2024-01-19 00:37:49,111 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2024-01-19 00:37:49,111 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2024-01-19 00:37:49,111 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 1, 'family': 10, 'scope': 200, 'local': b'fec0::80fd:9525:30cd:595b/64'}
2024-01-19 00:37:49,112 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2024-01-19 00:37:49,112 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2024-01-19 00:37:49,112 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 200, 'local': b'fec0::9953:2a6e:da19:8584/64'}
2024-01-19 00:37:49,112 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2024-01-19 00:37:49,112 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2024-01-19 00:37:49,112 DEBUG probert.network:717 addr_change NEW {'ifindex': 2, 'flags': 640, 'family': 10, 'scope': 253, 'local': b'fe80::10a4:a52e:bcce:c311/64'}
2024-01-19 00:37:49,112 DEBUG root:30 start: subiquity/Network/_send_update: CHANGE enp1s0
2024-01-19 00:37:49,113 DEBUG root:30 finish: subiquity/Network/_send_update: SUCCESS: CHANGE enp1s0
2024-01-19 00:37:49,113 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2}
2024-01-19 00:37:49,210 DEBUG pyroute2.ndb.139138816437760.sources.localhost:74 init
2024-01-19 00:37:49,211 DEBUG pyroute2.ndb.139138816437760.sources.localhost:384 starting the source
2024-01-19 00:37:49,212 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:74 init
2024-01-19 00:37:49,212 DEBUG pyroute2.ndb.139138816437760.sources.localhost:74 connecting
2024-01-19 00:37:49,213 DEBUG pyroute2.ndb.139138816437760.sources.localhost:74 loading
2024-01-19 00:37:49,213 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:384 starting the source
2024-01-19 00:37:49,214 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:74 connecting
2024-01-19 00:37:49,217 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:74 loading
2024-01-19 00:37:49,242 DEBUG pyroute2.ndb.139138816437760.sources.localhost:74 running
2024-01-19 00:37:49,245 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:74 running
2024-01-19 00:37:49,247 DEBUG pyroute2.ndb.139138816437760.sources.localhost:399 source shutdown
2024-01-19 00:37:49,248 DEBUG pyroute2.ndb.139138816437760.sources.localhost:374 sync
2024-01-19 00:37:49,248 DEBUG pyroute2.ndb.139138816437760.sources.localhost:369 shutdown handled by the main thread
2024-01-19 00:37:49,248 DEBUG pyroute2.ndb.139138816437760.sources.localhost:74 stopped
2024-01-19 00:37:49,248 DEBUG pyroute2.ndb.139138816437760.main:851 flush DB for the target localhost
2024-01-19 00:37:49,249 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:399 source shutdown
2024-01-19 00:37:49,266 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:374 sync
2024-01-19 00:37:49,266 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:369 shutdown handled by the main thread
2024-01-19 00:37:49,267 DEBUG pyroute2.ndb.139138816437760.sources.localhost/nsmanager:74 stopped
2024-01-19 00:37:49,267 DEBUG pyroute2.ndb.139138816437760.main:851 flush DB for the target localhost/nsmanager
2024-01-19 00:37:49,270 DEBUG subiquitycore.controllers.network:102 default routes True
2024-01-19 00:37:49,270 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 1, 'table': 254, 'dst': b'10.0.2.0/24', 'ifindex': 2}
2024-01-19 00:37:49,270 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'10.0.2.15', 'ifindex': 2}
2024-01-19 00:37:49,270 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'10.0.2.255', 'ifindex': 2}
2024-01-19 00:37:49,270 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1}
2024-01-19 00:37:49,270 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1}
2024-01-19 00:37:49,271 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1}
2024-01-19 00:37:49,271 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1}
2024-01-19 00:37:49,271 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fe80::/64', 'ifindex': 2}
2024-01-19 00:37:49,271 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'fec0::/64', 'ifindex': 2}
2024-01-19 00:37:49,271 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'default', 'ifindex': 2}
2024-01-19 00:37:49,304 DEBUG pyroute2.ndb.139138816429984.sources.localhost:74 init
2024-01-19 00:37:49,304 DEBUG pyroute2.ndb.139138816429984.sources.localhost:384 starting the source
2024-01-19 00:37:49,305 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:74 init
2024-01-19 00:37:49,305 DEBUG pyroute2.ndb.139138816429984.sources.localhost:74 connecting
2024-01-19 00:37:49,305 DEBUG pyroute2.ndb.139138816429984.sources.localhost:74 loading
2024-01-19 00:37:49,306 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:384 starting the source
2024-01-19 00:37:49,307 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:74 connecting
2024-01-19 00:37:49,309 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:74 loading
2024-01-19 00:37:49,335 DEBUG pyroute2.ndb.139138816429984.sources.localhost:74 running
2024-01-19 00:37:49,336 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:74 running
2024-01-19 00:37:49,338 DEBUG pyroute2.ndb.139138816429984.sources.localhost:399 source shutdown
2024-01-19 00:37:49,338 DEBUG pyroute2.ndb.139138816429984.sources.localhost:374 sync
2024-01-19 00:37:49,339 DEBUG pyroute2.ndb.139138816429984.sources.localhost:369 shutdown handled by the main thread
2024-01-19 00:37:49,339 DEBUG pyroute2.ndb.139138816429984.sources.localhost:74 stopped
2024-01-19 00:37:49,339 DEBUG pyroute2.ndb.139138816429984.main:851 flush DB for the target localhost
2024-01-19 00:37:49,340 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:399 source shutdown
2024-01-19 00:37:49,340 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:374 sync
2024-01-19 00:37:49,340 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:369 shutdown handled by the main thread
2024-01-19 00:37:49,340 DEBUG pyroute2.ndb.139138816429984.sources.localhost/nsmanager:74 stopped
2024-01-19 00:37:49,341 DEBUG pyroute2.ndb.139138816429984.main:851 flush DB for the target localhost/nsmanager
2024-01-19 00:37:49,342 DEBUG subiquitycore.controllers.network:102 default routes True
2024-01-19 00:37:49,342 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1}
2024-01-19 00:37:49,342 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fe80::10a4:a52e:bcce:c311', 'ifindex': 2}
2024-01-19 00:37:49,342 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fec0::80fd:9525:30cd:595b', 'ifindex': 2}
2024-01-19 00:37:49,342 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'fec0::9953:2a6e:da19:8584', 'ifindex': 2}
2024-01-19 00:37:49,342 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 5, 'table': 255, 'dst': b'ff00::/8', 'ifindex': 2}
2024-01-19 00:37:49,549 DEBUG subiquitycore.core:121 controllers started
2024-01-19 00:37:49,549 INFO root:30 start: subiquity/apply_autoinstall_config: 
2024-01-19 00:37:49,549 DEBUG root:30 start: subiquity/Early/apply_autoinstall_config: 
2024-01-19 00:37:49,553 DEBUG root:30 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,554 DEBUG root:30 start: subiquity/Reporting/apply_autoinstall_config: 
2024-01-19 00:37:49,554 DEBUG root:30 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,555 DEBUG root:30 start: subiquity/Error/apply_autoinstall_config: 
2024-01-19 00:37:49,555 DEBUG root:30 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,555 DEBUG root:30 start: subiquity/Userdata/apply_autoinstall_config: 
2024-01-19 00:37:49,555 DEBUG root:30 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,600 DEBUG subiquity.models.subiquity:256 model userdata for postinstall stage is configured, to go {'drivers', 'identity', 'ssh', 'locale', 'packages', 'ubuntu_pro', 'snaplist'}
2024-01-19 00:37:49,600 DEBUG root:30 start: subiquity/Package/apply_autoinstall_config: 
2024-01-19 00:37:49,600 DEBUG root:30 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,601 DEBUG subiquity.models.subiquity:256 model packages for postinstall stage is configured, to go {'drivers', 'identity', 'ssh', 'locale', 'ubuntu_pro', 'snaplist'}
2024-01-19 00:37:49,601 DEBUG root:30 start: subiquity/Debconf/apply_autoinstall_config: 
2024-01-19 00:37:49,601 DEBUG root:30 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,601 DEBUG subiquity.models.subiquity:256 model debconf_selections for install stage is configured, to go {'filesystem', 'source', 'proxy', 'kernel', 'keyboard'}
2024-01-19 00:37:49,601 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Locale as interactive
2024-01-19 00:37:49,601 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Refresh as interactive
2024-01-19 00:37:49,602 DEBUG root:30 start: subiquity/Kernel/apply_autoinstall_config: 
2024-01-19 00:37:49,602 DEBUG root:30 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,602 DEBUG subiquity.models.subiquity:256 model kernel for install stage is configured, to go {'source', 'proxy', 'keyboard', 'filesystem'}
2024-01-19 00:37:49,602 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Integrity as interactive
2024-01-19 00:37:49,602 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Keyboard as interactive
2024-01-19 00:37:49,603 DEBUG root:30 start: subiquity/Zdev/apply_autoinstall_config: 
2024-01-19 00:37:49,603 DEBUG root:30 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,603 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Source as interactive
2024-01-19 00:37:49,603 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Network as interactive
2024-01-19 00:37:49,603 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping UbuntuPro as interactive
2024-01-19 00:37:49,603 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Proxy as interactive
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Mirror as interactive
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Filesystem as interactive
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Identity as interactive
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SSH as interactive
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping SnapList as interactive
2024-01-19 00:37:49,604 DEBUG root:30 start: subiquity/Ad/apply_autoinstall_config: 
2024-01-19 00:37:49,604 DEBUG root:30 finish: subiquity/Ad/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,604 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Codecs as interactive
2024-01-19 00:37:49,605 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Drivers as interactive
2024-01-19 00:37:49,605 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping OEM as interactive
2024-01-19 00:37:49,605 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping TimeZone as interactive
2024-01-19 00:37:49,605 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Install as interactive
2024-01-19 00:37:49,605 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Updates as interactive
2024-01-19 00:37:49,605 DEBUG root:30 start: subiquity/Late/apply_autoinstall_config: 
2024-01-19 00:37:49,605 DEBUG root:30 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,606 DEBUG subiquity.server.server:461 apply_autoinstall_config: skipping Shutdown as interactive
2024-01-19 00:37:49,606 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 
2024-01-19 00:37:49,606 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'drivers', 'identity', 'ssh', 'ubuntu_pro', 'snaplist'}
2024-01-19 00:37:49,606 DEBUG root:30 start: subiquity/Refresh/configure_snapd: 
2024-01-19 00:37:49,606 DEBUG root:30 start: subiquity/Refresh/configure_snapd/get_details: 
2024-01-19 00:37:49,607 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2024-01-19 00:37:49,608 DEBUG subiquitycore.utils:118 arun_command called: ['/usr/sbin/realm', 'discover']
2024-01-19 00:37:49,614 DEBUG root:30 start: subiquity/OEM/load_metapackages_list: 
2024-01-19 00:37:49,615 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation: 
2024-01-19 00:37:49,615 DEBUG root:30 start: subiquity/Install/install: 
2024-01-19 00:37:49,618 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps
2024-01-19 00:37:49,731 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/snaps/edubuntu-desktop-installer HTTP/1.1" 200 1620
2024-01-19 00:37:49,770 DEBUG subiquity.server.controllers.snaplist:79 loading list of snaps
2024-01-19 00:37:49,772 DEBUG root:30 start: subiquity/Filesystem/_probe: 
2024-01-19 00:37:49,772 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2024-01-19 00:37:49,773 DEBUG root:30 start: subiquity/Refresh/check_for_update: 
2024-01-19 00:37:49,773 DEBUG root:30 start: subiquity/SnapList/loader: 
2024-01-19 00:37:49,774 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2024-01-19 00:37:49,775 DEBUG asyncio:54 Using selector: EpollSelector
2024-01-19 00:37:49,776 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:49,776 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2024-01-19 00:37:49,777 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled
2024-01-19 00:37:49,778 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.96739f1'
2024-01-19 00:37:49,798 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info
2024-01-19 00:37:49,799 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS: 
2024-01-19 00:37:49,799 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled
2024-01-19 00:37:49,800 DEBUG root:30 start: subiquity/SnapList/loader/list: 
2024-01-19 00:37:49,801 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N']
2024-01-19 00:37:49,806 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a']
2024-01-19 00:37:49,814 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:49,815 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2024-01-19 00:37:49,815 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:49,816 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2024-01-19 00:37:49,816 INFO root:30 start: subiquity/Meta/client_variant_POST: 
2024-01-19 00:37:49,817 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null
2024-01-19 00:37:49,819 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:49,821 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 
2024-01-19 00:37:49,822 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null
2024-01-19 00:37:49,822 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:37:49,823 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr...
2024-01-19 00:37:49,824 DEBUG subiquitycore.utils:132 arun_command ['/usr/sbin/realm', 'discover'] exited with code 1
2024-01-19 00:37:49,825 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2024-01-19 00:37:49,826 DEBUG subiquity.models.subiquity:256 model ubuntu_pro for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'ssh', 'timezone', 'snaplist'}
2024-01-19 00:37:49,827 DEBUG subiquity.models.subiquity:256 model proxy for install stage is configured, to go {'network', 'filesystem', 'source', 'keyboard', 'mirror'}
2024-01-19 00:37:49,827 DEBUG subiquity.models.subiquity:256 model mirror for install stage is configured, to go {'source', 'network', 'keyboard', 'filesystem'}
2024-01-19 00:37:49,827 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'timezone', 'snaplist'}
2024-01-19 00:37:49,827 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'timezone'}
2024-01-19 00:37:49,828 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2024-01-19 00:37:49,860 DEBUG root:30 start: subiquity/Locale/GET: 
2024-01-19 00:37:49,861 DEBUG root:30 finish: subiquity/Locale/GET: SUCCESS: 200 "C.UTF-8"
2024-01-19 00:37:49,957 DEBUG probert.dasd:134 Probing DASD devies
2024-01-19 00:37:49,957 DEBUG probert.dasd:137 DASD devices only present on s390x, arch=x86_64
2024-01-19 00:37:50,044 DEBUG root:30 start: subiquity/Refresh/GET: 
2024-01-19 00:37:50,186 ERROR probert.raid:40 Failed mdadm_assemble, mdadm command not found: [Errno 2] No such file or directory: 'mdadm'
2024-01-19 00:37:50,752 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?section=server HTTP/1.1" 200 None
2024-01-19 00:37:50,754 DEBUG root:30 finish: subiquity/SnapList/loader/list: SUCCESS: 
2024-01-19 00:37:50,755 DEBUG subiquity.server.controllers.snaplist:92 fetched list of 22 snaps
2024-01-19 00:37:50,755 DEBUG root:30 start: subiquity/SnapList/loader/fetch/microk8s: 
2024-01-19 00:37:51,288 ERROR root:30 finish: subiquity/Filesystem/_probe/probe_once: FAIL: [Errno 2] No such file or directory: 'pvscan'
2024-01-19 00:37:51,299 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 200 59
2024-01-19 00:37:51,289 ERROR block-discover:1288 block probing failed restricted=False
Traceback (most recent call last):
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquity/server/controllers/filesystem.py", line 1282, in _probe
    await asyncio.wait_for(self._probe_once_task.task, 90.0)
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
    return fut.result()
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquitycore/context.py", line 149, in decorated_async
    return await meth(self, **kw)
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquity/server/controllers/filesystem.py", line 1250, in _probe_once
    storage = await self.app.prober.get_storage(probe_types)
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquitycore/prober.py", line 66, in get_storage
    return await run_in_thread(run_probert, probe_types)
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquitycore/async_helpers.py", line 59, in run_in_thread
    return await loop.run_in_executor(None, func, *args)
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/snap/edubuntu-desktop-installer/13/bin/subiquity/subiquitycore/prober.py", line 62, in run_probert
    return asyncio.run(
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages/probert/storage.py", line 246, in probe
    await asyncio.gather(*coroutines)
  File "/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages/probert/storage.py", line 237, in run_probe
    result = await probe.pfunc(context=self.context,
  File "/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages/probert/lvm.py", line 200, in probe
    lvm_scan()
  File "/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages/probert/lvm.py", line 98, in lvm_scan
    subprocess.run(cmd, stdout=subprocess.DEVNULL,
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/subprocess.py", line 503, in run
    with Popen(*popenargs, **kwargs) as process:
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/subprocess.py", line 971, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/snap/edubuntu-desktop-installer/13/usr/lib/python3.10/subprocess.py", line 1863, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: 'pvscan'
2024-01-19 00:37:51,357 DEBUG subiquity.common.errorreport:394 generating crash report
2024-01-19 00:37:51,358 INFO subiquity.common.errorreport:415 saving crash report 'block probing crashed with FileNotFoundError' to /var/crash/1705624671.357173681.block_probe_fail.crash
2024-01-19 00:37:51,358 DEBUG subiquity.server.controllers.filesystem:1297 block probing took 1.6 seconds
2024-01-19 00:37:51,358 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor
2024-01-19 00:37:51,359 INFO root:30 start: subiquity/ErrorReporter/1705624671.357173681.block_probe_fail/add_info: 
2024-01-19 00:37:51,360 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=True
2024-01-19 00:37:51,360 DEBUG asyncio:54 Using selector: EpollSelector
2024-01-19 00:37:51,361 DEBUG subiquity.server.controllers.refresh:201 check_for_update received []
2024-01-19 00:37:51,361 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: no new version of snap available
2024-01-19 00:37:51,362 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNAVAILABLE", "current_snap_version": "0+git.96739f1", "new...
2024-01-19 00:37:51,610 DEBUG curtin:1325 Extracting storage config from probe data
2024-01-19 00:37:51,610 WARNING curtin:426 probe_data missing bcache data
2024-01-19 00:37:51,611 DEBUG curtin:73 /dev/vda is multipath device member? False
2024-01-19 00:37:51,611 DEBUG curtin:86 /dev/vda is multipath device partition? False
2024-01-19 00:37:51,611 DEBUG curtin:61 /dev/vda is multipath device? False
2024-01-19 00:37:51,611 DEBUG curtin:86 /dev/vda is multipath device partition? False
2024-01-19 00:37:51,611 DEBUG curtin:61 /dev/vda is multipath device? False
2024-01-19 00:37:51,655 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2024-01-19 00:37:51,655 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2024-01-19 00:37:51,656 WARNING curtin:426 probe_data missing dasd data
2024-01-19 00:37:51,656 WARNING curtin:426 probe_data missing dmcrypt data
2024-01-19 00:37:51,679 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2024-01-19 00:37:51,679 WARNING curtin:426 probe_data missing lvm data
2024-01-19 00:37:51,679 WARNING curtin:426 probe_data missing raid data
2024-01-19 00:37:51,679 WARNING curtin:426 probe_data missing mount data
2024-01-19 00:37:51,679 WARNING curtin:426 probe_data missing zfs data
2024-01-19 00:37:51,679 DEBUG curtin:1332 Sorting extracted configurations
2024-01-19 00:37:51,680 INFO curtin:1351 Validating extracted storage config components
2024-01-19 00:37:51,700 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-vda
    path: /dev/vda
    type: disk

2024-01-19 00:37:51,700 DEBUG curtin:1372 Generating storage config dependencies
2024-01-19 00:37:51,700 DEBUG curtin:1378 Merging storage config dependencies
2024-01-19 00:37:51,701 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-vda
        path: /dev/vda
        type: disk
    version: 2

2024-01-19 00:37:51,701 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')}
2024-01-19 00:37:51,701 DEBUG root:30 finish: subiquity/Filesystem/_probe/probe_once: SUCCESS: restricted=True
2024-01-19 00:37:51,702 DEBUG subiquity.server.controllers.filesystem:1297 disk probing took 0.3 seconds
2024-01-19 00:37:51,702 DEBUG subiquity.server.controllers.filesystem:1474 start_monitor
2024-01-19 00:37:51,702 DEBUG root:30 finish: subiquity/Filesystem/_probe: SUCCESS: 
2024-01-19 00:37:51,723 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=microk8s HTTP/1.1" 200 None
2024-01-19 00:37:51,745 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/microk8s: SUCCESS: 
2024-01-19 00:37:51,745 DEBUG root:30 start: subiquity/SnapList/loader/fetch/nextcloud: 
2024-01-19 00:37:52,336 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=nextcloud HTTP/1.1" 200 None
2024-01-19 00:37:52,337 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/nextcloud: SUCCESS: 
2024-01-19 00:37:52,338 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wekan: 
2024-01-19 00:37:52,345 INFO root:30 finish: subiquity/ErrorReporter/1705624671.357173681.block_probe_fail/add_info: SUCCESS: written to /var/crash/1705624671.357173681.block_probe_fail.crash
2024-01-19 00:37:52,647 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=wekan HTTP/1.1" 200 None
2024-01-19 00:37:52,648 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wekan: SUCCESS: 
2024-01-19 00:37:52,648 DEBUG root:30 start: subiquity/SnapList/loader/fetch/kata-containers: 
2024-01-19 00:37:52,913 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=kata-containers HTTP/1.1" 200 None
2024-01-19 00:37:52,913 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/kata-containers: SUCCESS: 
2024-01-19 00:37:52,914 DEBUG root:30 start: subiquity/SnapList/loader/fetch/docker: 
2024-01-19 00:37:53,201 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=docker HTTP/1.1" 200 None
2024-01-19 00:37:53,203 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/docker: SUCCESS: 
2024-01-19 00:37:53,203 DEBUG root:30 start: subiquity/SnapList/loader/fetch/canonical-livepatch: 
2024-01-19 00:37:53,465 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=canonical-livepatch HTTP/1.1" 200 None
2024-01-19 00:37:53,466 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/canonical-livepatch: SUCCESS: 
2024-01-19 00:37:53,466 DEBUG root:30 start: subiquity/SnapList/loader/fetch/rocketchat-server: 
2024-01-19 00:37:53,975 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=rocketchat-server HTTP/1.1" 200 None
2024-01-19 00:37:53,975 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/rocketchat-server: SUCCESS: 
2024-01-19 00:37:53,976 DEBUG root:30 start: subiquity/SnapList/loader/fetch/mosquitto: 
2024-01-19 00:37:54,246 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=mosquitto HTTP/1.1" 200 None
2024-01-19 00:37:54,247 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/mosquitto: SUCCESS: 
2024-01-19 00:37:54,247 DEBUG root:30 start: subiquity/SnapList/loader/fetch/etcd: 
2024-01-19 00:37:54,896 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=etcd HTTP/1.1" 200 None
2024-01-19 00:37:54,898 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/etcd: SUCCESS: 
2024-01-19 00:37:54,898 DEBUG root:30 start: subiquity/SnapList/loader/fetch/powershell: 
2024-01-19 00:37:55,121 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=powershell HTTP/1.1" 200 None
2024-01-19 00:37:55,122 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/powershell: SUCCESS: 
2024-01-19 00:37:55,122 DEBUG root:30 start: subiquity/SnapList/loader/fetch/sabnzbd: 
2024-01-19 00:37:55,360 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=sabnzbd HTTP/1.1" 200 None
2024-01-19 00:37:55,360 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/sabnzbd: SUCCESS: 
2024-01-19 00:37:55,361 DEBUG root:30 start: subiquity/SnapList/loader/fetch/wormhole: 
2024-01-19 00:37:55,579 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=wormhole HTTP/1.1" 200 None
2024-01-19 00:37:55,580 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/wormhole: SUCCESS: 
2024-01-19 00:37:55,580 DEBUG root:30 start: subiquity/SnapList/loader/fetch/aws-cli: 
2024-01-19 00:37:55,817 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=aws-cli HTTP/1.1" 200 None
2024-01-19 00:37:55,818 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/aws-cli: SUCCESS: 
2024-01-19 00:37:55,818 DEBUG root:30 start: subiquity/SnapList/loader/fetch/google-cloud-sdk: 
2024-01-19 00:37:56,126 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=google-cloud-sdk HTTP/1.1" 200 1799
2024-01-19 00:37:56,127 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/google-cloud-sdk: SUCCESS: 
2024-01-19 00:37:56,128 DEBUG root:30 start: subiquity/SnapList/loader/fetch/slcli: 
2024-01-19 00:37:56,360 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=slcli HTTP/1.1" 200 None
2024-01-19 00:37:56,360 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/slcli: SUCCESS: 
2024-01-19 00:37:56,361 DEBUG root:30 start: subiquity/SnapList/loader/fetch/doctl: 
2024-01-19 00:37:56,639 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=doctl HTTP/1.1" 200 None
2024-01-19 00:37:56,640 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/doctl: SUCCESS: 
2024-01-19 00:37:56,641 DEBUG root:30 start: subiquity/SnapList/loader/fetch/conjure-up: 
2024-01-19 00:37:56,864 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=conjure-up HTTP/1.1" 200 None
2024-01-19 00:37:56,865 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/conjure-up: SUCCESS: 
2024-01-19 00:37:56,865 DEBUG root:30 start: subiquity/SnapList/loader/fetch/postgresql10: 
2024-01-19 00:37:57,149 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=postgresql10 HTTP/1.1" 200 1523
2024-01-19 00:37:57,149 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/postgresql10: SUCCESS: 
2024-01-19 00:37:57,150 DEBUG root:30 start: subiquity/SnapList/loader/fetch/heroku: 
2024-01-19 00:37:57,396 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=heroku HTTP/1.1" 200 None
2024-01-19 00:37:57,397 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/heroku: SUCCESS: 
2024-01-19 00:37:57,397 DEBUG root:30 start: subiquity/SnapList/loader/fetch/keepalived: 
2024-01-19 00:37:57,661 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=keepalived HTTP/1.1" 200 None
2024-01-19 00:37:57,662 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/keepalived: SUCCESS: 
2024-01-19 00:37:57,662 DEBUG root:30 start: subiquity/SnapList/loader/fetch/prometheus: 
2024-01-19 00:37:57,968 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=prometheus HTTP/1.1" 200 None
2024-01-19 00:37:57,969 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/prometheus: SUCCESS: 
2024-01-19 00:37:57,969 DEBUG root:30 start: subiquity/SnapList/loader/fetch/juju: 
2024-01-19 00:37:58,337 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?name=juju HTTP/1.1" 200 None
2024-01-19 00:37:58,338 DEBUG root:30 finish: subiquity/SnapList/loader/fetch/juju: SUCCESS: 
2024-01-19 00:37:58,338 DEBUG root:30 finish: subiquity/SnapList/loader: SUCCESS: 
2024-01-19 00:37:59,623 DEBUG root:30 start: subiquity/Locale/POST: 
2024-01-19 00:37:59,624 DEBUG subiquity.server.controllers.locale:68 en_US.UTF-8
2024-01-19 00:37:59,624 DEBUG subiquity.models.subiquity:256 model locale for postinstall stage is configured, to go {'drivers', 'codecs', 'identity', 'network', 'timezone'}
2024-01-19 00:37:59,624 DEBUG root:30 finish: subiquity/Locale/POST: SUCCESS: 200 null
2024-01-19 00:37:59,624 DEBUG subiquitycore.utils:118 arun_command called: ['localectl', 'set-locale', 'en_US.UTF-8']
2024-01-19 00:37:59,634 DEBUG root:30 start: subiquity/Keyboard/GET: 
2024-01-19 00:37:59,646 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2024-01-19 00:37:59,650 DEBUG root:30 start: subiquity/Keyboard/GET: 
2024-01-19 00:37:59,659 DEBUG root:30 finish: subiquity/Keyboard/GET: SUCCESS: 200 {"setting": {"layout": "us", "variant": "", "toggle": null}, "layouts": [{"co...
2024-01-19 00:37:59,662 DEBUG root:30 start: subiquity/Keyboard/input_source_POST: 
2024-01-19 00:37:59,662 DEBUG subiquitycore.utils:118 arun_command called: ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','us')]"]
2024-01-19 00:37:59,706 DEBUG subiquitycore.utils:132 arun_command ['systemd-run', '--wait', '--uid=1000', '--setenv=DISPLAY=:0', '--setenv=XDG_RUNTIME_DIR=/run/user/1000', '--setenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus', '--', 'gsettings', 'set', 'org.gnome.desktop.input-sources', 'sources', "[('xkb','us')]"] exited with code 0
2024-01-19 00:37:59,707 DEBUG root:30 finish: subiquity/Keyboard/input_source_POST: SUCCESS: 200 null
2024-01-19 00:38:01,748 DEBUG root:30 start: subiquity/Keyboard/POST: 
2024-01-19 00:38:01,748 DEBUG subiquity.server.controllers.keyboard:221 KeyboardSetting(layout='us', variant='', toggle=None)
2024-01-19 00:38:01,748 DEBUG subiquity.models.subiquity:256 model keyboard for install stage is configured, to go {'source', 'network', 'filesystem'}
2024-01-19 00:38:01,749 DEBUG root:30 finish: subiquity/Keyboard/POST: SUCCESS: 200 null
2024-01-19 00:38:03,788 DEBUG root:30 start: subiquity/Source/GET: 
2024-01-19 00:38:03,789 DEBUG root:30 finish: subiquity/Source/GET: SUCCESS: 200 {"sources": [{"name": "Edubuntu Desktop (minimized)", "description": "A minim...
2024-01-19 00:38:03,789 DEBUG root:30 start: subiquity/Drivers/GET: 
2024-01-19 00:38:03,790 DEBUG root:30 finish: subiquity/Drivers/GET: SUCCESS: 200 {"install": false, "drivers": null, "local_only": true, "search_drivers": false}
2024-01-19 00:38:03,791 DEBUG root:30 start: subiquity/Codecs/GET: 
2024-01-19 00:38:03,791 DEBUG root:30 finish: subiquity/Codecs/GET: SUCCESS: 200 {"install": false}
2024-01-19 00:38:09,595 DEBUG root:30 start: subiquity/Source/POST: 
2024-01-19 00:38:09,596 DEBUG subiquity.models.subiquity:256 model source for install stage is configured, to go {'network', 'filesystem'}
2024-01-19 00:38:09,596 DEBUG subiquity.server.controllers.drivers:89 source variant has been set. Querying list of drivers.
2024-01-19 00:38:09,597 DEBUG root:30 finish: subiquity/Source/POST: SUCCESS: 200 null
2024-01-19 00:38:09,597 DEBUG subiquity.server.controllers.filesystem:414 got system None for variation default
2024-01-19 00:38:09,598 DEBUG root:30 start: subiquity/Drivers/_list_drivers: 
2024-01-19 00:38:09,598 DEBUG root:30 start: subiquity/Drivers/_list_drivers/wait_apt: 
2024-01-19 00:38:09,599 DEBUG root:30 start: subiquity/Drivers/POST: 
2024-01-19 00:38:09,600 DEBUG subiquity.models.subiquity:256 model drivers for postinstall stage is configured, to go {'codecs', 'identity', 'network', 'timezone'}
2024-01-19 00:38:09,600 DEBUG root:30 finish: subiquity/Drivers/POST: SUCCESS: 200 null
2024-01-19 00:38:09,601 DEBUG root:30 start: subiquity/Codecs/POST: 
2024-01-19 00:38:09,602 DEBUG subiquity.models.subiquity:256 model codecs for postinstall stage is configured, to go {'identity', 'network', 'timezone'}
2024-01-19 00:38:09,603 DEBUG root:30 finish: subiquity/Codecs/POST: SUCCESS: 200 null
2024-01-19 00:38:09,604 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2024-01-19 00:38:09,605 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:09,607 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:09,610 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2024-01-19 00:38:09,611 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:09,612 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:09,615 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2024-01-19 00:38:09,615 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:09,617 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2024-01-19 00:38:09,619 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2024-01-19 00:38:09,619 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2024-01-19 00:38:10,992 DEBUG root:30 start: subiquity/Filesystem/has_bitlocker_GET: 
2024-01-19 00:38:10,992 DEBUG root:30 finish: subiquity/Filesystem/has_bitlocker_GET: SUCCESS: 200 []
2024-01-19 00:38:10,993 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2024-01-19 00:38:10,994 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:10,995 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:10,998 DEBUG root:30 start: subiquity/Filesystem/v2_guided_GET: 
2024-01-19 00:38:10,998 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:10,999 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": null, "targets": [{"di...
2024-01-19 00:38:11,001 DEBUG root:30 start: subiquity/Filesystem/v2_guided_POST: 
2024-01-19 00:38:11,001 DEBUG subiquity.server.controllers.filesystem:1152 GuidedChoiceV2(target=GuidedStorageTargetReformat(disk_id='disk-vda', allowed=[<GuidedCapability.DIRECT: 2>, <GuidedCapability.LVM: 3>, <GuidedCapability.LVM_LUKS: 4>, <GuidedCapability.ZFS: 5>], disallowed=[]), capability=<GuidedCapability.DIRECT: 2>, recovery_key=None, sizing_policy=<SizingPolicy.ALL: 2>, reset_partition=False)
2024-01-19 00:38:11,002 DEBUG subiquity.models.filesystem:2105 adding ext4 to Partition(device=disk-vda, size=24692916224, wipe='superblock', number=2, grub_device=None, offset=2097152, id='partition-1')
2024-01-19 00:38:11,002 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:11,003 DEBUG root:30 finish: subiquity/Filesystem/v2_guided_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "configured": {"target": {"disk_id":...
2024-01-19 00:38:11,004 DEBUG root:30 start: subiquity/Filesystem/v2_POST: 
2024-01-19 00:38:11,004 DEBUG subiquity.models.subiquity:256 model filesystem for install stage is configured, to go {'network'}
2024-01-19 00:38:11,005 DEBUG subiquity.server.controllers.filesystem:1487 stop_monitor
2024-01-19 00:38:11,005 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:11,006 DEBUG root:30 finish: subiquity/Filesystem/v2_POST: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:11,008 DEBUG root:30 start: subiquity/Filesystem/v2_GET: 
2024-01-19 00:38:11,009 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:11,010 DEBUG root:30 finish: subiquity/Filesystem/v2_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:11,011 DEBUG root:30 start: subiquity/Filesystem/v2_orig_config_GET: 
2024-01-19 00:38:11,011 DEBUG curtin:1325 Extracting storage config from probe data
2024-01-19 00:38:11,011 WARNING curtin:426 probe_data missing bcache data
2024-01-19 00:38:11,011 DEBUG curtin:73 /dev/vda is multipath device member? False
2024-01-19 00:38:11,011 DEBUG curtin:86 /dev/vda is multipath device partition? False
2024-01-19 00:38:11,011 DEBUG curtin:61 /dev/vda is multipath device? False
2024-01-19 00:38:11,011 DEBUG curtin:86 /dev/vda is multipath device partition? False
2024-01-19 00:38:11,011 DEBUG curtin:61 /dev/vda is multipath device? False
2024-01-19 00:38:11,026 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2024-01-19 00:38:11,026 DEBUG curtin:86 /dev/sr0 is multipath device partition? False
2024-01-19 00:38:11,026 WARNING curtin:426 probe_data missing dasd data
2024-01-19 00:38:11,026 WARNING curtin:426 probe_data missing dmcrypt data
2024-01-19 00:38:11,026 DEBUG curtin:73 /dev/sr0 is multipath device member? False
2024-01-19 00:38:11,027 WARNING curtin:426 probe_data missing lvm data
2024-01-19 00:38:11,027 WARNING curtin:426 probe_data missing raid data
2024-01-19 00:38:11,027 WARNING curtin:426 probe_data missing mount data
2024-01-19 00:38:11,027 WARNING curtin:426 probe_data missing zfs data
2024-01-19 00:38:11,027 DEBUG curtin:1332 Sorting extracted configurations
2024-01-19 00:38:11,027 INFO curtin:1351 Validating extracted storage config components
2024-01-19 00:38:11,041 DEBUG curtin:1368 Extracted (unmerged) storage config:
storage:
-   id: disk-vda
    path: /dev/vda
    type: disk

2024-01-19 00:38:11,041 DEBUG curtin:1372 Generating storage config dependencies
2024-01-19 00:38:11,041 DEBUG curtin:1378 Merging storage config dependencies
2024-01-19 00:38:11,041 DEBUG curtin:1383 Merged storage config:
storage:
    config:
    -   id: disk-vda
        path: /dev/vda
        type: disk
    version: 2

2024-01-19 00:38:11,041 DEBUG subiquity.models.filesystem:1463 majmin_to_dev {'253:0': Disk(path='/dev/vda', preserve=True, id='disk-vda', type='disk')}
2024-01-19 00:38:11,042 DEBUG subiquity.server.controllers.filesystem:996 suggested install minimum size: 16.307G
2024-01-19 00:38:11,042 DEBUG root:30 finish: subiquity/Filesystem/v2_orig_config_GET: SUCCESS: 200 {"status": "DONE", "error_report": null, "disks": [{"id": "disk-vda", "label"...
2024-01-19 00:38:12,259 DEBUG root:30 start: subiquity/TimeZone/GET: 
2024-01-19 00:38:12,259 DEBUG root:30 finish: subiquity/TimeZone/GET: SUCCESS: 200 {"timezone": "America/New_York", "from_geoip": true}
2024-01-19 00:38:12,459 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2024-01-19 00:38:12,460 DEBUG subiquitycore.models.network:467 has_network True
2024-01-19 00:38:12,460 DEBUG subiquity.models.subiquity:256 model network for install stage is configured, to go set()
2024-01-19 00:38:12,460 DEBUG subiquity.models.subiquity:256 model network for postinstall stage is configured, to go {'identity', 'timezone'}
2024-01-19 00:38:12,460 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2024-01-19 00:38:12,461 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "NEEDS_CONFIRMATION", "confirming_tty": "", "error": null, "cloud_i...
2024-01-19 00:38:12,461 INFO root:30 start: subiquity/Meta/confirm_POST: 
2024-01-19 00:38:12,461 DEBUG subiquity.models.subiquity:256 model ssh for postinstall stage is configured, to go {'identity', 'timezone'}
2024-01-19 00:38:12,462 DEBUG subiquity.models.subiquity:256 model snaplist for postinstall stage is configured, to go {'identity', 'timezone'}
2024-01-19 00:38:12,462 INFO root:30 finish: subiquity/Meta/confirm_POST: SUCCESS: 200 null
2024-01-19 00:38:12,462 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_confirmation: SUCCESS: 
2024-01-19 00:38:12,462 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_apt: 
2024-01-19 00:38:12,462 INFO root:30 start: subiquity/Install/install/configure_apt: configuring apt
2024-01-19 00:38:12,463 DEBUG root:30 start: subiquity/Mirror/waiting: 
2024-01-19 00:38:12,463 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:38:12,463 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2024-01-19 00:38:12,463 DEBUG root:30 finish: subiquity/Mirror/waiting: SUCCESS: 
2024-01-19 00:38:12,463 DEBUG subiquity.server.controllers.mirror:202 Iterating over country-mirror
2024-01-19 00:38:12,464 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.standard.squashfs']
2024-01-19 00:38:12,464 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp6ar3jyb5/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:12,474 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.standard.squashfs', '/tmp/tmp6ar3jyb5/minimal.standard.squashfs.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:12,588 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp6ar3jyb5/minimal.standard.squashfs.dir:/tmp/tmp6ar3jyb5/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp6ar3jyb5/root.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:12,595 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'mount', '-o', 'lowerdir=/tmp/tmp6ar3jyb5/root.dir,upperdir=/tmp/tmp42moxa2p/upper,workdir=/tmp/tmp42moxa2p/work', '-t', 'overlay', 'overlay', '/tmp/tmp42moxa2p/mount']
2024-01-19 00:38:12,597 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:38:12,650 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.1"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmp42moxa2p/mount']
2024-01-19 00:38:14,521 DEBUG root:30 start: subiquity/TimeZone/POST: 
2024-01-19 00:38:14,660 DEBUG subiquity.models.subiquity:256 model timezone for postinstall stage is configured, to go {'identity'}
2024-01-19 00:38:14,660 DEBUG root:30 finish: subiquity/TimeZone/POST: SUCCESS: 200 null
2024-01-19 00:38:14,661 DEBUG root:30 start: subiquity/Identity/GET: 
2024-01-19 00:38:14,661 DEBUG root:30 finish: subiquity/Identity/GET: SUCCESS: 200 {"realname": "", "username": "", "crypted_password": "", "hostname": ""}
2024-01-19 00:38:14,663 DEBUG root:30 start: subiquity/Ad/has_support_GET: 
2024-01-19 00:38:14,663 DEBUG root:30 finish: subiquity/Ad/has_support_GET: SUCCESS: 200 true
2024-01-19 00:38:16,766 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']
2024-01-19 00:38:17,330 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:17,331 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:17,781 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:17,782 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:17,961 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:17,962 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,033 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,034 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,161 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,162 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,410 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,411 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,501 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,502 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,662 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,662 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,774 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,774 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,819 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,820 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,950 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,950 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:18,984 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:18,984 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,325 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,326 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,437 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,438 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,549 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,549 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,621 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,622 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,733 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,734 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:20,953 DEBUG root:30 start: subiquity/Identity/validate_username_GET: 
2024-01-19 00:38:20,954 DEBUG root:30 finish: subiquity/Identity/validate_username_GET: SUCCESS: 200 "OK"
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:176 Mirror checking successful
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:178 APT output follows
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:180 Get:1 http://us.archive.ubuntu.com/ubuntu noble InRelease [256 kB]
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:180 Hit:2 http://us.archive.ubuntu.com/ubuntu noble-updates InRelease
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:180 Get:3 http://us.archive.ubuntu.com/ubuntu noble-backports InRelease [90.8 kB]
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:180 Fetched 347 kB in 1s (301 kB/s)
2024-01-19 00:38:21,196 DEBUG subiquity.server.controllers.mirror:180 Reading package lists...
2024-01-19 00:38:21,196 DEBUG curtin:117 Setting up Layered Source for stack ['///cdrom/casper/minimal.squashfs', '///cdrom/casper/minimal.standard.squashfs']
2024-01-19 00:38:21,196 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.squashfs', '/tmp/tmp7jbmgdho/minimal.squashfs.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:21,200 DEBUG curtin:95 Running command ['mount', '-o', 'loop,ro', '///cdrom/casper/minimal.standard.squashfs', '/tmp/tmp7jbmgdho/minimal.standard.squashfs.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:21,204 DEBUG curtin:95 Running command ['mount', '-o', 'lowerdir=/tmp/tmp7jbmgdho/minimal.standard.squashfs.dir:/tmp/tmp7jbmgdho/minimal.squashfs.dir', '-t', 'overlay', 'overlay', '/tmp/tmp7jbmgdho/root.dir'] with allowed return codes [0] (capture=True)
2024-01-19 00:38:21,207 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'mount', '-o', 'lowerdir=/tmp/tmp7jbmgdho/root.dir,upperdir=/tmp/tmpr8p87ju0/upper,workdir=/tmp/tmpr8p87ju0/work', '-t', 'overlay', 'overlay', '/tmp/tmpr8p87ju0/mount']
2024-01-19 00:38:21,270 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.2"}}', '-c', '/var/log/installer/subiquity-curtin-apt.conf', 'apt-config', '-t', '/tmp/tmpr8p87ju0/mount']
2024-01-19 00:38:23,873 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'mount', '-o', 'lowerdir=/tmp/tmpr8p87ju0/upper:/tmp/tmp7jbmgdho/root.dir,upperdir=/tmp/tmprj3db91o/upper,workdir=/tmp/tmprj3db91o/work', '-t', 'overlay', 'overlay', '/tmp/tmprj3db91o/mount']
2024-01-19 00:38:23,940 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'mount', '-o', 'bind', '/cdrom', '/tmp/tmprj3db91o/mount/cdrom']
2024-01-19 00:38:23,969 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.3"}}', 'in-target', '-t', '/tmp/tmprj3db91o/mount', '--', 'apt-get', 'update']
2024-01-19 00:38:28,857 INFO root:30 start: subiquity/Meta/mark_configured_POST: 
2024-01-19 00:38:28,858 DEBUG subiquity.models.subiquity:256 model active_directory for postinstall stage is configured, to go {'identity'}
2024-01-19 00:38:28,858 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null
2024-01-19 00:38:28,895 DEBUG root:30 start: subiquity/Identity/POST: 
2024-01-19 00:38:28,895 DEBUG subiquity.models.subiquity:256 model identity for postinstall stage is configured, to go set()
2024-01-19 00:38:28,896 DEBUG root:30 finish: subiquity/Identity/POST: SUCCESS: 200 null
2024-01-19 00:38:28,897 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:38:28,897 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2024-01-19 00:38:29,275 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:38:29,275 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini...
2024-01-19 00:38:29,284 INFO root:30 start: subiquity/Meta/status_GET: 
2024-01-19 00:38:35,765 INFO root:30 finish: subiquity/Install/install/configure_apt: SUCCESS: configuring apt
2024-01-19 00:38:35,765 INFO root:30 start: subiquity/Install/install/curtin_install: installing system
2024-01-19 00:38:35,766 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step: executing curtin install initial step
2024-01-19 00:38:35,768 DEBUG root:30 finish: subiquity/Drivers/_list_drivers/wait_apt: SUCCESS: 
2024-01-19 00:38:35,768 DEBUG root:30 finish: subiquity/Drivers/_list_drivers: SUCCESS: 
2024-01-19 00:38:35,768 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list/wait_apt: SUCCESS: 
2024-01-19 00:38:35,768 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'mount', '-o', 'lowerdir=/tmp/tmprj3db91o/upper:/tmp/tmpr8p87ju0/upper:/tmp/tmp7jbmgdho/root.dir,upperdir=/tmp/tmpkk0unpcz/upper,workdir=/tmp/tmpkk0unpcz/work', '-t', 'overlay', 'overlay', '/tmp/tmpkk0unpcz/mount']
2024-01-19 00:38:35,770 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.4"}}', '-c', '/var/log/installer/curtin-install/subiquity-initial.conf', 'install', '--set', 'json:stages=[]']
2024-01-19 00:38:35,826 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'chroot', '/tmp/tmpkk0unpcz/mount', 'sh', '-c', 'command -v ubuntu-drivers']
2024-01-19 00:38:35,852 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--property', 'PrivateMounts=yes', '--pipe', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.5"}}', 'in-target', '-t', '/tmp/tmpkk0unpcz/mount', '--', 'ubuntu-drivers', 'list-oem']
2024-01-19 00:38:37,269 DEBUG root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step: SUCCESS: executing curtin install initial step
2024-01-19 00:38:37,269 DEBUG subiquity.models.filesystem:1838 mountpoints {'/': 'mount-0'}
2024-01-19 00:38:37,270 DEBUG root:30 start: subiquity/Install/install/curtin_install/run_curtin_step: executing curtin install partitioning step
2024-01-19 00:38:37,275 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.6"}}', '-c', '/var/log/installer/curtin-install/subiquity-partitioning.conf', 'install', '--set', 'json:stages=["partitioning"]', 'cp:///tmp/tmprj3db91o/mount']
2024-01-19 00:38:39,525 DEBUG subiquitycore.utils:151 astart_command called: ['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', 'umount', '/tmp/tmpkk0unpcz/mount']
2024-01-19 00:38:39,600 DEBUG subiquity.server.controllers.oem:192 OEM meta-packages to install: []
2024-01-19 00:38:39,601 DEBUG root:30 finish: subiquity/OEM/load_metapackages_list: SUCCESS: 
2024-01-19 00:38:41,258 ERROR root:30 finish: subiquity/Install/install/curtin_install/run_curtin_step: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.6"}}', '-c', '/var/log/installer/curtin-install/subiquity-partitioning.conf', 'install', '--set', 'json:stages=["partitioning"]', 'cp:///tmp/tmprj3db91o/mount']' returned non-zero exit status 3.
2024-01-19 00:38:41,259 ERROR root:30 finish: subiquity/Install/install/curtin_install: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.6"}}', '-c', '/var/log/installer/curtin-install/subiquity-partitioning.conf', 'install', '--set', 'json:stages=["partitioning"]', 'cp:///tmp/tmprj3db91o/mount']' returned non-zero exit status 3.
2024-01-19 00:38:41,259 DEBUG subiquity.common.errorreport:394 generating crash report
2024-01-19 00:38:41,293 INFO subiquity.common.errorreport:415 saving crash report 'install failed crashed with CalledProcessError' to /var/crash/1705624721.259701014.install_fail.crash
2024-01-19 00:38:41,294 ERROR root:30 finish: subiquity/Install/install: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3202', '--setenv', 'PATH=/snap/edubuntu-desktop-installer/13/bin/subiquity/bin:/snap/edubuntu-desktop-installer/13/bin/subiquity/usr/bin:/snap/edubuntu-desktop-installer/13/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/usr/sbin:/snap/edubuntu-desktop-installer/13/usr/bin:/snap/edubuntu-desktop-installer/13/sbin:/snap/edubuntu-desktop-installer/13/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/edubuntu-desktop-installer/13/lib/python3.10/site-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/dist-packages:/snap/edubuntu-desktop-installer/13/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '--setenv', 'SNAP=/snap/edubuntu-desktop-installer/13', '--', '/snap/edubuntu-desktop-installer/13/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3202.6"}}', '-c', '/var/log/installer/curtin-install/subiquity-partitioning.conf', 'install', '--set', 'json:stages=["partitioning"]', 'cp:///tmp/tmprj3db91o/mount']' returned non-zero exit status 3.
2024-01-19 00:38:41,294 INFO root:30 start: subiquity/ErrorReporter/1705624721.259701014.install_fail/add_info: