2023-02-14 13:38:38,172 INFO subiquity:162 Starting Subiquity server revision 762
2023-02-14 13:38:38,172 INFO subiquity:163 Arguments passed: ['/snap/ubuntu-desktop-installer/762/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/762/etc/subiquity/postinst.d', '--autoinstall=']
2023-02-14 13:38:38,173 DEBUG subiquity:164 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-02-14 13:38:38,173 DEBUG subiquity:165 Storage version: 2
2023-02-14 13:38:38,173 DEBUG asyncio:59 Using selector: EpollSelector
2023-02-14 13:38:38,174 DEBUG subiquitycore.prober:34 Prober() init finished, data:None
2023-02-14 13:38:38,381 DEBUG curtin:87 Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
2023-02-14 13:38:38,543 DEBUG subiquitycore.utils:92 arun_command called: ['cloud-init', 'status', '--wait']
2023-02-14 13:39:28,031 DEBUG subiquitycore.utils:101 arun_command ['cloud-init', 'status', '--wait'] exited with code 0
2023-02-14 13:39:28,031 DEBUG subiquity.server.server:527 waited 49.487844467163086s for cloud-init
2023-02-14 13:39:28,032 DEBUG subiquity.server.server:539 cloud-init status: '\nstatus: disabled\n', assumed disabled
2023-02-14 13:39:28,032 DEBUG subiquity.server.server:474 load_autoinstall_config only_early True file None
2023-02-14 13:39:28,032 DEBUG subiquity.server.server:474 load_autoinstall_config only_early False file None
2023-02-14 13:39:28,034 DEBUG subiquitycore.core:121 starting controllers
2023-02-14 13:39:28,035 DEBUG subiquity.server.controllers.kernel:66 Using kernel linux-generic-hwe-22.04 due to /run/kernel-meta-package
2023-02-14 13:39:28,212 DEBUG subiquity.models.source:76 loaded 2 sources from '/cdrom/casper/install-sources.yaml'
2023-02-14 13:39:31,453 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2023-02-14 13:39:31,453 DEBUG probert.network:585 event for link_change: NEW {'ifindex': 2, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'ens33'}
2023-02-14 13:39:31,454 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-02-14 13:39:31,454 DEBUG probert.network:585 event for addr_change: NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-02-14 13:39:31,454 DEBUG probert.network:672 link_change NEW {'ifindex': 1, 'flags': 65609, 'arptype': 772, 'family': 0, 'is_vlan': False, 'name': b'lo'}
2023-02-14 13:39:31,783 DEBUG subiquitycore.models.network:435 new_link 1 lo lo
2023-02-14 13:39:31,783 DEBUG subiquitycore.models.network:437 ignoring based on type
2023-02-14 13:39:31,784 DEBUG probert.network:672 link_change NEW {'ifindex': 2, 'flags': 4099, 'arptype': 1, 'family': 0, 'is_vlan': False, 'name': b'ens33'}
2023-02-14 13:39:32,173 DEBUG subiquitycore.models.network:435 new_link 2 ens33 eth
2023-02-14 13:39:32,173 DEBUG subiquitycore.models.network:466 new_link 2 ens33 with config {}
2023-02-14 13:39:32,173 DEBUG root:37 start: subiquity/Network/_send_update: NEW ens33
2023-02-14 13:39:32,174 DEBUG subiquity.server.controllers.network:354 dev_info ens33 {}
2023-02-14 13:39:32,174 DEBUG root:37 finish: subiquity/Network/_send_update: SUCCESS: NEW ens33
2023-02-14 13:39:32,174 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 2, 'scope': 254, 'local': b'127.0.0.1/8'}
2023-02-14 13:39:32,174 DEBUG probert.network:717 addr_change NEW {'ifindex': 1, 'flags': 128, 'family': 10, 'scope': 254, 'local': b'::1'}
2023-02-14 13:39:32,175 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.0/8', 'ifindex': 1}
2023-02-14 13:39:32,175 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 2, 'table': 255, 'dst': b'127.0.0.1', 'ifindex': 1}
2023-02-14 13:39:32,175 DEBUG probert.network:731 route_change NEW {'family': 2, 'type': 3, 'table': 255, 'dst': b'127.255.255.255', 'ifindex': 1}
2023-02-14 13:39:32,175 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 1, 'table': 254, 'dst': b'::1', 'ifindex': 1}
2023-02-14 13:39:32,175 DEBUG probert.network:731 route_change NEW {'family': 10, 'type': 2, 'table': 255, 'dst': b'::1', 'ifindex': 1}
2023-02-14 13:39:35,539 DEBUG subiquitycore.core:124 controllers started
2023-02-14 13:39:35,539 INFO root:37 start: subiquity/apply_autoinstall_config: 
2023-02-14 13:39:35,539 DEBUG root:37 start: subiquity/Early/apply_autoinstall_config: 
2023-02-14 13:39:35,619 DEBUG root:37 finish: subiquity/Early/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,620 DEBUG root:37 start: subiquity/Reporting/apply_autoinstall_config: 
2023-02-14 13:39:35,621 DEBUG root:37 finish: subiquity/Reporting/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,621 DEBUG root:37 start: subiquity/Error/apply_autoinstall_config: 
2023-02-14 13:39:35,622 DEBUG root:37 finish: subiquity/Error/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,623 DEBUG root:37 start: subiquity/Userdata/apply_autoinstall_config: 
2023-02-14 13:39:35,623 DEBUG root:37 finish: subiquity/Userdata/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,624 DEBUG subiquity.models.subiquity:247 model userdata for postinstall stage is configured, to go {'ssh', 'locale', 'identity', 'packages', 'network', 'ubuntu_pro', 'snaplist', 'drivers'}
2023-02-14 13:39:35,624 DEBUG root:37 start: subiquity/Package/apply_autoinstall_config: 
2023-02-14 13:39:35,625 DEBUG root:37 finish: subiquity/Package/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,626 DEBUG subiquity.models.subiquity:247 model packages for postinstall stage is configured, to go {'ssh', 'locale', 'identity', 'network', 'ubuntu_pro', 'snaplist', 'drivers'}
2023-02-14 13:39:35,626 DEBUG root:37 start: subiquity/Debconf/apply_autoinstall_config: 
2023-02-14 13:39:35,627 DEBUG root:37 finish: subiquity/Debconf/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,628 DEBUG subiquity.models.subiquity:247 model debconf_selections for install stage is configured, to go {'proxy', 'source', 'filesystem', 'kernel', 'network', 'mirror', 'keyboard'}
2023-02-14 13:39:35,628 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Locale as interactive
2023-02-14 13:39:35,628 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Refresh as interactive
2023-02-14 13:39:35,628 DEBUG root:37 start: subiquity/Kernel/apply_autoinstall_config: 
2023-02-14 13:39:35,629 DEBUG root:37 finish: subiquity/Kernel/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,630 DEBUG subiquity.models.subiquity:247 model kernel for install stage is configured, to go {'proxy', 'source', 'filesystem', 'network', 'mirror', 'keyboard'}
2023-02-14 13:39:35,630 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Integrity as interactive
2023-02-14 13:39:35,630 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Keyboard as interactive
2023-02-14 13:39:35,630 DEBUG root:37 start: subiquity/Zdev/apply_autoinstall_config: 
2023-02-14 13:39:35,631 DEBUG root:37 finish: subiquity/Zdev/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Source as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Network as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping UbuntuPro as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Proxy as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Mirror as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Filesystem as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Identity as interactive
2023-02-14 13:39:35,632 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping SSH as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping SnapList as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Codecs as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Drivers as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping TimeZone as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Install as interactive
2023-02-14 13:39:35,633 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Updates as interactive
2023-02-14 13:39:35,633 DEBUG root:37 start: subiquity/Late/apply_autoinstall_config: 
2023-02-14 13:39:35,634 DEBUG root:37 finish: subiquity/Late/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,635 DEBUG subiquity.server.server:466 apply_autoinstall_config: skipping Shutdown as interactive
2023-02-14 13:39:35,635 INFO root:37 finish: subiquity/apply_autoinstall_config: SUCCESS: 
2023-02-14 13:39:35,635 DEBUG subiquity.models.subiquity:247 model locale for postinstall stage is configured, to go {'ssh', 'identity', 'network', 'ubuntu_pro', 'snaplist', 'drivers'}
2023-02-14 13:39:35,635 DEBUG root:37 start: subiquity/Refresh/configure_snapd: 
2023-02-14 13:39:35,636 DEBUG root:37 start: subiquity/Refresh/configure_snapd/get_details: 
2023-02-14 13:39:35,638 DEBUG root:37 start: subiquity/Refresh/check_for_update: 
2023-02-14 13:39:35,648 DEBUG root:37 start: subiquity/Install/install: 
2023-02-14 13:39:35,650 DEBUG root:37 start: subiquity/Filesystem/_probe: 
2023-02-14 13:39:35,650 DEBUG root:37 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2023-02-14 13:39:36,022 ERROR probert.raid:40 Failed mdadm_assemble, mdadm command not found: [Errno 2] No such file or directory: 'mdadm'
2023-02-14 13:39:39,652 DEBUG urllib3.connectionpool:456 http://localhost:None "GET /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 200 1558
2023-02-14 13:39:39,657 DEBUG root:37 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.6be84149'
2023-02-14 13:39:39,658 DEBUG subiquity.server.controllers.refresh:152 snap tracking , not resetting based on .disk/info
2023-02-14 13:39:39,658 DEBUG root:37 finish: subiquity/Refresh/configure_snapd: SUCCESS: 
2023-02-14 13:39:50,713 ERROR root:37 finish: subiquity/Filesystem/_probe/probe_once: FAIL: cancelled
2023-02-14 13:39:50,755 ERROR block-discover:847 block probing failed restricted=False
Traceback (most recent call last):
  File "/snap/ubuntu-desktop-installer/762/bin/subiquity/subiquity/server/controllers/filesystem.py", line 841, in _probe
    await asyncio.wait_for(self._probe_once_task.task, timeout)
  File "/snap/ubuntu-desktop-installer/762/usr/lib/python3.8/asyncio/tasks.py", line 501, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2023-02-14 13:39:52,926 DEBUG subiquity.common.errorreport:384 generating crash report
2023-02-14 13:39:52,932 INFO subiquity.common.errorreport:406 saving crash report 'block probing crashed with TimeoutError' to /var/crash/1676381992.927021265.block_probe_fail.crash
2023-02-14 13:39:52,932 INFO root:37 start: subiquity/ErrorReporter/1676381992.927021265.block_probe_fail/add_info: 
2023-02-14 13:39:52,933 DEBUG root:37 start: subiquity/Filesystem/_probe/probe_once: restricted=True