2024-01-16 07:37:18,419 INFO subiquity:199 Starting Subiquity server revision 1278 of snap /snap/ubuntu-desktop-installer/1278 2024-01-16 07:37:18,419 INFO subiquity:200 Arguments passed: ['/snap/ubuntu-desktop-installer/1278/bin/subiquity/subiquity/cmd/server.py', '--use-os-prober', '--storage-version=2', '--postinst-hooks-dir=/snap/ubuntu-desktop-installer/1278/etc/subiquity/postinst.d'] 2024-01-16 07:37:45,345 INFO root:30 start: subiquity/apply_autoinstall_config: 2024-01-16 07:37:45,348 INFO root:30 finish: subiquity/apply_autoinstall_config: SUCCESS: 2024-01-16 07:38:02,502 ERROR root:30 finish: subiquity/Refresh/check_for_update: FAIL: cancelled 2024-01-16 07:38:04,357 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:38:04,357 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:38:17,201 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:38:20,723 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:38:20,723 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:38:20,727 INFO root:30 start: subiquity/Meta/client_variant_POST: 2024-01-16 07:38:20,727 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null 2024-01-16 07:38:20,925 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:38:20,925 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:38:20,926 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:38:20,926 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:38:20,926 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:38:20,926 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:38:20,926 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:38:20,927 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 2024-01-16 07:38:20,927 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null 2024-01-16 07:38:20,927 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2024-01-16 07:38:20,928 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2024-01-16 07:38:36,959 ERROR root:30 finish: subiquity/Meta/status_GET: FAIL: cancelled 2024-01-16 07:38:40,254 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:38:40,254 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:38:44,793 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:39:52,263 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:39:52,264 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:39:54,899 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:40:46,840 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:40:46,841 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:40:47,693 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:41:04,470 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:41:04,470 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:41:05,400 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:41:11,658 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:41:11,658 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:41:11,660 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:41:11,660 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:41:11,660 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:41:11,660 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:41:11,661 INFO root:30 start: subiquity/Meta/client_variant_POST: 2024-01-16 07:41:11,661 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null 2024-01-16 07:41:11,661 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:41:11,662 INFO root:30 start: subiquity/Meta/interactive_sections_GET: 2024-01-16 07:41:11,662 INFO root:30 finish: subiquity/Meta/interactive_sections_GET: SUCCESS: 200 null 2024-01-16 07:41:11,662 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:41:11,662 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "cloud_init_ok": tr... 2024-01-16 07:41:11,663 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2024-01-16 07:41:11,664 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2024-01-16 07:41:22,914 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:41:22,914 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:41:24,637 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:42:06,078 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'maps', 'raw', 'format', '%w,%d,%N'] 2024-01-16 07:42:06,079 ERROR probert.multipath:38 Failed to run cmd: ['multipathd', 'show', 'paths', 'raw', 'format', '%d,%z,%m,%N,%n,%R,%r,%a'] 2024-01-16 07:42:13,875 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:42:16,188 ERROR root:30 finish: subiquity/Drivers/_list_drivers/wait_apt: FAIL: cancelled 2024-01-16 07:42:16,189 ERROR root:30 finish: subiquity/Drivers/_list_drivers: FAIL: cancelled 2024-01-16 07:42:39,436 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:43:23,320 INFO curtin:1351 Validating extracted storage config components 2024-01-16 07:43:27,359 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2024-01-16 07:43:27,359 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2024-01-16 07:43:27,360 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "NEEDS_CONFIRMATION", "confirming_tty": "", "error": null, "cloud_i... 2024-01-16 07:43:27,360 INFO root:30 start: subiquity/Meta/confirm_POST: 2024-01-16 07:43:27,361 INFO root:30 finish: subiquity/Meta/confirm_POST: SUCCESS: 200 null 2024-01-16 07:43:27,362 INFO root:30 start: subiquity/Install/install/configure_apt: configuring apt 2024-01-16 07:43:27,362 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:43:27,363 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2024-01-16 07:43:27,382 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:43:46,385 INFO root:30 finish: subiquity/Install/install/configure_apt: SUCCESS: configuring apt 2024-01-16 07:43:46,385 INFO root:30 start: subiquity/Install/install/curtin_install: installing system 2024-01-16 07:44:27,931 INFO root:30 start: subiquity/Meta/mark_configured_POST: 2024-01-16 07:44:27,932 INFO root:30 finish: subiquity/Meta/mark_configured_POST: SUCCESS: 200 null 2024-01-16 07:44:29,538 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:44:29,539 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2024-01-16 07:44:29,568 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:44:29,568 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2024-01-16 07:44:29,790 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:46:56,964 INFO root:30 finish: subiquity/Install/install/curtin_install: SUCCESS: installing system 2024-01-16 07:46:56,965 INFO root:30 start: subiquity/Install/install/postinstall: final system configuration 2024-01-16 07:46:56,974 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2024-01-16 07:46:56,974 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_ini... 2024-01-16 07:46:57,040 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:46:57,041 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:47:30,914 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "UU_RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_... 2024-01-16 07:47:30,914 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "UU_RUNNING", "confirming_tty": "/dev/tty1", "error": null, "cloud_... 2024-01-16 07:47:30,915 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:47:30,916 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:47:38,001 ERROR root:30 finish: subiquity/Install/install/postinstall/restore_apt_config: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3313', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1278/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1278/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1278/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/usr/sbin:/snap/ubuntu-desktop-installer/1278/usr/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/ubuntu-desktop-installer/1278/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1278', '--', '/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3313.17"}}', 'in-target', '-t', '/target', '--', 'apt-get', 'update']' returned non-zero exit status 100. 2024-01-16 07:47:38,002 ERROR root:30 finish: subiquity/Install/install/postinstall: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3313', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1278/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1278/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1278/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/usr/sbin:/snap/ubuntu-desktop-installer/1278/usr/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/ubuntu-desktop-installer/1278/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1278', '--', '/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3313.17"}}', 'in-target', '-t', '/target', '--', 'apt-get', 'update']' returned non-zero exit status 100. 2024-01-16 07:47:38,027 INFO subiquity.common.errorreport:415 saving crash report 'install failed crashed with CalledProcessError' to /var/crash/1705391258.002308369.install_fail.crash 2024-01-16 07:47:38,028 ERROR root:30 finish: subiquity/Install/install: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3313', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1278/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1278/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1278/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/usr/sbin:/snap/ubuntu-desktop-installer/1278/usr/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/ubuntu-desktop-installer/1278/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1278', '--', '/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3313.17"}}', 'in-target', '-t', '/target', '--', 'apt-get', 'update']' returned non-zero exit status 100. 2024-01-16 07:47:38,028 INFO root:30 start: subiquity/ErrorReporter/1705391258.002308369.install_fail/add_info: 2024-01-16 07:47:38,028 ERROR subiquity.server.server:415 top level error Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1278/bin/subiquity/subiquity/server/controllers/shutdown.py", line 73, in _wait_install await self.app.controllers.Install.install_task subprocess.CalledProcessError: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3313', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1278/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1278/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1278/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/usr/sbin:/snap/ubuntu-desktop-installer/1278/usr/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/ubuntu-desktop-installer/1278/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1278', '--', '/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3313.17"}}', 'in-target', '-t', '/target', '--', 'apt-get', 'update']' returned non-zero exit status 100. 2024-01-16 07:47:38,029 ERROR subiquity.server.server:415 top level error Traceback (most recent call last): File "/snap/ubuntu-desktop-installer/1278/bin/subiquity/subiquity/server/controllers/shutdown.py", line 73, in _wait_install await self.app.controllers.Install.install_task subprocess.CalledProcessError: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3313', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/ubuntu-desktop-installer/1278/bin/subiquity/bin:/snap/ubuntu-desktop-installer/1278/bin/subiquity/usr/bin:/snap/ubuntu-desktop-installer/1278/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/usr/sbin:/snap/ubuntu-desktop-installer/1278/usr/bin:/snap/ubuntu-desktop-installer/1278/sbin:/snap/ubuntu-desktop-installer/1278/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', '--setenv', 'PYTHONPATH=/snap/ubuntu-desktop-installer/1278/lib/python3.10/site-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/dist-packages:/snap/ubuntu-desktop-installer/1278/usr/lib/python3/site-packages:', '--setenv', 'PYTHON=/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '--setenv', 'SNAP=/snap/ubuntu-desktop-installer/1278', '--', '/snap/ubuntu-desktop-installer/1278/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3313.17"}}', 'in-target', '-t', '/target', '--', 'apt-get', 'update']' returned non-zero exit status 100. 2024-01-16 07:47:38,029 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "/dev/tty1", "error": {"state": "INCOMPL... 2024-01-16 07:47:38,029 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "/dev/tty1", "error": {"state": "INCOMPL... 2024-01-16 07:47:38,053 INFO root:30 start: subiquity/Meta/status_GET: 2024-01-16 07:47:38,054 INFO root:30 start: subiquity/Meta/status_GET: