[Bug 2009141] host_installer_shell_cmds_04062023_1.txt
bugproxy
2009141 at bugs.launchpad.net
Thu Apr 6 21:50:28 UTC 2023
------- Comment on attachment From finnegan at us.ibm.com 2023-04-06 17:43 EDT-------
Reference attached file host_installer_shell_cmds_04062023_1.txt on DMP details, from the shell for command executed in shell
Note after chzdev --enable, Quantity 1969 files generated in /var/log/crash filling up /
i.e.
ls -l /var/crash
chzdev --enable 0.0.100d
lszdev
ls -l | grep unknown | wc -l
1969
i.e.
45590 Apr 6 12:17 1680808641.142762184.unknown.crash.gz
90 Apr 6 12:17 1680808641.142762184.unknown.meta.gz
45751 Apr 6 12:17 1680808641.190968275.unknown.crash.gz
77 Apr 6 12:17 1680808641.190968275.unknown.meta.gz
.
.
.
142575 Apr 6 12:18 1680808725.929860353.unknown.crash.gz
77 Apr 6 12:18 1680808725.929860353.unknown.meta.gz
162995 Apr 6 12:18 1680808726.069142342.unknown.crash.gz
77 Apr 6 12:18 1680808726.069142342.unknown.meta.gz
141831 Apr 6 12:18 1680808726.164782763.unknown.crash.gz
77 Apr 6 12:18 1680808726.164782763.unknown.meta.gz
Includes
lszdev --auto-conf
multipath -l
lszfcp
fdisk -l /dev/mapper/xxxxx
ls -l /var/crash | wc -l <=============== Quantity 1969 files generated filling up /
root at ubuntu-server:~# df -T
Filesystem Type 1K-blocks Used Available Use% Mounted on
tmpfs tmpfs 3294672 305604 2989068 10% /run
/dev/loop0 iso9660 1149188 1149188 0 100% /cdrom
/cow overlay 16473348 16473348 0 100% /
overlay overlay 292992 292992 0 100% /media/filesystem
tmpfs tmpfs 16473348 0 16473348 0% /dev/shm
tmpfs tmpfs 5120 0 5120 0% /run/lock
tmpfs tmpfs 16473348 0 16473348 0% /tmp
tmpfs tmpfs 3294668 4 3294664 1% /run/user/1000
overlay overlay 292992 292992 0 100% /tmp/tmpcsrrjbgt/root.dir
In response to
> try manually wiping out the disk that have old LVM
Some of the luns are older OS Boot luns similar to lun mpathb (Boot lun
for ubuntu 20.04).
Wiping these luns would not be an option as they are needed for ongoing
tests and/or support
Will use a work-around to unmap such luns from the host during a new OS
install so a new lun [i.e. for 20.04.2) can be installed
Another OS Boot lun is 20.04.1 on zfcp-host 120d/130d [not enabled for
latest run]
Boot lun for ubuntu 20.04
lun mpathb (360050762198c1fc2180000000b000132) = (Boot lun for ubuntu 20.04)
mpathb (360050762198c1fc2180000000b000132) dm-1 IBM,FlashSystem-9840
size=50G features='0' hwhandler='0' wp=rw
`-+- policy='service-time 0' prio=0 status=active
|- 0:0:1:0 sdc 8:32 active undef running
`- 0:0:4:0 sdi 8:128 active undef running
fdisk -l /dev/mapper/mpathb
Disk /dev/mapper/mpathb: 50 GiB, 53687091200 bytes, 104857600 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 65536 bytes
Disklabel type: gpt
Disk identifier: D3739269-492B-463E-927C-5441496FB8F3
Device Start End Sectors Size Type
/dev/mapper/mpathb-part1 2048 2099199 2097152 1G Linux filesystem
/dev/mapper/mpathb-part2 2099200 104855551 102756352 49G Linux filesystem
** Attachment added: "host_installer_shell_cmds_04062023_1.txt"
https://bugs.launchpad.net/bugs/2009141/+attachment/5661756/+files/host_installer_shell_cmds_04062023_1.txt
--
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to subiquity in Ubuntu.
https://bugs.launchpad.net/bugs/2009141
Title:
[UBUNTU 22.04] OS installer exits for zfcp 32G adapter with an unknown
error. An error occurred during installation
Status in Ubuntu on IBM z Systems:
Triaged
Status in subiquity package in Ubuntu:
Triaged
Bug description:
Bug Description:
Installation of Ubuntu 22.04 on s390x failed with an unknown error just after having successfully activated a zfcp HBA with Fibre-Channel-attached SCSI disks.
I do see 0.0.100d successfully being online and having paths attached:
zfcp-host
0.0.100d online ?
0x500173800cef0111:0x0000000000000000 sg16
0x500173800cef0111:0x0001000000000000 sdp sg17
0x500173800cef0111:0x0002000000000000 sdq sg18
[host.ilabg13_9.11.116.213_ubuntu-22.04_ssh_installer.txt lines 41-41/9373 byte 238696/1146881 21%]
But immediately after that, the installer reports an error:
An error occurred during installation
??????????????????????????????????????????????????????????????????????????
?subiquity/Early/apply_autoinstall_config
?subiquity/Reporting/apply_autoinstall_config
?subiquity/Error/apply_autoinstall_config
?subiquity/Userdata/apply_autoinstall_config
?subiquity/Package/apply_autoinstall_config
?subiquity/Debconf/apply_autoinstall_config
?subiquity/Kernel/apply_autoinstall_config
?subiquity/Late/apply_autoinstall_config ??????????????????????????????????????????????????????????????????????????
? Sorry, an unknown error occurred. ?
? Information is being collected from the system that will help the ?
? developers diagnose the report. |
It looks like there was some ascii art progress bar while data was
collected and then the dialog updated to:
? [ View full report ] ?
? If you want to help improve the installer, you can send an error ?
? report. ?
? [ Send to Canonical ] ?
? [ Close report ] |
Next "View full report" was selected?
ProblemType: Bug
Architecture: s390x
CrashDB: {'impl': 'launchpad', 'project': 'subiquity'}
CurrentDmesg:
[ 0.093997] Linux version 5.15.0-43-generic (buildd at bos02-s390x-005) (gcc (Ubuntu 11.2.0-19ubuntu1) 11.2.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #46-Ubuntu SMP Tue Jul 12 12:40:17 UTC 2022 (Ubuntu 5.15.0-43.46-generic 5.15.39)
[ 0.094001] setup: Linux is running as a z/VM guest operating system in 64-bit mode
[ 0.360759] Kernel command line:
ip=9.11.116.213::9.11.116.1:255.255.255.0:ilabg13:ence0f:none:9.11.227.25
https://cdimage.ubuntu.com/releases/jammy/release/ubuntu-22.04.1-live-
server-s39
[ 2677.003438] zfcp 0.0.100d: qdio: ZFCP on SC 10 using AI:1 QEBSM:1 PRI:1 TDD:1 SIGA: W
[ 2677.032397] scsi host0: zfcp
[ 2677.060025] scsi 0:0:0:0: RAID IBM 2810XIV-LUN-0 0000 PQ: 0 ANSI: 5
[ 2677.061097] scsi 0:0:0:0: alua: disable for non-disk devices
[ 2677.061134] scsi 0:0:0:0: Attached scsi generic sg0 type 12
[ 2677.062988] scsi 0:0:0:1: Direct-Access IBM 2810XIV 0000 PQ: 0 ANSI: 5
[ 2677.064628] scsi 0:0:0:1: alua: supports implicit TPGS
[ 2677.064632] scsi 0:0:0:1: alua: device naa.6001738cfc900cef0000000000013596 port group 0 rel port 301
[ 2677.064679] sd 0:0:0:1: Attached scsi generic sg1 type 0
==> zfcp could successfully set 0.0.100d online and automatic LUN scan
worked.
[ 2677.513028] sd 0:0:16:1074020357: [sdac] Attached SCSI disk
[ 2677.522641] sd 0:0:16:1074020356: [sdab] Attached SCSI disk
[ 2677.522677] sd 0:0:15:1074020357: [sdaa] Attached SCSI disk
[ 2677.522693] sd 0:0:15:1074020356: [sdz] Attached SCSI disk
[ 2678.660373] device-mapper: multipath service-time: version 0.3.0 loaded
Date: Wed Jan 18 21:04:03 2023
DistroRelease: Ubuntu 22.04
ExecutablePath: /snap/subiquity/3699/lib/python3.8/site-packages/subiquity/cmd/server.py
InstallerServerLog:
2023-01-18 20:23:57,901 INFO subiquity:112 Starting Subiquity server revision 3699
2023-01-18 21:02:53,381 DEBUG root:39 start: subiquity/Zdev/GET:
2023-01-18 21:02:53,381 DEBUG subiquitycore.utils:64 run_command called: ['lszdev', '--quiet', '--pairs', '--columns', 'id,type,on,exists,pers,auto,failed,names']
2023-01-18 21:02:53,405 DEBUG subiquitycore.utils:77 run_command ['lszdev', '--quiet', '--pairs', '--columns', 'id,type,on,exists,pers,auto,failed,names'] exited with code 0
2023-01-18 21:02:53,406 DEBUG root:39 finish: subiquity/Zdev/GET: SUCCESS: 200 [{"id": "0.0.0009", "type": "generic-ccw", "on": true, "exists": true, "pers"...
2023-01-18 21:02:53,414 INFO aiohttp.access:233 [18/Jan/2023:21:02:53 +0000] "GET /zdev HTTP/1.1" 200 2059 "-" "Python/3.8 aiohttp/3.6.2"
2023-01-18 21:03:06,492 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
2023-01-18 21:03:06,534 DEBUG subiquitycore.utils:77 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-01-18 21:03:06,534 DEBUG probert.network:585 event for addr_change: CHANGE {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 0, 'local': b'2002:90b:e006:116:76:54ff:fe00:5/64'}
2023-01-18 21:03:06,534 DEBUG probert.network:717 addr_change CHANGE {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 0, 'local': b'2002:90b:e006:116:76:54ff:fe00:5/64'}
2023-01-18 21:03:06,534 DEBUG root:39 start: subiquity/Network/_send_update: CHANGE ence0f
2023-01-18 21:03:06,534 DEBUG subiquity.server.controllers.network:354 dev_info ence0f {'addresses': ['9.11.116.213/24'], 'gateway4': '9.11.116.1', 'nameservers': {'addresses': ['9.11.227.25']}}
2023-01-18 21:03:06,535 DEBUG root:39 finish: subiquity/Network/_send_update: SUCCESS: CHANGE ence0f
2023-01-18 21:03:19,283 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
2023-01-18 21:03:19,314 DEBUG subiquitycore.utils:77 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-01-18 21:03:19,314 DEBUG probert.network:585 event for addr_change: CHANGE {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 0, 'local': b'2002:90b:e006:116:76:54ff:fe00:5/64'}
2023-01-18 21:03:19,314 DEBUG probert.network:717 addr_change CHANGE {'ifindex': 2, 'flags': 768, 'family': 10, 'scope': 0, 'local': b'2002:90b:e006:116:76:54ff:fe00:5/64'}
2023-01-18 21:03:19,314 DEBUG root:39 start: subiquity/Network/_send_update: CHANGE ence0f
2023-01-18 21:03:19,314 DEBUG subiquity.server.controllers.network:354 dev_info ence0f {'addresses': ['9.11.116.213/24'], 'gateway4': '9.11.116.1', 'nameservers': {'addresses': ['9.11.227.25']}}
2023-01-18 21:03:19,314 DEBUG root:39 finish: subiquity/Network/_send_update: SUCCESS: CHANGE ence0f
2023-01-18 21:03:59,037 DEBUG root:39 start: subiquity/Zdev/chzdev_POST:
2023-01-18 21:03:59,038 DEBUG subiquitycore.utils:92 arun_command called: ['chzdev', '--enable', '0.0.100d']
2023-01-18 21:03:59,357 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
2023-01-18 21:03:59,373 DEBUG subiquitycore.utils:77 run_command ['udevadm', 'settle', '-t', '0'] exited with code 1
2023-01-18 21:03:59,373 DEBUG subiquity.server.controller.filesystem:495 waiting 0.1 to let udev event queue settle
... <<< some time with repeated udevadm settle >>> ...
2023-01-18 21:04:02,984 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
2023-01-18 21:04:02,986 DEBUG subiquitycore.utils:77 run_command ['udevadm', 'settle', '-t', '0'] exited with code 1
2023-01-18 21:04:02,986 DEBUG subiquity.server.controller.filesystem:495 waiting 0.1 to let udev event queue settle
2023-01-18 21:04:03,029 DEBUG subiquitycore.utils:101 arun_command ['chzdev', '--enable', '0.0.100d'] exited with code 0
2023-01-18 21:04:03,029 DEBUG subiquitycore.utils:64 run_command called: ['lszdev', '--quiet', '--pairs', '--columns', 'id,type,on,exists,pers,auto,failed,names']
2023-01-18 21:04:03,047 DEBUG subiquitycore.utils:77 run_command ['lszdev', '--quiet', '--pairs', '--columns', 'id,type,on,exists,pers,auto,failed,names'] exited with code 0
2023-01-18 21:04:03,052 DEBUG root:39 finish: subiquity/Zdev/chzdev_POST: SUCCESS: 200 [{"id": "0.0.0009", "type": "generic-ccw", "on": true, "exists": true, "pers"...
2023-01-18 21:04:03,052 INFO aiohttp.access:233 [18/Jan/2023:21:03:59 +0000] "POST /zdev/chzdev?action=%22enable%22&zdev=%7B%22id%22:+%220.0.100d%22,+%22type%22:+%22zfcp-host%22,+%22on%22:+false,+%22exists%22:+true,+%22pers%22:+false,+%22auto%22:+false,+%22failed%22:+false,+%22names%22:+%22%22%7D HTTP/1.1" 200 7956 "-" "Python/3.8 aiohttp/3.6.2"
2023-01-18 21:04:03,087 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
2023-01-18 21:04:03,114 DEBUG subiquitycore.utils:77 run_command ['udevadm', 'settle', '-t', '0'] exited with code 0
2023-01-18 21:04:03,114 ERROR subiquity.server.server:416 top level error
2023-01-18 21:04:03,114 ERROR subiquity.server.server:416 top level error
Traceback (most recent call last):
File "/snap/subiquity/3699/usr/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/snap/subiquity/3699/lib/python3.8/site-packages/subiquity/server/controllers/filesystem.py", line 506, in _udev_event
action, dev = self._monitor.receive_device()
File "/snap/subiquity/3699/lib/python3.8/site-packages/pyudev/monitor.py", line 397, in receive_device
device = self.poll()
File "/snap/subiquity/3699/lib/python3.8/site-packages/pyudev/monitor.py", line 357, in poll
if eintr_retry_call(poll.Poll.for_events((self, 'r')).poll, timeout):
File "/snap/subiquity/3699/lib/python3.8/site-packages/pyudev/_util.py", line 163, in eintr_retry_call
return func(*args, **kwargs)
File "/snap/subiquity/3699/lib/python3.8/site-packages/pyudev/_os/poll.py", line 97, in poll
return list(self._parse_events(eintr_retry_call(self._notifier.poll, timeout)))
File "/snap/subiquity/3699/lib/python3.8/site-packages/pyudev/_os/poll.py", line 112, in _parse_events
raise IOError('Error while polling fd: {0!r}'.format(fd))
OSError: Error while polling fd: 20
2023-01-18 21:04:03,116 DEBUG subiquitycore.common.errorreport:384 generating crash report
2023-01-18 21:04:03,116 INFO subiquitycore.common.errorreport:406 saving crash report 'unknown error crashed with OSError' to /var/crash/1674075843.116781473.unknown.crash
2023-01-18 21:04:03,117 INFO root:39 start: subiquity/ErrorReporter/1674075843.116781473.unknown/add_info:
2023-01-18 21:04:03,117 INFO root:39 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "", "error": {"state": "INCOMPLETE", "ba...
2023-01-18 21:04:03,117 INFO root:39 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "", "error": {"state": "INCOMPLETE", "ba...
2023-01-18 21:04:03,117 INFO root:39 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "", "error": {"state": "INCOMPLETE", "ba...
2023-01-18 21:04:03,118 INFO root:39 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "ERROR", "confirming_tty": "", "error": {"state": "INCOMPLETE", "ba...
2023-01-18 21:04:03,118 DEBUG subiquitycore.utils:64 run_command called: ['udevadm', 'settle', '-t', '0']
InstallerServerLogInfo:
InterpreterPath: /snap/subiquity/3699/usr/bin/python3.8
UdevDb:
...
P: /devices/css0/0.0.0010/0.0.100d
L: 0
E: DEVPATH=/devices/css0/0.0.0010/0.0.100d
E: SUBSYSTEM=ccw
E: DRIVER=zfcp
E: CU_TYPE=1731
E: CU_MODEL=03
E: DEV_TYPE=1732
E: DEV_MODEL=03
E: MODALIAS=ccw:t1731m03dt1732dm03
...
P: /devices/css0/0.0.0010/0.0.100d/host0/rport-0:0-0/target0:0:0/0:0:0:1/block/sda
N: sda
L: 0
S: disk/by-path/ccw-0.0.100d-fc-0x500173800cef0131-lun-1
S: disk/by-id/scsi-0IBM_2810XIV_host=ilabg13_tuc3_fcp_32G
S: disk/by-id/scsi-36001738cfc900cef0000000000013596
S: disk/by-id/wwn-0x6001738cfc900cef0000000000013596
S: disk/by-uuid/da904d37-e306-4223-8fbb-9670357ca708
S: disk/by-id/scsi-SIBM_2810XIV_6000CEF0000000000013596
S: disk/by-id/scsi-1IBM_2810XIV_6000CEF0000000000013596
...
E: DM_MULTIPATH_DEVICE_PATH=1
...
P: /devices/css0/0.0.0010/0.0.100d/host0/rport-0:0-17/target0:0:17/0:0:17:1/block/sdae
N: sdae
L: 0
S: disk/by-id/scsi-1IBM_FlashSystem-984026c6702d26c6-0000-007d-000294
S: disk/by-id/scsi-SIBM_FlashSystem-9840_26c6702d26c6-0000-007d-000294
S: disk/by-path/ccw-0.0.100d-fc-0x500507605e8b7271-lun-1
S: disk/by-uuid/97c7452a-2f45-4f7b-9127-d63b4a34e1e4
S: disk/by-id/scsi-36005076b19bcb49b180000007d000294
S: disk/by-id/wwn-0x6005076b19bcb49b180000007d000294
E: DEVPATH=/devices/css0/0.0.0010/0.0.100d/host0/rport-0:0-17/target0:0:17/0:0:17:1/block/sdae
E: SUBSYSTEM=block
E: DEVNAME=/dev/sdae
E: DEVTYPE=disk
E: DISKSEQ=43
E: MAJOR=65
E: MINOR=224
E: USEC_INITIALIZED=2677514875
E: DM_MULTIPATH_DEVICE_PATH=1
...
P: /devices/css0/0.0.0010/0.0.100d/host0/rport-0:0-9/target0:0:9/0:0:9:1/block/sdo
N: sdo
L: 0
S: disk/by-path/ccw-0.0.100d-fc-0x500507680b2541ba-lun-1
S: disk/by-id/wwn-0x6005076400818089b000000000000157
S: disk/by-id/scsi-36005076400818089b000000000000157
S: disk/by-id/scsi-SIBM_2145_010020c0226cXX00
S: disk/by-uuid/0fbe15bc-49fb-4a09-b9f2-269129fa9913
E: DEVPATH=/devices/css0/0.0.0010/0.0.100d/host0/rport-0:0-9/target0:0:9/0:0:9:1/block/sdo
E: SUBSYSTEM=block
E: DEVNAME=/dev/sdo
E: DEVTYPE=disk
E: DISKSEQ=27
E: MAJOR=8
E: MINOR=224
E: USEC_INITIALIZED=2677616364
E: DM_MULTIPATH_DEVICE_PATH=1
==> Probably the last discovered SCSI LUN.
P: /devices/virtual/block/dm-0
N: dm-0
L: 50
S: disk/by-id/scsi-360050762198c1fc2180000000b000132
S: disk/by-id/wwn-0x60050762198c1fc2180000000b000132
S: disk/by-id/dm-name-mpatha
S: disk/by-id/dm-uuid-mpath-360050762198c1fc2180000000b000132
S: mapper/mpatha
E: DEVPATH=/devices/virtual/block/dm-0
E: SUBSYSTEM=block
E: DEVNAME=/dev/dm-0
E: DEVTYPE=disk
E: DISKSEQ=44
E: MAJOR=253
E: MINOR=0
E: USEC_INITIALIZED=2678671661
E: DM_UDEV_DISABLE_LIBRARY_FALLBACK_FLAG=1
E: DM_UDEV_PRIMARY_SOURCE_FLAG=1
E: DM_ACTIVATION=1
E: DM_NAME=mpatha
E: DM_UUID=mpath-360050762198c1fc2180000000b000132
E: DM_SUSPENDED=0
E: DM_UDEV_RULES=1
E: DM_UDEV_RULES_VSN=2
E: MPATH_SBIN_PATH=/sbin
E: MPATH_DEVICE_READY=1
==> Multipath devices also got assembled.
Canonical, why did the installer get an error?
Does the installer really have a busy(!) waiting loop calling udevadm settle with zero timeout?
But even if so, with the number of discovered devices and the settle finally returning with success errorlevel 0, it should just work?
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-z-systems/+bug/2009141/+subscriptions
More information about the foundations-bugs
mailing list