24.04 install on s390x crashes due to an aio issue

[Frank Heimes]

Since the original message that jumped to my eyes when the crash happened:
( fdasd error: device verification failed
 Partition '/dev/nvme0n1' (259/1) detected where device is required )
was/is not the root cause and is not fatal (see comment #2), I'll update the bug description to focus on the AIO issue / messages that I noticed:

 --------%<----------------%<----------------%<----------------%<--------
Title: Installer UI crashed with ClientOSError
Traceback:
 Traceback (most recent call last):
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/client/client.py", line 402, in run
     await super().run()
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquitycore/tui.py", line 351, in run
     await super().run()
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquitycore/core.py", line 134, in run
     raise exc
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/client/client.py", line 505, in _select_initial_screen
     await self.client.meta.mark_configured.POST(endpoint_names)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/common/api/client.py", line 47, in impl
     async with make_request(
   File "/snap/subiquity/5575/usr/lib/python3.10/contextlib.py", line 199, in __aenter__
     return await anext(self.gen)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/common/api/client.py", line 118, in make_request
     async with session.request(
   File "/snap/subiquity/5575/usr/lib/python3/dist-packages/aiohttp/client.py", line 1138, in __aenter__
     self._resp = await self._coro
   File "/snap/subiquity/5575/usr/lib/python3/dist-packages/aiohttp/client.py", line 559, in _request
     await resp.start(conn)
   File "/snap/subiquity/5575/usr/lib/python3/dist-packages/aiohttp/client_reqrep.py", line 898, in start
     message, payload = await protocol.read() # type: ignore[union-attr]
   File "/snap/subiquity/5575/usr/lib/python3/dist-packages/aiohttp/streams.py", line 616, in read
     await self._waiter
 aiohttp.client_exceptions.ClientOSError: [Errno 104] Connection reset by peer
 --------%<----------------%<----------------%<----------------%<--------
... but looks more like an issue with asynchronous io, no?

 --------%<----------------%<----------------%<----------------%<--------
subiquity-client-debug.log.2444-2024-03-12 17:32:14,116 INFO subiquity:130 Starting Subiquity TUI revision 5575 of snap /snap/subiquity/5575
subiquity-client-debug.log.2444-2024-03-12 17:32:14,116 INFO subiquity:131 Arguments passed: ['/snap/subiquity/5575/usr/bin/subiquity']
subiquity-client-debug.log.2444-2024-03-12 17:32:14,116 DEBUG subiquity:132 Environment: environ({'PYTHONIOENCODING': 'utf-8', 'SNAP_COMMON': '/var/snap/subiquity/common', 'SNAP_INSTANCE_KEY': '', 'USER': 'root', 'SNAP_UID': '0', 'PYTHONPATH_ORIG': '', 'SNAP_LIBRARY_PATH': '/var/lib/snapd/lib/gl:/var/lib/snapd/lib/gl32:/var/lib/snapd/void', 'PYTHON': '/snap/subiquity/5575/usr/bin/python3.10', 'SNAP_USER_DATA': '/root/snap/subiquity/5575', 'SUBIQUITY_ROOT': '/snap/subiquity/5575', 'PYTHONIOENCODING_ORIG': '', 'SYSTEMD_EXEC_PID': '2444', 'SNAP_REVISION': '5575', 'JOURNAL_STREAM': '8:37240', 'SNAP_CONTEXT': 'RUOSwITDKd-0wId3yOPg1N__m7eUzi6eODQx-w9xX9BSzVUjYO3M', 'PYTHON_ORIG': '', 'SNAP_VERSION': '22.02.2+git2073.263520ad', 'TERM': 'linux', 'SNAP_INSTANCE_NAME': 'subiquity', 'SUBIQUITY_ROOT_ORIG': '', 'PATH': '/snap/subiquity/5575/bin:/snap/subiquity/5575/usr/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', 'INVOCATION_ID': '1949f3b06c9941769ae99f1a5f34a346', 'SNAP_DATA': '/var/snap/subiquity/5575', 'LANG': 'en_US.UTF-8', 'SNAP_ARCH': 's390x', 'SNAP_COOKIE': 'RUOSwITDKd-0wId3yOPg1N__m7eUzi6eODQx-w9xX9BSzVUjYO3M', 'SNAP_USER_COMMON': '/root/snap/subiquity/common', 'SNAP_REEXEC': '0', 'SNAP_NAME': 'subiquity', 'PATH_ORIG': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin', 'PWD': '/var/snap/subiquity/5575', 'SNAP_REAL_HOME': '/root', 'SNAP': '/snap/subiquity/5575', 'SNAP_EUID': '0', 'PYTHONPATH': '/snap/subiquity/5575/lib/python3.10/site-packages', 'APPORT_DATA_DIR': '/snap/subiquity/5575/share/apport'})
subiquity-client-debug.log.2444-2024-03-12 17:32:14,116 DEBUG asyncio:54 Using selector: EpollSelector
subiquity-client-debug.log.2444-2024-03-12 17:32:14,116 DEBUG subiquitycore.screen:129 KDGKBTYPE returned b'\x02', is_linux_tty True
subiquity-client-debug.log.2444-2024-03-12 17:32:15,199 DEBUG subiquitycore.core:118 starting controllers
subiquity-client-debug.log.2444-2024-03-12 17:32:15,199 DEBUG subiquitycore.core:121 controllers started
subiquity-client-debug.log.2444-2024-03-12 17:32:15,200 DEBUG subiquity/Progress/_wait_status:105 start:
subiquity-client-debug.log.2444-2024-03-12 17:32:15,239 DEBUG subiquity.common.errorreport:398 generating crash report
subiquity-client-debug.log.2444:2024-03-12 17:32:15,242 INFO subiquity.common.errorreport:424 saving crash report 'Installer UI crashed with ClientOSError' to /var/crash/1710264735.239347935.ui.crash
subiquity-client-debug.log.2444-2024-03-12 17:32:15,242 INFO subiquity/ErrorReporter/1710264735.239347935.ui/add_info:105 start:
subiquity-client-debug.log.2444:2024-03-12 17:32:15,384 INFO subiquity/ErrorReporter/1710264735.239347935.ui/add_info:110 finish: written to /var/crash/1710264735.239347935.ui.crash SUCCESS
subiquity-client-debug.log.2444-2024-03-12 17:32:15,386 DEBUG subiquity/Progress/_wait_status:110 finish: cancelled FAIL
--
subiquity-client-info.log.2444-2024-03-12 17:32:14,116 INFO subiquity:130 Starting Subiquity TUI revision 5575 of snap /snap/subiquity/5575
subiquity-client-info.log.2444-2024-03-12 17:32:14,116 INFO subiquity:131 Arguments passed: ['/snap/subiquity/5575/usr/bin/subiquity']
subiquity-client-info.log.2444:2024-03-12 17:32:15,242 INFO subiquity.common.errorreport:424 saving crash report 'Installer UI crashed with ClientOSError' to /var/crash/1710264735.239347935.ui.crash
subiquity-client-info.log.2444-2024-03-12 17:32:15,242 INFO subiquity/ErrorReporter/1710264735.239347935.ui/add_info:105 start:
subiquity-client-info.log.2444:2024-03-12 17:32:15,384 INFO subiquity/ErrorReporter/1710264735.239347935.ui/add_info:110 finish: written to /var/crash/1710264735.239347935.ui.crash SUCCESS
 --------%<----------------%<----------------%<----------------%<--------

There is a chance that this is 'just' a follow-on issue from the already known openssh-server crash reported here: LP#2056570
(That's the main reason why we are now waiting <Incomplete> for an update that has the openssh-server situation solved, and will re-test...)

[Frank Heimes (fheimes)]

Had a closer look at the crash file(s), and I'm not sure if the message that was presented to me during the installation, after the crash is due to the kind of optimistic approach and probing that is done during installation ?!

But it actually never makes sense to do:
"
Running command ['fdasd', '--table', '/dev/nvme0n1'] with allowed return codes [0] (capture=False)
"
since it will always fail and end up like this:
"
 fdasd error: device verification failed
 Partition '/dev/nvme0n1' (259/1) detected where device is required
"

However, two crashed happened during this installation, whereas one seems to be the known (LP#2056570) openssh-server case (1710264760.127559423.install_fail.crash):
 --------%<----------------%<----------------%<----------------%<--------
Title: install failed crashed with CalledProcessError
Traceback:
 Traceback (most recent call last):
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/controllers/install.py", line 625, in install
     await self.postinstall(context=context)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquitycore/context.py", line 149, in decorated_async
     return await meth(self, **kw)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/controllers/install.py", line 664, in postinstall
     await self.install_package(context=context, package=package.name)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquitycore/context.py", line 149, in decorated_async
     return await meth(self, **kw)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/controllers/install.py", line 725, in install_package
     await run_curtin_command(
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/curtin.py", line 230, in run_curtin_command
     return await cmd.wait()
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/curtin.py", line 125, in wait
     result = await self.runner.wait(self.proc)
   File "/snap/subiquity/5575/lib/python3.10/site-packages/subiquity/server/runner.py", line 94, in wait
     raise subprocess.CalledProcessError(
 subprocess.CalledProcessError: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.2553', '--setenv', 'PATH=/snap/subiquity/5575/bin:/snap/subiquity/5575/usr/bin:/snap/subiquity/5575/bin:/snap/subiquity/5575/usr/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/subiquity/5575/bin:/snap/subiquity/5575/sbin:/snap/subiquity/5575/bin:/snap/subiquity/5575/sbin', '--setenv', 'PYTHONPATH=:/snap/subiquity/5575/lib/python3.10/site-packages:/snap/subiquity/5575/lib/python3.10/site-packages', '--setenv', 'PYTHON=/snap/subiquity/5575/usr/bin/python3.10', '--setenv', 'SNAP=/snap/subiquity/5575', '--', '/snap/subiquity/5575/usr/bin/python3.10', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.2553.10"}}', 'system-install', '-t', '/target', '--assume-downloaded', '--', 'openssh-server']' returned non-zero exit status 100.
 --------%<----------------%<----------------%<-...

[Dan Bungert (dbungert)]

As Frank seems to want to focus on the AIO part, let's do that.

The fdasd part the bug was originally filed on is non-fatal, and the openssh symptom is a known issue and is in progress.

I would like this to be retested when the openssh symptom has been addressed. Setting to incomplete pending that retest.

[Ubuntu QA Website (ubuntuqa)]

This bug has been reported on the Ubuntu ISO testing tracker.

A list of all reports related to this bug can be found here:
http://iso.qa.ubuntu.com/qatracker/reports/bugs/2057696

[Dan Bungert (dbungert)]

Closing per suggestion from Frank. Server crashes are often client crashes, so there is no particular action here (other than a UX change to make this distinction more obvious)