csi-driver icon indicating copy to clipboard operation
csi-driver copied to clipboard

Encrypted XFS volume fails to be mounted, pod stucks at `ContainerCreating`

Open bheisig opened this issue 11 months ago • 14 comments

TL;DR

When moving a pod from one worker node to another the attached volume fails to be mounted. The volume is encrypted and formatted with XFS.

Expected behavior

When moving a pod to another node the attached volume should also be moved and mounted and attached properly.

Observed behavior

It worked fine a couple of months ago but since then this behavior occurs on 3 different k8s clusters.

Pod stucks at state ContainerCreating.

k8s event log
 Warning  FailedMount             33s (x14 over 12m)  kubelet                  MountVolume.SetUp failed for volume "pvc-f478066b-1e87-4572-9dd3-32da9985f75d" : rpc error: code = Internal desc = failed to publish volume: format of disk "/dev/mapper/scsi-0HC_Volume_100327067" failed: type:("xfs") target:("/var/lib/kubelet/pods/b8b76bc0-285c-4ee8-ae66-672f38b80ce9/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount") options:("defaults") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully
error reading existing superblock: I/O error
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on (unknown) bno 0x27fef00/0x100, err=5
mkfs.xfs: Releasing dirty buffer to free list!
found dirty buffer (bulk) on free list!
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on (unknown) bno 0x0/0x100, err=5
mkfs.xfs: Releasing dirty buffer to free list!
found dirty buffer (bulk) on free list!
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on xfs_sb bno 0x0/0x1, err=5
mkfs.xfs: Releasing dirty buffer to free list!
mkfs.xfs: libxfs_device_zero write failed: I/O error
meta-data=/dev/mapper/scsi-0HC_Volume_100327067 isize=512    agcount=4, agsize=1310592 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0
         =                       exchange=0  
data     =                       bsize=4096   blocks=5242368, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1, parent=0
log      =internal log           bsize=4096   blocks=16384, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0
)
dmesg on k8s worker node (source)
[  702.744852] sd 0:0:0:1: [sdb] Synchronizing SCSI cache
[  702.745000] sd 0:0:0:1: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[  702.745138] sd 0:0:0:1: [sdb] Synchronize Cache(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  702.745142] sd 0:0:0:1: [sdb] Sense Key : Illegal Request [current] 
[  702.745144] sd 0:0:0:1: [sdb] Add. Sense: Logical unit not supported
[  703.218767] dmcrypt_write/2: attempt to access beyond end of device
               sdb: rw=169985, sector=10505187, nr_sectors = 7 limit=0
[  703.218791] XFS (dm-12): log I/O error -5
[  703.220142] XFS (dm-12): Filesystem has been shut down due to log error (0x2).
[  703.223894] XFS (dm-12): Please unmount the filesystem and rectify the problem(s).
[  703.232395] XFS (dm-12): Unmounting Filesystem 0a9c39c8-6311-4de9-aa29-c80d72678f8a
dmesg on k8s worker node (destination)
[ 8558.563139] sd 0:0:0:2: Power-on or device reset occurred
[ 8558.563283] sd 0:0:0:2: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[ 8558.563726] sd 0:0:0:2: [sdb] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB)
[ 8558.563781] sd 0:0:0:2: [sdb] Write Protect is off
[ 8558.563785] sd 0:0:0:2: [sdb] Mode Sense: 63 00 00 08
[ 8558.563867] sd 0:0:0:2: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 8558.566654] sd 0:0:0:2: [sdb] Attached SCSI disk
[ 8561.101394] scsi host7: iSCSI Initiator over TCP/IP
[ 8561.103179] scsi 7:0:0:0: RAID              IET      Controller       0001 PQ: 0 ANSI: 5
[ 8561.104758] scsi 7:0:0:0: Attached scsi generic sg3 type 12
[ 8561.105203] scsi 7:0:0:1: Direct-Access     IET      VIRTUAL-DISK     0001 PQ: 0 ANSI: 5
[ 8561.108397] sd 7:0:0:1: Attached scsi generic sg4 type 0
[ 8561.108491] sd 7:0:0:1: Power-on or device reset occurred
[ 8561.108795] sd 7:0:0:1: [sdc] 4194304 512-byte logical blocks: (2.15 GB/2.00 GiB)
[ 8561.108913] sd 7:0:0:1: [sdc] Write Protect is off
[ 8561.108916] sd 7:0:0:1: [sdc] Mode Sense: 69 00 10 08
[ 8561.109245] sd 7:0:0:1: [sdc] Write cache: disabled, read cache: enabled, supports DPO and FUA
[ 8561.126059] sd 7:0:0:1: [sdc] Attached SCSI disk
[ 8562.074292] blkid: attempt to access beyond end of device
               sdk: rw=524288, sector=41942912, nr_sectors = 8 limit=0
[ 8562.074305] blkid: attempt to access beyond end of device
               sdk: rw=0, sector=41942912, nr_sectors = 8 limit=0
[ 8562.074308] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8562.078707] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[ 8562.078721] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[ 8562.078874] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2048, sector=4096, nr_sectors = 1 limit=0
[ 8562.079351] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=41942784, nr_sectors = 256 limit=0
[ 8562.079703] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 256 limit=0
[ 8562.079876] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 1 limit=0
[ 8562.087313] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20973608, nr_sectors = 2048 limit=0
[ 8562.087351] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20975656, nr_sectors = 2048 limit=0
[ 8562.675559] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8563.786083] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8565.794174] eth0: renamed from tmpb18e5
[ 8565.907520] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8570.047102] bio_check_eod: 282 callbacks suppressed
[ 8570.047109] blkid: attempt to access beyond end of device
               sdk: rw=524288, sector=41942912, nr_sectors = 8 limit=0
[ 8570.047130] blkid: attempt to access beyond end of device
               sdk: rw=0, sector=41942912, nr_sectors = 8 limit=0
[ 8570.047137] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8570.055588] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[ 8570.055601] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[ 8570.055729] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2048, sector=4096, nr_sectors = 1 limit=0
[ 8570.056255] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=41942784, nr_sectors = 256 limit=0
[ 8570.056726] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 256 limit=0
[ 8570.057054] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 1 limit=0
[ 8570.060980] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20975656, nr_sectors = 2048 limit=0
[ 8570.060997] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20977704, nr_sectors = 2048 limit=0
[ 8578.217568] bio_check_eod: 63 callbacks suppressed
[ 8578.217573] blkid: attempt to access beyond end of device
               sdk: rw=524288, sector=41942912, nr_sectors = 8 limit=0
[ 8578.217584] blkid: attempt to access beyond end of device
               sdk: rw=0, sector=41942912, nr_sectors = 8 limit=0
[ 8578.217587] Buffer I/O error on dev dm-9, logical block 5242352, async page read
[ 8578.221335] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[ 8578.221341] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[ 8578.221391] mkfs.xfs: attempt to access beyond end of device
               sdk: rw=2048, sector=4096, nr_sectors = 1 limit=0
[ 8578.221618] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=41942784, nr_sectors = 256 limit=0
[ 8578.221837] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 256 limit=0
[ 8578.221958] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=34817, sector=4096, nr_sectors = 1 limit=0
[ 8578.223096] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20973608, nr_sectors = 2048 limit=0
[ 8578.223118] dmcrypt_write/2: attempt to access beyond end of device
               sdk: rw=1, sector=20975656, nr_sectors = 2048 limit=0
[ 8594.370868] bio_check_eod: 63 callbacks suppressed
[ 8594.370873] blkid: attempt to access beyond end of device
               sdk: rw=524288, sector=41942912, nr_sectors = 8 limit=0
[ 8594.370887] blkid: attempt to access beyond end of device
               sdk: rw=0, sector=41942912, nr_sectors = 8 limit=0
[ 8594.370891] Buffer I/O error on dev dm-9, logical block 5242352, async page read
journal on k8s worker node (destination)
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: scsi 0:0:0:1: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: Attached scsi generic sg2 type 0
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: Power-on or device reset occurred
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: [sdk] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB)
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: [sdk] Write Protect is off
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: [sdk] Mode Sense: 63 00 00 08
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: [sdk] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b kernel: sd 0:0:0:1: [sdk] Attached SCSI disk
Apr 02 11:45:59 k8s-worker-2d67845a20e2271b (udev-worker)[213707]: sdk: Process '/usr/bin/unshare -m /usr/bin/snap auto-import --mount=/dev/sdk' failed with exit code 1.
Apr 02 11:46:00 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:00.438875727Z" level=info msg="TaskExit event in podsandbox handler container_id:\"ec43f24ae3d627e43567d72ba1a9ea8acf368f3b4ee697868ae914ea12fd2e3f\"  id:\"f0914f34a06f78b8c7ba83a2d77775b6c703396a858343a131932f31166b74a4\"  pid:213794  exited_at:{seconds:1743594360  nanos:438488333}"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.302967412Z" level=info msg="TaskExit event in podsandbox handler container_id:\"6363f2cb7e0c6ffa001f39952881cae5544f95f83d7c406dd3a3808dffeb822f\"  id:\"696bc5287d8978036999bbf4827e2841965bd796cf41c89f6dc1a38632d2c56c\"  pid:213848  exited_at:{seconds:1743594361  nanos:302623017}"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.305870435Z" level=info msg="TaskExit event in podsandbox handler container_id:\"6363f2cb7e0c6ffa001f39952881cae5544f95f83d7c406dd3a3808dffeb822f\"  id:\"4d7962cc892b52f42a2a506b598067c6f670aee3c8630558bb181ed395c9b7bf\"  pid:213850  exited_at:{seconds:1743594361  nanos:305650753}"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.601855000Z" level=info msg="TaskExit event in podsandbox handler container_id:\"a100e4f6459bb5e5e657f0aa8d2c069c9622bf6033318416061d795783c42e40\"  id:\"81c77cc709c1f8adb57f0c99aec31cf6f28f361fecb9a9ae8afb6330490bb88a\"  pid:213911  exited_at:{seconds:1743594361  nanos:601477162}"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.604140997Z" level=info msg="TaskExit event in podsandbox handler container_id:\"a100e4f6459bb5e5e657f0aa8d2c069c9622bf6033318416061d795783c42e40\"  id:\"636e8924f14b147d213e982ca70c8a551994de896202510587d639503cd7841b\"  pid:213913  exited_at:{seconds:1743594361  nanos:603797614}"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.637333740Z" level=warning msg="container event discarded" container=dc93210697a2d9a4bbcb68ca3ced36a0abeae5ed44970fa062029f48fe7d170a type=CONTAINER_DELETED_EVENT
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:01.747587    1480 scope.go:117] "RemoveContainer" containerID="f8e7dfe737fe57e6904763db97ec09e01d71703bb1589a0d85beecdaea6f7f18"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.749742607Z" level=info msg="RemoveContainer for \"f8e7dfe737fe57e6904763db97ec09e01d71703bb1589a0d85beecdaea6f7f18\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.755661032Z" level=info msg="RemoveContainer for \"f8e7dfe737fe57e6904763db97ec09e01d71703bb1589a0d85beecdaea6f7f18\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.757763345Z" level=info msg="StopPodSandbox for \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.796210690Z" level=info msg="TearDown network for sandbox \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\" successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.796249022Z" level=info msg="StopPodSandbox for \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.796709053Z" level=info msg="RemovePodSandbox for \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.796751633Z" level=info msg="Forcibly stopping sandbox \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.830034965Z" level=info msg="TearDown network for sandbox \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\" successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.832517320Z" level=info msg="Ensure that sandbox 10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95 in task-service has been cleanup successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.837023632Z" level=info msg="RemovePodSandbox \"10819328a07f4ec6773ec091e7fa308318fd6e4122e4741d68f088f7c78ddc95\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.837501908Z" level=info msg="StopPodSandbox for \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.878625230Z" level=info msg="TearDown network for sandbox \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\" successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.878668180Z" level=info msg="StopPodSandbox for \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.879228579Z" level=info msg="RemovePodSandbox for \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.879302488Z" level=info msg="Forcibly stopping sandbox \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.912867356Z" level=info msg="TearDown network for sandbox \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\" successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.916560006Z" level=info msg="Ensure that sandbox 4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca in task-service has been cleanup successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.920025029Z" level=info msg="RemovePodSandbox \"4e1688ab2cfe9da243e4118c0e92adbddf99cb4d39d1a1d2fb50d534b316d8ca\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.920597912Z" level=info msg="StopPodSandbox for \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:01.947678    1480 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") " pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:01.964200    1480 operation_generator.go:1491] "Controller attach succeeded for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") device path: \"\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.967464021Z" level=info msg="TearDown network for sandbox \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\" successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.967509305Z" level=info msg="StopPodSandbox for \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\" returns successfully"
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.968038616Z" level=info msg="RemovePodSandbox for \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\""
Apr 02 11:46:01 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:01.968094540Z" level=info msg="Forcibly stopping sandbox \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\""
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:02.007108085Z" level=info msg="TearDown network for sandbox \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\" successfully"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:02.011727128Z" level=info msg="Ensure that sandbox 2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237 in task-service has been cleanup successfully"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:02.015867647Z" level=info msg="RemovePodSandbox \"2399fe1e38c7930ecd9d80d14d14d8fa73f7e562f75c89d8b52c8d4cf23ba237\" returns successfully"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b containerd[1173]: time="2025-04-02T11:46:02.021943506Z" level=info msg="TaskExit event in podsandbox handler container_id:\"e9d4f67c03d04bd0e12dfdc922576f1e229600a5f20c67438bd8050915cf825e\"  id:\"6701d8e407af9e61fd40efba1a4120bbf02674b1e28bf1fd3c286d6a05201d67\"  pid:214037  exited_at:{seconds:1743594362  nanos:21457707}"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.049158    1480 operation_generator.go:538] "MountVolume.WaitForAttach entering for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") DevicePath \"\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.056010    1480 operation_generator.go:548] "MountVolume.WaitForAttach succeeded for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") DevicePath \"csi-4d085733a3b94c6963c384fc65fe08188edb788e9e3518f8cbd5e4a04516b313\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.063375    1480 csi_attacher.go:380] kubernetes.io/csi: attacher.MountDevice STAGE_UNSTAGE_VOLUME capability not set. Skipping MountDevice...
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.063413    1480 operation_generator.go:580] "MountVolume.MountDevice succeeded for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") device mount path \"/var/lib/kubelet/plugins/kubernetes.io/csi/csi.hetzner.cloud/690cdbea35506e948320f285c6424c7b8d3de5876983b647558104acf864be34/globalmount\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: bio_check_eod: 63 callbacks suppressed
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: blkid: attempt to access beyond end of device
                                                    sdb: rw=524288, sector=41942912, nr_sectors = 8 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: blkid: attempt to access beyond end of device
                                                    sdb: rw=0, sector=41942912, nr_sectors = 8 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: Buffer I/O error on dev dm-0, logical block 5242352, async page read
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: mkfs.xfs: attempt to access beyond end of device
                                                    sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: mkfs.xfs: attempt to access beyond end of device
                                                    sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: mkfs.xfs: attempt to access beyond end of device
                                                    sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                    sdb: rw=34817, sector=41942784, nr_sectors = 256 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                    sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                    sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                    sdb: rw=1, sector=20973608, nr_sectors = 2048 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                    sdb: rw=1, sector=20975656, nr_sectors = 2048 limit=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: E0402 11:46:02.116819    1480 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/csi/csi.hetzner.cloud^100327067 podName: nodeName:}" failed. No retries permitted until 2025-04-02 11:46:02.616793886 +0000 UTC m=+4926.399117456 (durationBeforeRetry 500ms). Error: MountVolume.SetUp failed for volume "pvc-f478066b-1e87-4572-9dd3-32da9985f75d" (UniqueName: "kubernetes.io/csi/csi.hetzner.cloud^100327067") pod "db-57fd8cc95d-ppdhr" (UID: "9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b") : rpc error: code = Internal desc = failed to publish volume: format of disk "/dev/mapper/scsi-0HC_Volume_100327067" failed: type:("xfs") target:("/var/lib/kubelet/pods/9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount") options:("defaults") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: error reading existing superblock: I/O error
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: pwrite failed: I/O error
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: libxfs_bwrite: write failed on (unknown) bno 0x27fef00/0x100, err=5
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: found dirty buffer (bulk) on free list!
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: pwrite failed: I/O error
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: libxfs_bwrite: write failed on (unknown) bno 0x0/0x100, err=5
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: found dirty buffer (bulk) on free list!
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: pwrite failed: I/O error
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: libxfs_bwrite: write failed on xfs_sb bno 0x0/0x1, err=5
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: mkfs.xfs: libxfs_device_zero write failed: I/O error
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: meta-data=/dev/mapper/scsi-0HC_Volume_100327067 isize=512    agcount=4, agsize=1310592 blks
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       sectsz=512   attr=2, projid32bit=1
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       crc=1        finobt=1, sparse=1, rmapbt=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       exchange=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: data     =                       bsize=4096   blocks=5242368, imaxpct=25
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       sunit=0      swidth=0 blks
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: naming   =version 2              bsize=4096   ascii-ci=0, ftype=1, parent=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: log      =internal log           bsize=4096   blocks=16384, version=2
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]:          =                       sectsz=512   sunit=0 blks, lazy-count=1
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: realtime =none                   extsz=4096   blocks=0, rtextents=0
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: )
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.657138    1480 operation_generator.go:538] "MountVolume.WaitForAttach entering for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") DevicePath \"csi-4d085733a3b94c6963c384fc65fe08188edb788e9e3518f8cbd5e4a04516b313\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: I0402 11:46:02.664760    1480 operation_generator.go:548] "MountVolume.WaitForAttach succeeded for volume \"pvc-f478066b-1e87-4572-9dd3-32da9985f75d\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^100327067\") pod \"db-57fd8cc95d-ppdhr\" (UID: \"9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b\") DevicePath \"csi-4d085733a3b94c6963c384fc65fe08188edb788e9e3518f8cbd5e4a04516b313\"" pod="test/db-57fd8cc95d-ppdhr"
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kernel: Buffer I/O error on dev dm-0, logical block 5242352, async page read
Apr 02 11:46:02 k8s-worker-2d67845a20e2271b kubelet[1480]: E0402 11:46:02.717019    1480 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/csi/csi.hetzner.cloud^100327067 podName: nodeName:}" failed. No retries permitted until 2025-04-02 11:46:03.716995522 +0000 UTC m=+4927.499319092 (durationBeforeRetry 1s). Error: MountVolume.SetUp failed for volume "pvc-f478066b-1e87-4572-9dd3-32da9985f75d" (UniqueName: "kubernetes.io/csi/csi.hetzner.cloud^100327067") pod "db-57fd8cc95d-ppdhr" (UID: "9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b") : rpc error: code = Internal desc = failed to publish volume: format of disk "/dev/mapper/scsi-0HC_Volume_100327067" failed: type:("xfs") target:("/var/lib/kubelet/pods/9c69a551-ba03-4bd6-ae7e-5cbe7adf5d7b/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount") options:("defaults") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully
hcloud csi node (destination node)
time=2025-04-02T11:15:53.995Z level=INFO source=/home/runner/work/csi-driver/csi-driver/internal/volumes/mount.go:125 msg="publishing volume" component=linux-mount-service target-path=/var/lib/kubelet/pods/ec66598d-e63d-4f2b-9631-ae29db466128/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount device-path=/dev/mapper/scsi-0HC_Volume_100327067 fs-type=xfs block-volume=false readonly=false mount-options="" encrypted=true
I0402 11:15:53.998597       1 mount_linux.go:618] Disk "/dev/mapper/scsi-0HC_Volume_100327067" appears to be unformatted, attempting to format as type: "xfs" with options: [-c options=/usr/share/xfsprogs/mkfs/lts_4.19.conf -f /dev/mapper/scsi-0HC_Volume_100327067]
E0402 11:15:54.014943       1 mount_linux.go:625] format of disk "/dev/mapper/scsi-0HC_Volume_100327067" failed: type:("xfs") target:("/var/lib/kubelet/pods/ec66598d-e63d-4f2b-9631-ae29db466128/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount") options:("defaults") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully
error reading existing superblock: I/O error
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on (unknown) bno 0x27fef00/0x100, err=5
mkfs.xfs: Releasing dirty buffer to free list!
found dirty buffer (bulk) on free list!
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on (unknown) bno 0x0/0x100, err=5
mkfs.xfs: Releasing dirty buffer to free list!
found dirty buffer (bulk) on free list!
mkfs.xfs: pwrite failed: I/O error
libxfs_bwrite: write failed on xfs_sb bno 0x0/0x1, err=5
mkfs.xfs: Releasing dirty buffer to free list!
mkfs.xfs: libxfs_device_zero write failed: I/O error
time=2025-04-02T11:15:54.014Z level=ERROR source=/home/runner/work/csi-driver/csi-driver/internal/app/app.go:276 msg="handler failed" err="rpc error: code = Internal desc = failed to publish volume: format of disk \"/dev/mapper/scsi-0HC_Volume_100327067\" failed: type:(\"xfs\") target:(\"/var/lib/kubelet/pods/ec66598d-e63d-4f2b-9631-ae29db466128/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount\") options:(\"defaults\") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully\nerror reading existing superblock: I/O error\nmkfs.xfs: pwrite failed: I/O error\nlibxfs_bwrite: write failed on (unknown) bno 0x27fef00/0x100, err=5\nmkfs.xfs: Releasing dirty buffer to free list!\nfound dirty buffer (bulk) on free list!\nmkfs.xfs: pwrite failed: I/O error\nlibxfs_bwrite: write failed on (unknown) bno 0x0/0x100, err=5\nmkfs.xfs: Releasing dirty buffer to free list!\nfound dirty buffer (bulk) on free list!\nmkfs.xfs: pwrite failed: I/O error\nlibxfs_bwrite: write failed on xfs_sb bno 0x0/0x1, err=5\nmkfs.xfs: Releasing dirty buffer to free list!\nmkfs.xfs: libxfs_device_zero write failed: I/O error\nmeta-data=/dev/mapper/scsi-0HC_Volume_100327067 isize=512    agcount=4, agsize=1310592 blks\n         =                       sectsz=512   attr=2, projid32bit=1\n         =                       crc=1        finobt=1, sparse=1, rmapbt=0\n         =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0\n         =                       exchange=0  \ndata     =                       bsize=4096   blocks=5242368, imaxpct=25\n         =                       sunit=0      swidth=0 blks\nnaming   =version 2              bsize=4096   ascii-ci=0, ftype=1, parent=0\nlog      =internal log           bsize=4096   blocks=16384, version=2\n         =                       sectsz=512   sunit=0 blks, lazy-count=1\nrealtime =none                   extsz=4096   blocks=0, rtextents=0\n) "
meta-data=/dev/mapper/scsi-0HC_Volume_100327067 isize=512    agcount=4, agsize=1310592 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0
         =                       exchange=0  
data     =                       bsize=4096   blocks=5242368, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1, parent=0
log      =internal log           bsize=4096   blocks=16384, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0
) 

Minimal working example

  • Vanilla k8s 1.31.7 (reproducible with 1.30.x, too)
  • At least 2 worker nodes
  • Worker nodes running Ubuntu 24.04.2 LTS (reproducible with Ubuntu 22.04 and Kernel 5.15.0-136-generic, too)
  • Linux Kernel 6.8.0-57-generic
  • containerd 2.0.4
  • hcloud-csi 2.13.0 Helm Chart
  • LUKS-encrypted volume formatted with XFS

For example, deploy the official MongoDB image v7 from Docker Hub:

k8s manifests
---
apiVersion: storage.k8s.io/v1
kind: StorageClass
metadata:
  name: hcloud-encrypted-volume-xfs
  annotations:
    storageclass.kubernetes.io/is-default-class: "false"
provisioner: csi.hetzner.cloud
reclaimPolicy: Delete
volumeBindingMode: WaitForFirstConsumer
allowVolumeExpansion: true
parameters:
  csi.storage.k8s.io/node-publish-secret-name: hcloud-csi-encryption
  csi.storage.k8s.io/node-publish-secret-namespace: kube-system
  fsType: xfs
---
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  namespace: test
  name: db
spec:
  accessModes:
    - ReadWriteOnce
  resources:
    requests:
      storage: 10Gi
  storageClassName: hcloud-encrypted-volume-xfs
  volumeMode: Filesystem
---
kind: Deployment
apiVersion: apps/v1
metadata:
  namespace: test
  name: db
  labels:
    app.kubernetes.io/name: db
spec:
  replicas: 1
  strategy:
    type: Recreate
  selector:
    matchLabels:
      app.kubernetes.io/component: db
  template:
    metadata:
      labels:
        app.kubernetes.io/name: db
    spec:
      volumes:
        - name: data
          persistentVolumeClaim:
            claimName: db
      containers:
        - name: db
          image: mongo:7.0.18
          imagePullPolicy: Always
          args:
            - mongod
            - --auth
            - --wiredTigerCacheSizeGB
            - '0.25'
          volumeMounts:
            - name: data
              mountPath: /data/db
          env:
            - name: MONGO_INITDB_ROOT_USERNAME
              value: root
            - name: MONGO_INITDB_ROOT_PASSWORD
              value: secret
            - name: MONGO_INITDB_DATABASE
              value: test

Additional information

Diry workaround: rebooting the worker node solves this issue.

bheisig avatar Apr 02 '25 12:04 bheisig

Hey, thank you for the detailed report of your issue. The people mainly responsible for this project are/were at KubeCon this week. I will investigate this issue next week.

Best Regards, Lukas

lukasmetzner avatar Apr 04 '25 13:04 lukasmetzner

Hey, I currently, cannot reproduce your issue. Do you have some more information about your environment, that you could share with me? Did you also try to reproduce the issue in a fresh testing cluster? How as the pod moved? Did you drain the node?

Could you provide some details about the xfs configuration of your volume? You can get this information by running the following command on the node where your volume is successfully mounted:

xfs_info <target-path> (target-path can be found in the logs of the DaemonSet)

Best Regards Lukas

lukasmetzner avatar Apr 07 '25 13:04 lukasmetzner

Hi.

This is directly from the affected worker node after a reboot (see my first post about the "dirty workaround"):

# xfs_info /var/lib/kubelet/pods/1898c74f-6cd1-4859-815a-e0d2fc3e5cc7/volumes/kubernetes.io~csi/pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17/mount
meta-data=/dev/mapper/scsi-0HC_Volume_102191764 isize=512    agcount=4, agsize=655232 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0
data     =                       bsize=4096   blocks=2620928, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=16384, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0

I don't know why but I can't run it on the DaemonSet:

# kubectl -n hcloud-csi exec -it hcloud-csi-node-rcrw9 --container=hcloud-csi-driver -- xfs_info /var/lib/kubelet/pods/1898c74f-6cd1-4859-815a-e0d2fc3e5cc7/volumes/kubernetes.io~csi/pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17/mount
xfs_info: cannot open /var/lib/kubelet/pods/1898c74f-6cd1-4859-815a-e0d2fc3e5cc7/volumes/kubernetes.io~csi/pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17/mount: Is a directory
command terminated with exit code 1

It's sufficient to cordon a worker node and delete a pod to reproduce the issue. There's no need to drain a node.

Sorry, I haven't found the time to reproduce this issue on a fresh cluster. Is there any other specific information I can provide?

bheisig avatar Apr 11 '25 10:04 bheisig

Hey,

does this only occur with a specific volume? If not, does it also occur with newly created volumes? Does this issue only happen if the pod/volume are being scheduled on a specific node of yours, or does it happen regardless of the node?

Is your volume functioning normally after applying the workaround? Your dmesg (source) logs also don't appear to indicate a healthy state.

If this only affects a specific volume, we could try to investigate any file system damage. In order to do this, delete the pod and wait for the volume to be detached from any server. In the Cloud Console mount the volume to a server of your choice and choose manual as a mount option. Run fdisk -l on the node, and you should be able to see your volume. Now open the LUKS device via cryptsetup open /dev/xxx volume-debugging (note: you need to enter your passphrase here) and check the XFS file system for damage via xfs_repair -n /dev/mapper/volume-debugging (-n being a no modify mode, just checks the file system for damage).

lukasmetzner avatar Apr 14 '25 15:04 lukasmetzner

Hey,

A bunch of questions… I try my best to answer them:

  • The problem occurs with a lot of volumes, not only one specific. They have in common that they are encrypted with LUKS and formatted with XFS.
  • The problem doesn't occur on newly created volumes. But it does occur when we try to reproduce it following the steps mentioned above.
  • It happens on all nodes (Ubuntu 22.04/24.04, k8s 1.30/1.31)
  • After the workaround the volume can be mounted successfully. But it fails again whenever I try to reproduce it.
dmesg from worker node during a failed volume state
[279286.471494] Memory cgroup out of memory: Killed process 1739884 (mongod) total-vm:1013180kB, anon-rss:519196kB, file-rss:85504kB, shmem-rss:0kB, UID:999 pgtables:1880kB oom_score_adj:992
[279286.476209] Tasks in /kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod18a7e0f3_f227_4c2f_92ca_79f9f6e47f7c.slice/cri-containerd-5415c4ab7f221d06753bd074fa4b97ab25765032f9357a48da6549f788b013df.scope are going to be killed due to memory.oom.group set
[279286.476219] Memory cgroup out of memory: Killed process 1739884 (mongod) total-vm:1013180kB, anon-rss:519196kB, file-rss:85504kB, shmem-rss:0kB, UID:999 pgtables:1880kB oom_score_adj:992
[281221.024566] XFS (dm-7): Unmounting Filesystem 6e95865a-4710-40a9-a3a6-803eb9e1fe25
[281226.264006] sd 0:0:0:5: [sdl] Synchronizing SCSI cache
[281226.264176] sd 0:0:0:5: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[281226.264428] sd 0:0:0:5: [sdl] Synchronize Cache(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[281226.264435] sd 0:0:0:5: [sdl] Sense Key : Illegal Request [current] 
[281226.264440] sd 0:0:0:5: [sdl] Add. Sense: Logical unit not supported
[281762.204260] scsi 0:0:0:1: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[281762.206121] sd 0:0:0:1: Attached scsi generic sg14 type 0
[281762.206223] sd 0:0:0:1: Power-on or device reset occurred
[281762.206500] sd 0:0:0:1: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[281762.206859] sd 0:0:0:1: [sdh] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[281762.206959] sd 0:0:0:1: [sdh] Write Protect is off
[281762.206968] sd 0:0:0:1: [sdh] Mode Sense: 63 00 00 08
[281762.207880] sd 0:0:0:1: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[281762.213200] sd 0:0:0:1: [sdh] Attached SCSI disk
[281765.485123] blkid: attempt to access beyond end of device
                sdl: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[281765.485145] blkid: attempt to access beyond end of device
                sdl: rw=0, sector=20971392, nr_sectors = 8 limit=0
[281765.485152] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281765.502166] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[281765.502183] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[281765.502316] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2048, sector=4096, nr_sectors = 1 limit=0
[281765.502837] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[281765.503317] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 256 limit=0
[281765.503564] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 1 limit=0
[281765.507210] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10487848, nr_sectors = 2048 limit=0
[281765.509805] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10489896, nr_sectors = 2048 limit=0
[281766.193344] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281767.301946] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281769.439216] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281773.583443] bio_check_eod: 282 callbacks suppressed
[281773.583451] blkid: attempt to access beyond end of device
                sdl: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[281773.583470] blkid: attempt to access beyond end of device
                sdl: rw=0, sector=20971392, nr_sectors = 8 limit=0
[281773.583475] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281773.593047] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[281773.593061] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[281773.593187] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2048, sector=4096, nr_sectors = 1 limit=0
[281773.593657] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[281773.594129] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 256 limit=0
[281773.594373] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 1 limit=0
[281773.598316] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10502184, nr_sectors = 2048 limit=0
[281773.598345] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10504232, nr_sectors = 2048 limit=0
[281781.692859] bio_check_eod: 63 callbacks suppressed
[281781.692866] blkid: attempt to access beyond end of device
                sdl: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[281781.692884] blkid: attempt to access beyond end of device
                sdl: rw=0, sector=20971392, nr_sectors = 8 limit=0
[281781.692890] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281781.702395] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[281781.702410] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[281781.702540] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2048, sector=4096, nr_sectors = 1 limit=0
[281781.702994] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[281781.703525] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 256 limit=0
[281781.703840] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 1 limit=0
[281781.708961] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10491944, nr_sectors = 2048 limit=0
[281781.708990] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10496040, nr_sectors = 2048 limit=0
[281785.385529] eth0: renamed from tmp94819
[281795.388446] eth0: renamed from tmpae1df
[281797.820564] bio_check_eod: 63 callbacks suppressed
[281797.820571] blkid: attempt to access beyond end of device
                sdl: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[281797.820590] blkid: attempt to access beyond end of device
                sdl: rw=0, sector=20971392, nr_sectors = 8 limit=0
[281797.820596] Buffer I/O error on dev dm-7, logical block 2620912, async page read
[281797.829756] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[281797.829801] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[281797.829929] mkfs.xfs: attempt to access beyond end of device
                sdl: rw=2048, sector=4096, nr_sectors = 1 limit=0
[281797.830381] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[281797.830856] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 256 limit=0
[281797.831089] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=34817, sector=4096, nr_sectors = 1 limit=0
[281797.833340] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10487848, nr_sectors = 2048 limit=0
[281797.834339] dmcrypt_write/2: attempt to access beyond end of device
                sdl: rw=1, sector=10493992, nr_sectors = 2048 limit=0

We mounted the volume on another non-k8s host and opened it with cryptsetup:

fdisk -l
Disk /dev/sdc: 10 GiB, 10737418240 bytes, 20971520 sectors
Disk model: Volume          
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
xfs_repair -n /dev/mapper/volume-debugging
Phase 1 - find and verify superblock...
Phase 2 - using internal log
        - zero log...
        - scan filesystem freespace and inode maps...
        - found root inode chunk
Phase 3 - for each AG...
        - scan (but don't clear) agi unlinked lists...
        - process known inodes and perform inode discovery...
        - agno = 0
        - agno = 1
        - agno = 2
        - agno = 3
        - process newly discovered inodes...
Phase 4 - check for duplicate blocks...
        - setting up duplicate extent list...
        - check for inodes claiming duplicate blocks...
        - agno = 2
        - agno = 0
        - agno = 1
        - agno = 3
No modify flag set, skipping phase 5
Phase 6 - check inode connectivity...
        - traversing filesystem ...
        - traversal finished ...
        - moving disconnected inodes to lost+found ...
Phase 7 - verify link counts...
No modify flag set, skipping filesystem flush and exiting.

bheisig avatar Apr 28 '25 07:04 bheisig

Found a similar issue with longhorn: https://github.com/longhorn/longhorn/issues/8604

jooola avatar Apr 29 '25 12:04 jooola

Hey,

We have tried to investigate this issue further and also started discussions with internal teams. So far we could still not reproduce the issue, which makes it quite tough to debug.

Could you maybe provide some details on the history of the affected volumes? Did you do any major upgrades (dist-upgrade) since the day you created them. Did you ever monitor some outages of the underlying hosts?

Could you possibly provide some logs from before and after the reboot on the node where the affected volume is currently scheduled?

Are their details of the CSI-Driver configuration (e.g. Helm values), which you could provide?

If the data in question is non-critical and its loss would not affect you or your organization, you could try using tools like xfs_repair or fsck to repair the filesystem.

Discussions with internal teams are also ongoing, I might come back with some more details, if we have any substantial finding.

I sincerely apologize for the inconvenience caused.

Best Regards, Lukas

lukasmetzner avatar Apr 29 '25 15:04 lukasmetzner

Thank you for your time and effort! We really appreciate it :)

Here is some more context.

We see this issue on k8s clusters which are > 1 year old. They receive k8s updates regularly. We don't perform dist updates/upgrades on running worker nodes. During any k8s update we replace worker nodes with new ones. New ones base on a re-freshed OS image using Packer. This image includes latest updates.

The issue started at the end of last year on k8s 1.30/Ubuntu 22.04. Meanwhile we upgraded to k8s 1.31. For testing purposes we did a dist upgrade to Ubuntu 24.04 using Packer. The issue remains the same on all different version states.

Yes, of course, we do monitor our worker nodes and k8s objects. For example, on a recently created worker node we don't see any outtages before the issue occurs.

The "age" of a volume doesn't matter. We also see this issue on recently created volumes.

Here some details when we reproduce the issue. We force a pod incl. volume to move from one worker node to another one. The volume is in a failed state.

dmesg on cordoned worker node
[432747.184786] XFS (dm-0): Unmounting Filesystem 28364769-9736-41a3-a1a5-7b636d627f44
[432750.243285] sd 0:0:0:1: [sdc] Synchronizing SCSI cache
[432750.243434] sd 0:0:0:1: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[432750.243648] sd 0:0:0:1: [sdc] Synchronize Cache(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[432750.243653] sd 0:0:0:1: [sdc] Sense Key : Illegal Request [current] 
[432750.243657] sd 0:0:0:1: [sdc] Add. Sense: Logical unit not supported
journal on cordoned worker node
Apr 30 09:02:46 k8s-worker-17792006bfef6207 kernel: sd 0:0:0:1: [sdc] Synchronizing SCSI cache
Apr 30 09:02:46 k8s-worker-17792006bfef6207 kernel: sd 0:0:0:1: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
Apr 30 09:02:46 k8s-worker-17792006bfef6207 kernel: sd 0:0:0:1: [sdc] Synchronize Cache(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
Apr 30 09:02:46 k8s-worker-17792006bfef6207 kernel: sd 0:0:0:1: [sdc] Sense Key : Illegal Request [current] 
Apr 30 09:02:46 k8s-worker-17792006bfef6207 kernel: sd 0:0:0:1: [sdc] Add. Sense: Logical unit not supported
dmesg on affected worker node
[434290.446936] XFS (dm-1): Unmounting Filesystem 28364769-9736-41a3-a1a5-7b636d627f44
[434297.158331] sd 0:0:0:0: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[434297.185533] sd 0:0:0:2: [sdb] Synchronizing SCSI cache
[434297.185843] sd 0:0:0:2: [sdb] Synchronize Cache(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[434297.185851] sd 0:0:0:2: [sdb] Sense Key : Illegal Request [current] 
[434297.185856] sd 0:0:0:2: [sdb] Add. Sense: Logical unit not supported
[434504.235840] eth0: renamed from tmp53795
[434512.429610] eth0: renamed from tmp4e102
[434531.659163] scsi 0:0:0:2: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[434531.659270] sd 0:0:0:0: LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.
[434531.664776] sd 0:0:0:2: Attached scsi generic sg2 type 0
[434531.665091] sd 0:0:0:2: Power-on or device reset occurred
[434531.665467] sd 0:0:0:2: [sdp] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[434531.665593] sd 0:0:0:2: [sdp] Write Protect is off
[434531.665601] sd 0:0:0:2: [sdp] Mode Sense: 63 00 00 08
[434531.665815] sd 0:0:0:2: [sdp] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[434531.670667] sd 0:0:0:2: [sdp] Attached SCSI disk
[434535.152180] blkid: attempt to access beyond end of device
                sdb: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[434535.152204] blkid: attempt to access beyond end of device
                sdb: rw=0, sector=20971392, nr_sectors = 8 limit=0
[434535.152210] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434535.159992] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[434535.160008] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[434535.160126] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
[434535.160625] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[434535.161594] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
[434535.161787] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
[434535.164956] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10491944, nr_sectors = 2048 limit=0
[434535.165269] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10496040, nr_sectors = 2048 limit=0
[434535.741199] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434536.858467] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434538.975063] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434543.118652] bio_check_eod: 282 callbacks suppressed
[434543.118660] blkid: attempt to access beyond end of device
                sdb: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[434543.118680] blkid: attempt to access beyond end of device
                sdb: rw=0, sector=20971392, nr_sectors = 8 limit=0
[434543.118686] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434543.125821] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[434543.125856] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[434543.125977] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
[434543.126507] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[434543.126908] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
[434543.127102] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
[434543.131028] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10487848, nr_sectors = 2048 limit=0
[434543.134310] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10489896, nr_sectors = 2048 limit=0
[434550.573555] eth0: renamed from tmp81b05
[434551.296084] bio_check_eod: 63 callbacks suppressed
[434551.296094] blkid: attempt to access beyond end of device
                sdb: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[434551.296120] blkid: attempt to access beyond end of device
                sdb: rw=0, sector=20971392, nr_sectors = 8 limit=0
[434551.296128] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434551.304661] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[434551.304677] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[434551.304801] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
[434551.305312] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[434551.305724] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
[434551.306025] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
[434551.312277] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10487848, nr_sectors = 2048 limit=0
[434551.312301] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10489896, nr_sectors = 2048 limit=0
[434567.466202] bio_check_eod: 63 callbacks suppressed
[434567.466210] blkid: attempt to access beyond end of device
                sdb: rw=524288, sector=20971392, nr_sectors = 8 limit=0
[434567.466231] blkid: attempt to access beyond end of device
                sdb: rw=0, sector=20971392, nr_sectors = 8 limit=0
[434567.466237] Buffer I/O error on dev dm-1, logical block 2620912, async page read
[434567.473658] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
[434567.473673] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
[434567.473759] mkfs.xfs: attempt to access beyond end of device
                sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
[434567.474148] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=20971264, nr_sectors = 256 limit=0
[434567.474661] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
[434567.474947] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
[434567.478668] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10498088, nr_sectors = 2048 limit=0
[434567.482262] dmcrypt_write/2: attempt to access beyond end of device
                sdb: rw=1, sector=10487848, nr_sectors = 2048 limit=0
journal on affected worker node
Apr 30 09:03:33 k8s-worker-78818640c23fdbc kubelet[1469]: I0430 09:03:33.994387    1469 operation_generator.go:538] "MountVolume.WaitForAttach entering for volume \"pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^102191764\") pod \"db-5ff58dd4b5-zzlfw\" (UID: \"b8cb7e2d-cfab-40af-8f40-5343b3ddc4f0\") DevicePath \"csi-344bd85accec1c164efd9c899338ed4abff0856aa9452ebbd1f4ddb2c3ca6c78\"" pod="example/db-5ff58dd4b5-zzlfw"
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: I0430 09:03:34.003380    1469 operation_generator.go:548] "MountVolume.WaitForAttach succeeded for volume \"pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17\" (UniqueName: \"kubernetes.io/csi/csi.hetzner.cloud^102191764\") pod \"db-5ff58dd4b5-zzlfw\" (UID: \"b8cb7e2d-cfab-40af-8f40-5343b3ddc4f0\") DevicePath \"csi-344bd85accec1c164efd9c899338ed4abff0856aa9452ebbd1f4ddb2c3ca6c78\"" pod="example/db-5ff58dd4b5-zzlfw"
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: bio_check_eod: 63 callbacks suppressed
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: blkid: attempt to access beyond end of device
                                                   sdb: rw=524288, sector=20971392, nr_sectors = 8 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: blkid: attempt to access beyond end of device
                                                   sdb: rw=0, sector=20971392, nr_sectors = 8 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: Buffer I/O error on dev dm-1, logical block 2620912, async page read
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: mkfs.xfs: attempt to access beyond end of device
                                                   sdb: rw=18435, sector=4096, nr_sectors = 2097152 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: mkfs.xfs: attempt to access beyond end of device
                                                   sdb: rw=2051, sector=2101248, nr_sectors = 2097152 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: mkfs.xfs: attempt to access beyond end of device
                                                   sdb: rw=2048, sector=4096, nr_sectors = 1 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                   sdb: rw=34817, sector=20971264, nr_sectors = 256 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                   sdb: rw=34817, sector=4096, nr_sectors = 256 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                   sdb: rw=34817, sector=4096, nr_sectors = 1 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                   sdb: rw=1, sector=10498088, nr_sectors = 2048 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kernel: dmcrypt_write/2: attempt to access beyond end of device
                                                   sdb: rw=1, sector=10487848, nr_sectors = 2048 limit=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: E0430 09:03:34.079300    1469 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/csi/csi.hetzner.cloud^102191764 podName: nodeName:}" failed. No retries permitted until 2025-04-30 09:04:06.079260711 +0000 UTC m=+434467.226618858 (durationBeforeRetry 32s). Error: MountVolume.SetUp failed for volume "pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17" (UniqueName: "kubernetes.io/csi/csi.hetzner.cloud^102191764") pod "db-5ff58dd4b5-zzlfw" (UID: "b8cb7e2d-cfab-40af-8f40-5343b3ddc4f0") : rpc error: code = Internal desc = failed to publish volume: format of disk "/dev/mapper/scsi-0HC_Volume_102191764" failed: type:("xfs") target:("/var/lib/kubelet/pods/b8cb7e2d-cfab-40af-8f40-5343b3ddc4f0/volumes/kubernetes.io~csi/pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17/mount") options:("defaults") errcode:(exit status 1) output:(Parameters parsed from config file /usr/share/xfsprogs/mkfs/lts_4.19.conf successfully
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: error reading existing superblock: I/O error
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: pwrite failed: I/O error
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: libxfs_bwrite: write failed on (unknown) bno 0x13fef00/0x100, err=5
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: found dirty buffer (bulk) on free list!
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: pwrite failed: I/O error
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: libxfs_bwrite: write failed on (unknown) bno 0x0/0x100, err=5
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: found dirty buffer (bulk) on free list!
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: pwrite failed: I/O error
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: libxfs_bwrite: write failed on xfs_sb bno 0x0/0x1, err=5
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: Releasing dirty buffer to free list!
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: mkfs.xfs: libxfs_device_zero write failed: I/O error
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: meta-data=/dev/mapper/scsi-0HC_Volume_102191764 isize=512    agcount=4, agsize=655232 blks
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       sectsz=512   attr=2, projid32bit=1
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       crc=1        finobt=1, sparse=1, rmapbt=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       reflink=0    bigtime=0 inobtcount=0 nrext64=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       exchange=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: data     =                       bsize=4096   blocks=2620928, imaxpct=25
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       sunit=0      swidth=0 blks
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: naming   =version 2              bsize=4096   ascii-ci=0, ftype=1, parent=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: log      =internal log           bsize=4096   blocks=16384, version=2
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]:          =                       sectsz=512   sunit=0 blks, lazy-count=1
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: realtime =none                   extsz=4096   blocks=0, rtextents=0
Apr 30 09:03:34 k8s-worker-78818640c23fdbc kubelet[1469]: )

During a failed state we can manually decrypt and mount the volume on the worker node. The XFS filesystem is not corrupted.

dmesg after rebooting the affected worker node
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-6.8.0-58-generic root=UUID=f184a16b-6eca-41cb-b48a-ff37cdce1d79 ro consoleblank=0 systemd.show_status=true console=tty1 console=ttyS0
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Hygon HygonGenuine
[    0.000000]   Centaur CentaurHauls
[    0.000000]   zhaoxin   Shanghai  
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007ffdbfff] usable
[    0.000000] BIOS-e820: [mem 0x000000007ffdc000-0x000000007fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fed1c000-0x00000000fed1ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000084fffffff] usable
[    0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] APIC: Static calls initialized
[    0.000000] SMBIOS 3.0.0 present.
[    0.000000] DMI: Hetzner vServer/Standard PC (Q35 + ICH9, 2009), BIOS 20171111 11/11/2017
[    0.000000] Hypervisor detected: KVM
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: using sched offset of 436648859113869 cycles
[    0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000005] tsc: Detected 2495.312 MHz processor
[    0.001217] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.001221] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.001227] last_pfn = 0x850000 max_arch_pfn = 0x400000000
[    0.001267] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
[    0.001271] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.001324] last_pfn = 0x7ffdc max_arch_pfn = 0x400000000
[    0.003671] found SMP MP-table at [mem 0x000f5470-0x000f547f]
[    0.003686] Using GB pages for direct mapping
[    0.003930] RAMDISK: [mem 0x34cfb000-0x36674fff]
[    0.004066] ACPI: Early table checksum verification disabled
[    0.004070] ACPI: RSDP 0x00000000000F5220 000014 (v00 BOCHS )
[    0.004083] ACPI: RSDT 0x000000007FFE2BAB 000038 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004088] ACPI: FACP 0x000000007FFE292B 0000F4 (v03 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004094] ACPI: DSDT 0x000000007FFE0040 0028EB (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004097] ACPI: FACS 0x000000007FFE0000 000040
[    0.004100] ACPI: APIC 0x000000007FFE2A1F 0000F0 (v03 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004103] ACPI: HPET 0x000000007FFE2B0F 000038 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004105] ACPI: MCFG 0x000000007FFE2B47 00003C (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004108] ACPI: WAET 0x000000007FFE2B83 000028 (v01 BOCHS  BXPC     00000001 BXPC 00000001)
[    0.004111] ACPI: Reserving FACP table memory at [mem 0x7ffe292b-0x7ffe2a1e]
[    0.004112] ACPI: Reserving DSDT table memory at [mem 0x7ffe0040-0x7ffe292a]
[    0.004113] ACPI: Reserving FACS table memory at [mem 0x7ffe0000-0x7ffe003f]
[    0.004114] ACPI: Reserving APIC table memory at [mem 0x7ffe2a1f-0x7ffe2b0e]
[    0.004115] ACPI: Reserving HPET table memory at [mem 0x7ffe2b0f-0x7ffe2b46]
[    0.004116] ACPI: Reserving MCFG table memory at [mem 0x7ffe2b47-0x7ffe2b82]
[    0.004117] ACPI: Reserving WAET table memory at [mem 0x7ffe2b83-0x7ffe2baa]
[    0.004485] No NUMA configuration found
[    0.004486] Faking a node at [mem 0x0000000000000000-0x000000084fffffff]
[    0.004495] NODE_DATA(0) allocated [mem 0x84ffd5000-0x84fffffff]
[    0.004707] Zone ranges:
[    0.004708]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.004710]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.004711]   Normal   [mem 0x0000000100000000-0x000000084fffffff]
[    0.004713]   Device   empty
[    0.004714] Movable zone start for each node
[    0.004716] Early memory node ranges
[    0.004717]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.004718]   node   0: [mem 0x0000000000100000-0x000000007ffdbfff]
[    0.004719]   node   0: [mem 0x0000000100000000-0x000000084fffffff]
[    0.004723] Initmem setup node 0 [mem 0x0000000000001000-0x000000084fffffff]
[    0.004731] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.004753] On node 0, zone DMA: 97 pages in unavailable ranges
[    0.045662] On node 0, zone Normal: 36 pages in unavailable ranges
[    0.046702] ACPI: PM-Timer IO Port: 0x608
[    0.046717] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.046750] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.046753] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.046755] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.046757] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.046758] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.046759] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.046763] ACPI: Using ACPI (MADT) for SMP configuration information
[    0.046764] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.046769] smpboot: Allowing 16 CPUs, 0 hotplug CPUs
[    0.046788] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
[    0.046808] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.046810] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[    0.046811] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000effff]
[    0.046811] PM: hibernation: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[    0.046813] PM: hibernation: Registered nosave memory: [mem 0x7ffdc000-0x7fffffff]
[    0.046814] PM: hibernation: Registered nosave memory: [mem 0x80000000-0xafffffff]
[    0.046815] PM: hibernation: Registered nosave memory: [mem 0xb0000000-0xbfffffff]
[    0.046815] PM: hibernation: Registered nosave memory: [mem 0xc0000000-0xfed1bfff]
[    0.046816] PM: hibernation: Registered nosave memory: [mem 0xfed1c000-0xfed1ffff]
[    0.046817] PM: hibernation: Registered nosave memory: [mem 0xfed20000-0xfeffbfff]
[    0.046818] PM: hibernation: Registered nosave memory: [mem 0xfeffc000-0xfeffffff]
[    0.046818] PM: hibernation: Registered nosave memory: [mem 0xff000000-0xfffbffff]
[    0.046819] PM: hibernation: Registered nosave memory: [mem 0xfffc0000-0xffffffff]
[    0.046821] [mem 0xc0000000-0xfed1bfff] available for PCI devices
[    0.046823] Booting paravirtualized kernel on KVM
[    0.046825] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.046833] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:16 nr_cpu_ids:16 nr_node_ids:1
[    0.047645] percpu: Embedded 86 pages/cpu s229376 r8192 d114688 u524288
[    0.047650] pcpu-alloc: s229376 r8192 d114688 u524288 alloc=1*2097152
[    0.047652] pcpu-alloc: [0] 00 01 02 03 [0] 04 05 06 07 
[    0.047658] pcpu-alloc: [0] 08 09 10 11 [0] 12 13 14 15 
[    0.047686] kvm-guest: PV spinlocks disabled, no host support
[    0.047687] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-6.8.0-58-generic root=UUID=f184a16b-6eca-41cb-b48a-ff37cdce1d79 ro consoleblank=0 systemd.show_status=true console=tty1 console=ttyS0
[    0.047771] Unknown kernel command line parameters "BOOT_IMAGE=/boot/vmlinuz-6.8.0-58-generic", will be passed to user space.
[    0.047793] random: crng init done
[    0.050284] Dentry cache hash table entries: 4194304 (order: 13, 33554432 bytes, linear)
[    0.051529] Inode-cache hash table entries: 2097152 (order: 12, 16777216 bytes, linear)
[    0.051640] Fallback order for Node 0: 0 
[    0.051646] Built 1 zonelists, mobility grouping on.  Total pages: 8063708
[    0.051648] Policy zone: Normal
[    0.051656] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
[    0.051662] software IO TLB: area num 16.
[    0.116967] Memory: 32053848K/32767464K available (22528K kernel code, 4438K rwdata, 14368K rodata, 4992K init, 4720K bss, 713356K reserved, 0K cma-reserved)
[    0.117987] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
[    0.118014] ftrace: allocating 58152 entries in 228 pages
[    0.129602] ftrace: allocated 228 pages with 4 groups
[    0.130498] Dynamic Preempt: voluntary
[    0.130606] rcu: Preemptible hierarchical RCU implementation.
[    0.130607] rcu: 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=16.
[    0.130608] 	Trampoline variant of Tasks RCU enabled.
[    0.130609] 	Rude variant of Tasks RCU enabled.
[    0.130610] 	Tracing variant of Tasks RCU enabled.
[    0.130610] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[    0.130611] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=16
[    0.133439] NR_IRQS: 524544, nr_irqs: 552, preallocated irqs: 16
[    0.133669] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.144777] Console: colour VGA+ 80x25
[    0.144781] printk: legacy console [tty1] enabled
[    0.188753] printk: legacy console [ttyS0] enabled
[    0.302908] ACPI: Core revision 20230628
[    0.303893] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.305768] APIC: Switch to symmetric I/O mode setup
[    0.307097] x2apic enabled
[    0.308087] APIC: Switched APIC routing to: physical x2apic
[    0.310458] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.312108] tsc: Marking TSC unstable due to TSCs unsynchronized
[    0.313730] Calibrating delay loop (skipped) preset value.. 4990.62 BogoMIPS (lpj=2495312)
[    0.315833] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[    0.317813] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
[    0.319039] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
[    0.320071] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.321730] Spectre V2 : Mitigation: Retpolines
[    0.322728] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.324728] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
[    0.325728] Spectre V2 : Enabling Speculation Barrier for firmware calls
[    0.327728] RETBleed: Mitigation: untrained return thunk
[    0.328731] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.329729] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[    0.330743] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.331728] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.332728] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.333728] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.335728] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format.
[    0.364203] Freeing SMP alternatives memory: 48K
[    0.365021] pid_max: default: 32768 minimum: 301
[    0.365805] LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,integrity
[    0.366740] landlock: Up and running.
[    0.367982] Yama: becoming mindful.
[    0.368779] AppArmor: AppArmor initialized
[    0.370103] Mount-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.371761] Mountpoint-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.476189] smpboot: CPU0: AMD EPYC-Rome Processor (family: 0x17, model: 0x31, stepping: 0x0)
[    0.477937] RCU Tasks: Setting shift to 4 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[    0.479220] RCU Tasks Rude: Setting shift to 4 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[    0.480222] RCU Tasks Trace: Setting shift to 4 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[    0.481741] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
[    0.483049] ... version:                0
[    0.483986] ... bit width:              48
[    0.485727] ... generic registers:      6
[    0.486728] ... value mask:             0000ffffffffffff
[    0.488016] ... max period:             00007fffffffffff
[    0.489018] ... fixed-purpose events:   0
[    0.489981] ... event mask:             000000000000003f
[    0.491815] signal: max sigframe size: 1776
[    0.493036] rcu: Hierarchical SRCU implementation.
[    0.494001] rcu: 	Max phase no-delay instances is 400.
[    0.498594] smp: Bringing up secondary CPUs ...
[    0.499841] smpboot: x86: Booting SMP configuration:
[    0.501032] .... node  #0, CPUs:        #1  #2  #3  #4  #5  #6  #7  #8  #9 #10 #11 #12 #13 #14 #15
[    0.515867] smp: Brought up 1 node, 16 CPUs
[    0.519022] smpboot: Max logical packages: 1
[    0.520011] smpboot: Total of 16 processors activated (79849.98 BogoMIPS)
[    0.525096] devtmpfs: initialized
[    0.526041] x86/mm: Memory block size: 128MB
[    0.529815] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.531251] futex hash table entries: 4096 (order: 6, 262144 bytes, linear)
[    0.532138] pinctrl core: initialized pinctrl subsystem
[    0.533165] PM: RTC time: 09:38:14, date: 2025-04-30
[    0.535474] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.536407] DMA: preallocated 4096 KiB GFP_KERNEL pool for atomic allocations
[    0.537326] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.538840] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.540750] audit: initializing netlink subsys (disabled)
[    0.542051] audit: type=2000 audit(1746005894.328:1): state=initialized audit_enabled=0 res=1
[    0.542767] thermal_sys: Registered thermal governor 'fair_share'
[    0.544728] thermal_sys: Registered thermal governor 'bang_bang'
[    0.546046] thermal_sys: Registered thermal governor 'step_wise'
[    0.547036] thermal_sys: Registered thermal governor 'user_space'
[    0.548070] thermal_sys: Registered thermal governor 'power_allocator'
[    0.549047] EISA bus registered
[    0.551729] cpuidle: using governor ladder
[    0.552735] cpuidle: using governor menu
[    0.554805] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.556876] PCI: ECAM [mem 0xb0000000-0xbfffffff] (base 0xb0000000) for domain 0000 [bus 00-ff]
[    0.558207] PCI: Using configuration type 1 for base access
[    0.559905] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
[    0.562839] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[    0.564051] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
[    0.565044] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[    0.566727] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
[    0.568830] ACPI: Added _OSI(Module Device)
[    0.569989] ACPI: Added _OSI(Processor Device)
[    0.570996] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.572008] ACPI: Added _OSI(Processor Aggregator Device)
[    0.574709] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.575858] ACPI: _OSC evaluation for CPUs failed, trying _PDC
[    0.577207] ACPI: Interpreter enabled
[    0.577990] ACPI: PM: (supports S0 S5)
[    0.578985] ACPI: Using IOAPIC for interrupt routing
[    0.580859] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.582219] PCI: Using E820 reservations for host bridge windows
[    0.583871] ACPI: Enabled 2 GPEs in block 00 to 3F
[    0.588543] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.589069] acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI EDR HPX-Type3]
[    0.590284] acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR DPC]
[    0.591740] acpi PNP0A08:00: _OSC: OS now controls [SHPCHotplug PME AER PCIeCapability]
[    0.594009] PCI host bridge to bus 0000:00
[    0.594998] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.596728] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.598060] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.599184] pci_bus 0000:00: root bus resource [mem 0x80000000-0xafffffff window]
[    0.600195] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window]
[    0.601181] pci_bus 0000:00: root bus resource [mem 0xc000000000-0xc7ffffffff window]
[    0.602729] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.604114] pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 conventional PCI endpoint
[    0.605958] pci 0000:00:01.0: [1af4:1050] type 00 class 0x030000 conventional PCI endpoint
[    0.610745] pci 0000:00:01.0: BAR 0 [mem 0xfd000000-0xfd7fffff pref]
[    0.612748] pci 0000:00:01.0: BAR 2 [mem 0xc120000000-0xc120003fff 64bit pref]
[    0.614735] pci 0000:00:01.0: BAR 4 [mem 0xfea10000-0xfea10fff]
[    0.616054] pci 0000:00:01.0: ROM [mem 0xfea00000-0xfea0ffff pref]
[    0.617776] pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    0.620315] pci 0000:00:02.0: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.624736] pci 0000:00:02.0: BAR 0 [mem 0xfea11000-0xfea11fff]
[    0.626056] pci 0000:00:02.0: PCI bridge to [bus 01]
[    0.627041] pci 0000:00:02.0:   bridge window [mem 0xfe800000-0xfe9fffff]
[    0.629259] pci 0000:00:02.0:   bridge window [mem 0xc100000000-0xc11fffffff 64bit pref]
[    0.631350] pci 0000:00:02.1: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.633736] pci 0000:00:02.1: BAR 0 [mem 0xfea12000-0xfea12fff]
[    0.635748] pci 0000:00:02.1: PCI bridge to [bus 02]
[    0.637760] pci 0000:00:02.1:   bridge window [mem 0xfe600000-0xfe7fffff]
[    0.639968] pci 0000:00:02.1:   bridge window [mem 0xc0e0000000-0xc0ffffffff 64bit pref]
[    0.641949] pci 0000:00:02.2: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.645238] pci 0000:00:02.2: BAR 0 [mem 0xfea13000-0xfea13fff]
[    0.646749] pci 0000:00:02.2: PCI bridge to [bus 03]
[    0.648760] pci 0000:00:02.2:   bridge window [mem 0xfe400000-0xfe5fffff]
[    0.650960] pci 0000:00:02.2:   bridge window [mem 0xc0c0000000-0xc0dfffffff 64bit pref]
[    0.652949] pci 0000:00:02.3: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.656262] pci 0000:00:02.3: BAR 0 [mem 0xfea14000-0xfea14fff]
[    0.657066] pci 0000:00:02.3: PCI bridge to [bus 04]
[    0.658761] pci 0000:00:02.3:   bridge window [mem 0xfe200000-0xfe3fffff]
[    0.660965] pci 0000:00:02.3:   bridge window [mem 0xc0a0000000-0xc0bfffffff 64bit pref]
[    0.663848] pci 0000:00:02.4: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.666735] pci 0000:00:02.4: BAR 0 [mem 0xfea15000-0xfea15fff]
[    0.668052] pci 0000:00:02.4: PCI bridge to [bus 05]
[    0.669760] pci 0000:00:02.4:   bridge window [mem 0xfe000000-0xfe1fffff]
[    0.672116] pci 0000:00:02.4:   bridge window [mem 0xc080000000-0xc09fffffff 64bit pref]
[    0.674061] pci 0000:00:02.5: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.677737] pci 0000:00:02.5: BAR 0 [mem 0xfea16000-0xfea16fff]
[    0.679056] pci 0000:00:02.5: PCI bridge to [bus 06]
[    0.680760] pci 0000:00:02.5:   bridge window [mem 0xfde00000-0xfdffffff]
[    0.683756] pci 0000:00:02.5:   bridge window [mem 0xc060000000-0xc07fffffff 64bit pref]
[    0.686439] pci 0000:00:02.6: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.689736] pci 0000:00:02.6: BAR 0 [mem 0xfea17000-0xfea17fff]
[    0.691748] pci 0000:00:02.6: PCI bridge to [bus 07]
[    0.693041] pci 0000:00:02.6:   bridge window [mem 0xfdc00000-0xfddfffff]
[    0.695211] pci 0000:00:02.6:   bridge window [mem 0xc040000000-0xc05fffffff 64bit pref]
[    0.697143] pci 0000:00:02.7: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.700288] pci 0000:00:02.7: BAR 0 [mem 0xfea18000-0xfea18fff]
[    0.701057] pci 0000:00:02.7: PCI bridge to [bus 08]
[    0.702043] pci 0000:00:02.7:   bridge window [mem 0xfda00000-0xfdbfffff]
[    0.703523] pci 0000:00:02.7:   bridge window [mem 0xc020000000-0xc03fffffff 64bit pref]
[    0.705300] pci 0000:00:03.0: [1b36:000c] type 01 class 0x060400 PCIe Root Port
[    0.707216] pci 0000:00:03.0: BAR 0 [mem 0xfea19000-0xfea19fff]
[    0.708052] pci 0000:00:03.0: PCI bridge to [bus 09]
[    0.709037] pci 0000:00:03.0:   bridge window [mem 0xfd800000-0xfd9fffff]
[    0.710581] pci 0000:00:03.0:   bridge window [mem 0xc000000000-0xc01fffffff 64bit pref]
[    0.719735] pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 conventional PCI endpoint
[    0.722092] pci 0000:00:1f.0: quirk: [io  0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO
[    0.723400] pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 conventional PCI endpoint
[    0.725761] pci 0000:00:1f.2: BAR 4 [io  0xc040-0xc05f]
[    0.727024] pci 0000:00:1f.2: BAR 5 [mem 0xfea1a000-0xfea1afff]
[    0.728982] pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 conventional PCI endpoint
[    0.731747] pci 0000:00:1f.3: BAR 4 [io  0x0700-0x073f]
[    0.733862] pci 0000:00:02.0: PCI bridge to [bus 01]
[    0.735853] pci 0000:02:00.0: [1b36:000d] type 00 class 0x0c0330 PCIe Endpoint
[    0.738478] pci 0000:02:00.0: BAR 0 [mem 0xfe600000-0xfe603fff 64bit]
[    0.740782] pci 0000:00:02.1: PCI bridge to [bus 02]
[    0.742833] pci 0000:03:00.0: [1af4:1043] type 00 class 0x078000 PCIe Endpoint
[    0.745742] pci 0000:03:00.0: BAR 1 [mem 0xfe400000-0xfe400fff]
[    0.747061] pci 0000:03:00.0: BAR 4 [mem 0xc0c0000000-0xc0c0003fff 64bit pref]
[    0.749092] pci 0000:00:02.2: PCI bridge to [bus 03]
[    0.750991] pci 0000:04:00.0: [1af4:1045] type 00 class 0x00ff00 PCIe Endpoint
[    0.753754] pci 0000:04:00.0: BAR 4 [mem 0xc0a0000000-0xc0a0003fff 64bit pref]
[    0.756514] pci 0000:00:02.3: PCI bridge to [bus 04]
[    0.758524] pci 0000:05:00.0: [1af4:1044] type 00 class 0x00ff00 PCIe Endpoint
[    0.760277] pci 0000:05:00.0: BAR 1 [mem 0xfe000000-0xfe000fff]
[    0.761061] pci 0000:05:00.0: BAR 4 [mem 0xc080000000-0xc080003fff 64bit pref]
[    0.763962] pci 0000:00:02.4: PCI bridge to [bus 05]
[    0.765995] pci 0000:06:00.0: [1af4:1048] type 00 class 0x010000 PCIe Endpoint
[    0.769743] pci 0000:06:00.0: BAR 1 [mem 0xfde00000-0xfde00fff]
[    0.771060] pci 0000:06:00.0: BAR 4 [mem 0xc060000000-0xc060003fff 64bit pref]
[    0.773909] pci 0000:00:02.5: PCI bridge to [bus 06]
[    0.775818] acpiphp: Slot [0] registered
[    0.776882] pci 0000:07:00.0: [1af4:1041] type 00 class 0x020000 PCIe Endpoint
[    0.780122] pci 0000:07:00.0: BAR 1 [mem 0xfdc80000-0xfdc80fff]
[    0.781069] pci 0000:07:00.0: BAR 4 [mem 0xc040000000-0xc040003fff 64bit pref]
[    0.782166] pci 0000:07:00.0: ROM [mem 0xfdc00000-0xfdc7ffff pref]
[    0.784536] pci 0000:00:02.6: PCI bridge to [bus 07]
[    0.787113] acpiphp: Slot [0-2] registered
[    0.788729] pci 0000:00:02.7: PCI bridge to [bus 08]
[    0.790361] acpiphp: Slot [0-3] registered
[    0.791982] pci 0000:00:03.0: PCI bridge to [bus 09]
[    0.798797] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
[    0.800128] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
[    0.801807] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
[    0.803122] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
[    0.804109] ACPI: PCI: Interrupt link LNKE configured for IRQ 10
[    0.805809] ACPI: PCI: Interrupt link LNKF configured for IRQ 10
[    0.807123] ACPI: PCI: Interrupt link LNKG configured for IRQ 11
[    0.808112] ACPI: PCI: Interrupt link LNKH configured for IRQ 11
[    0.809747] ACPI: PCI: Interrupt link GSIA configured for IRQ 16
[    0.811040] ACPI: PCI: Interrupt link GSIB configured for IRQ 17
[    0.812736] ACPI: PCI: Interrupt link GSIC configured for IRQ 18
[    0.814040] ACPI: PCI: Interrupt link GSID configured for IRQ 19
[    0.815736] ACPI: PCI: Interrupt link GSIE configured for IRQ 20
[    0.817043] ACPI: PCI: Interrupt link GSIF configured for IRQ 21
[    0.818737] ACPI: PCI: Interrupt link GSIG configured for IRQ 22
[    0.820043] ACPI: PCI: Interrupt link GSIH configured for IRQ 23
[    0.822757] iommu: Default domain type: Translated
[    0.824021] iommu: DMA domain TLB invalidation policy: lazy mode
[    0.825767] SCSI subsystem initialized
[    0.826762] libata version 3.00 loaded.
[    0.826774] ACPI: bus type USB registered
[    0.827998] usbcore: registered new interface driver usbfs
[    0.829023] usbcore: registered new interface driver hub
[    0.830737] usbcore: registered new device driver usb
[    0.832026] pps_core: LinuxPPS API ver. 1 registered
[    0.833009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
[    0.834215] PTP clock support registered
[    0.835757] EDAC MC: Ver: 3.0.0
[    0.837085] NetLabel: Initializing
[    0.837973] NetLabel:  domain hash size = 128
[    0.838996] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.840043] NetLabel:  unlabeled traffic allowed by default
[    0.841748] mctp: management component transport protocol core
[    0.843035] NET: Registered PF_MCTP protocol family
[    0.844020] PCI: Using ACPI for IRQ routing
[    0.959316] PCI: pci_cache_line_size set to 64 bytes
[    0.959613] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[    0.959617] e820: reserve RAM buffer [mem 0x7ffdc000-0x7fffffff]
[    0.959759] pci 0000:00:01.0: vgaarb: setting as boot VGA device
[    0.960726] pci 0000:00:01.0: vgaarb: bridge control possible
[    0.960726] pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[    0.960733] vgaarb: loaded
[    0.961832] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[    0.963012] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[    0.970903] clocksource: Switched to clocksource kvm-clock
[    0.972509] VFS: Disk quotas dquot_6.6.0
[    0.973570] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.975413] AppArmor: AppArmor Filesystem Enabled
[    0.976649] pnp: PnP ACPI init
[    0.977674] system 00:04: [mem 0xb0000000-0xbfffffff window] has been reserved
[    0.979763] pnp: PnP ACPI: found 5 devices
[    0.990589] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.992862] NET: Registered PF_INET protocol family
[    0.994293] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    1.011653] tcp_listen_portaddr_hash hash table entries: 16384 (order: 6, 262144 bytes, linear)
[    1.013898] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    1.015949] TCP established hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    1.018388] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, linear)
[    1.020433] TCP: Hash tables configured (established 262144 bind 65536)
[    1.022319] MPTCP token hash table entries: 32768 (order: 7, 786432 bytes, linear)
[    1.024690] UDP hash table entries: 16384 (order: 7, 524288 bytes, linear)
[    1.026496] UDP-Lite hash table entries: 16384 (order: 7, 524288 bytes, linear)
[    1.028482] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    1.029912] NET: Registered PF_XDP protocol family
[    1.031171] pci 0000:00:02.6: bridge window [io  0x1000-0x0fff] to [bus 07] add_size 1000
[    1.033244] pci 0000:00:02.7: bridge window [io  0x1000-0x0fff] to [bus 08] add_size 1000
[    1.035333] pci 0000:00:03.0: bridge window [io  0x1000-0x0fff] to [bus 09] add_size 1000
[    1.037403] pci 0000:00:02.6: bridge window [io  0x1000-0x1fff]: assigned
[    1.039064] pci 0000:00:02.7: bridge window [io  0x2000-0x2fff]: assigned
[    1.040731] pci 0000:00:03.0: bridge window [io  0x3000-0x3fff]: assigned
[    1.042396] pci 0000:00:02.0: PCI bridge to [bus 01]
[    1.045407] pci 0000:00:02.0:   bridge window [mem 0xfe800000-0xfe9fffff]
[    1.048120] pci 0000:00:02.0:   bridge window [mem 0xc100000000-0xc11fffffff 64bit pref]
[    1.052500] pci 0000:00:02.1: PCI bridge to [bus 02]
[    1.055329] pci 0000:00:02.1:   bridge window [mem 0xfe600000-0xfe7fffff]
[    1.057944] pci 0000:00:02.1:   bridge window [mem 0xc0e0000000-0xc0ffffffff 64bit pref]
[    1.061141] pci 0000:00:02.2: PCI bridge to [bus 03]
[    1.063962] pci 0000:00:02.2:   bridge window [mem 0xfe400000-0xfe5fffff]
[    1.066762] pci 0000:00:02.2:   bridge window [mem 0xc0c0000000-0xc0dfffffff 64bit pref]
[    1.070791] pci 0000:00:02.3: PCI bridge to [bus 04]
[    1.072781] pci 0000:00:02.3:   bridge window [mem 0xfe200000-0xfe3fffff]
[    1.074983] pci 0000:00:02.3:   bridge window [mem 0xc0a0000000-0xc0bfffffff 64bit pref]
[    1.079771] pci 0000:00:02.4: PCI bridge to [bus 05]
[    1.081684] pci 0000:00:02.4:   bridge window [mem 0xfe000000-0xfe1fffff]
[    1.083775] pci 0000:00:02.4:   bridge window [mem 0xc080000000-0xc09fffffff 64bit pref]
[    1.086776] pci 0000:00:02.5: PCI bridge to [bus 06]
[    1.088999] pci 0000:00:02.5:   bridge window [mem 0xfde00000-0xfdffffff]
[    1.093366] pci 0000:00:02.5:   bridge window [mem 0xc060000000-0xc07fffffff 64bit pref]
[    1.097078] pci 0000:00:02.6: PCI bridge to [bus 07]
[    1.098362] pci 0000:00:02.6:   bridge window [io  0x1000-0x1fff]
[    1.100541] pci 0000:00:02.6:   bridge window [mem 0xfdc00000-0xfddfffff]
[    1.103694] pci 0000:00:02.6:   bridge window [mem 0xc040000000-0xc05fffffff 64bit pref]
[    1.106522] pci 0000:00:02.7: PCI bridge to [bus 08]
[    1.107804] pci 0000:00:02.7:   bridge window [io  0x2000-0x2fff]
[    1.109971] pci 0000:00:02.7:   bridge window [mem 0xfda00000-0xfdbfffff]
[    1.112088] pci 0000:00:02.7:   bridge window [mem 0xc020000000-0xc03fffffff 64bit pref]
[    1.115876] pci 0000:00:03.0: PCI bridge to [bus 09]
[    1.117182] pci 0000:00:03.0:   bridge window [io  0x3000-0x3fff]
[    1.119277] pci 0000:00:03.0:   bridge window [mem 0xfd800000-0xfd9fffff]
[    1.121339] pci 0000:00:03.0:   bridge window [mem 0xc000000000-0xc01fffffff 64bit pref]
[    1.125565] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    1.127110] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    1.128648] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    1.130340] pci_bus 0000:00: resource 7 [mem 0x80000000-0xafffffff window]
[    1.132005] pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window]
[    1.133677] pci_bus 0000:00: resource 9 [mem 0xc000000000-0xc7ffffffff window]
[    1.135515] pci_bus 0000:01: resource 1 [mem 0xfe800000-0xfe9fffff]
[    1.137065] pci_bus 0000:01: resource 2 [mem 0xc100000000-0xc11fffffff 64bit pref]
[    1.138984] pci_bus 0000:02: resource 1 [mem 0xfe600000-0xfe7fffff]
[    1.143808] pci_bus 0000:02: resource 2 [mem 0xc0e0000000-0xc0ffffffff 64bit pref]
[    1.145736] pci_bus 0000:03: resource 1 [mem 0xfe400000-0xfe5fffff]
[    1.147299] pci_bus 0000:03: resource 2 [mem 0xc0c0000000-0xc0dfffffff 64bit pref]
[    1.149247] pci_bus 0000:04: resource 1 [mem 0xfe200000-0xfe3fffff]
[    1.150784] pci_bus 0000:04: resource 2 [mem 0xc0a0000000-0xc0bfffffff 64bit pref]
[    1.152695] pci_bus 0000:05: resource 1 [mem 0xfe000000-0xfe1fffff]
[    1.154242] pci_bus 0000:05: resource 2 [mem 0xc080000000-0xc09fffffff 64bit pref]
[    1.156164] pci_bus 0000:06: resource 1 [mem 0xfde00000-0xfdffffff]
[    1.157698] pci_bus 0000:06: resource 2 [mem 0xc060000000-0xc07fffffff 64bit pref]
[    1.159608] pci_bus 0000:07: resource 0 [io  0x1000-0x1fff]
[    1.160993] pci_bus 0000:07: resource 1 [mem 0xfdc00000-0xfddfffff]
[    1.162531] pci_bus 0000:07: resource 2 [mem 0xc040000000-0xc05fffffff 64bit pref]
[    1.164450] pci_bus 0000:08: resource 0 [io  0x2000-0x2fff]
[    1.165842] pci_bus 0000:08: resource 1 [mem 0xfda00000-0xfdbfffff]
[    1.167381] pci_bus 0000:08: resource 2 [mem 0xc020000000-0xc03fffffff 64bit pref]
[    1.169302] pci_bus 0000:09: resource 0 [io  0x3000-0x3fff]
[    1.170688] pci_bus 0000:09: resource 1 [mem 0xfd800000-0xfd9fffff]
[    1.172244] pci_bus 0000:09: resource 2 [mem 0xc000000000-0xc01fffffff 64bit pref]
[    1.174626] ACPI: \_SB_.GSIG: Enabled at IRQ 22
[    1.177693] PCI: CLS 0 bytes, default 64
[    1.178875] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    1.179134] Trying to unpack rootfs image as initramfs...
[    1.180144] software IO TLB: mapped [mem 0x000000007bfdc000-0x000000007ffdc000] (64MB)
[    1.180835] Initialise system trusted keyrings
[    1.186547] Key type blacklist registered
[    1.187817] workingset: timestamp_bits=36 max_order=23 bucket_order=0
[    1.189416] zbud: loaded
[    1.190452] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    1.192229] fuse: init (API version 7.39)
[    1.193800] integrity: Platform Keyring initialized
[    1.195075] integrity: Machine keyring initialized
[    1.207700] Key type asymmetric registered
[    1.208776] Asymmetric key parser 'x509' registered
[    1.210028] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243)
[    1.212130] io scheduler mq-deadline registered
[    1.217827] pcieport 0000:00:02.0: PME: Signaling with IRQ 24
[    1.219596] pcieport 0000:00:02.0: AER: enabled with IRQ 24
[    1.221771] pcieport 0000:00:02.1: PME: Signaling with IRQ 25
[    1.223538] pcieport 0000:00:02.1: AER: enabled with IRQ 25
[    1.226349] pcieport 0000:00:02.2: PME: Signaling with IRQ 26
[    1.228954] pcieport 0000:00:02.2: AER: enabled with IRQ 26
[    1.231697] pcieport 0000:00:02.3: PME: Signaling with IRQ 27
[    1.233471] pcieport 0000:00:02.3: AER: enabled with IRQ 27
[    1.236195] pcieport 0000:00:02.4: PME: Signaling with IRQ 28
[    1.237980] pcieport 0000:00:02.4: AER: enabled with IRQ 28
[    1.240730] pcieport 0000:00:02.5: PME: Signaling with IRQ 29
[    1.242481] pcieport 0000:00:02.5: AER: enabled with IRQ 29
[    1.245257] pcieport 0000:00:02.6: PME: Signaling with IRQ 30
[    1.246995] pcieport 0000:00:02.6: AER: enabled with IRQ 30
[    1.250868] pcieport 0000:00:02.7: PME: Signaling with IRQ 31
[    1.252614] pcieport 0000:00:02.7: AER: enabled with IRQ 31
[    1.254475] ACPI: \_SB_.GSIH: Enabled at IRQ 23
[    1.256564] pcieport 0000:00:03.0: PME: Signaling with IRQ 32
[    1.258322] pcieport 0000:00:03.0: AER: enabled with IRQ 32
[    1.260891] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    1.262677] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    1.264626] ACPI: button: Power Button [PWRF]
[    1.266715] ACPI: \_SB_.GSIF: Enabled at IRQ 21
[    1.279768] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    1.307026] 00:00: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    1.309292] Freeing initrd memory: 26088K
[    1.322619] Linux agpgart interface v0.103
[    1.328885] loop: module loaded
[    1.330442] virtio_scsi virtio4: 16/0/0 default/read/poll queues
[    1.335327] scsi host0: Virtio SCSI HBA
[    1.339343] ACPI: bus type drm_connector registered
[    1.340221] scsi 0:0:0:0: Direct-Access     QEMU     QEMU HARDDISK    2.5+ PQ: 0 ANSI: 5
[    1.340704] tun: Universal TUN/TAP device driver, 1.6
[    1.346262] scsi 0:0:0:2: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.352076] PPP generic driver version 2.4.2
[    1.353557] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    1.356649] scsi 0:0:0:6: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.357012] serio: i8042 KBD port at 0x60,0x64 irq 1
[    1.362917] serio: i8042 AUX port at 0x60,0x64 irq 12
[    1.363739] scsi 0:0:0:5: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.364432] mousedev: PS/2 mouse device common for all mice
[    1.370561] rtc_cmos 00:03: RTC can wake from S4
[    1.370854] scsi 0:0:0:4: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.373372] rtc_cmos 00:03: registered as rtc0
[    1.378599] rtc_cmos 00:03: setting system clock to 2025-04-30T09:38:15 UTC (1746005895)
[    1.380271] scsi 0:0:0:3: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.380885] rtc_cmos 00:03: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
[    1.387603] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    1.388207] i2c_dev: i2c /dev entries driver
[    1.389734] scsi 0:0:0:1: Direct-Access     HC       Volume           2.5+ PQ: 0 ANSI: 5
[    1.391955] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
[    1.407775] device-mapper: uevent: version 1.0.3
[    1.411763] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: [email protected]
[    1.417592] platform eisa.0: Probing EISA bus 0
[    1.419349] platform eisa.0: EISA: Cannot allocate resource for mainboard
[    1.422795] platform eisa.0: Cannot allocate resource for EISA slot 1
[    1.426248] platform eisa.0: Cannot allocate resource for EISA slot 2
[    1.429665] platform eisa.0: Cannot allocate resource for EISA slot 3
[    1.432135] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    1.432288] sd 0:0:0:0: Power-on or device reset occurred
[    1.432573] sd 0:0:0:0: [sda] 720003072 512-byte logical blocks: (369 GB/343 GiB)
[    1.432603] platform eisa.0: Cannot allocate resource for EISA slot 4
[    1.432651] sd 0:0:0:0: [sda] Write Protect is off
[    1.432655] sd 0:0:0:0: [sda] Mode Sense: 63 00 00 08
[    1.432842] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.434582] scsi 0:0:0:2: Attached scsi generic sg1 type 0
[    1.434943] sd 0:0:0:2: Power-on or device reset occurred
[    1.435298] sd 0:0:0:2: [sdb] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[    1.435389] sd 0:0:0:2: [sdb] Write Protect is off
[    1.435391] sd 0:0:0:2: [sdb] Mode Sense: 63 00 00 08
[    1.435583] sd 0:0:0:2: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.438030] platform eisa.0: Cannot allocate resource for EISA slot 5
[    1.438143]  sda: sda1 sda14 sda15
[    1.438380] sd 0:0:0:0: [sda] Attached SCSI disk
[    1.438954] sd 0:0:0:2: [sdb] Attached SCSI disk
[    1.439928] sd 0:0:0:6: Attached scsi generic sg2 type 0
[    1.440084] sd 0:0:0:6: Power-on or device reset occurred
[    1.440289] sd 0:0:0:6: [sdc] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[    1.440342] sd 0:0:0:6: [sdc] Write Protect is off
[    1.440344] sd 0:0:0:6: [sdc] Mode Sense: 63 00 00 08
[    1.440456] sd 0:0:0:6: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.443017] platform eisa.0: Cannot allocate resource for EISA slot 6
[    1.444261] sd 0:0:0:5: Attached scsi generic sg3 type 0
[    1.444274] sd 0:0:0:6: [sdc] Attached SCSI disk
[    1.444349] sd 0:0:0:5: Power-on or device reset occurred
[    1.444650] sd 0:0:0:5: [sdd] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB)
[    1.444784] sd 0:0:0:5: [sdd] Write Protect is off
[    1.444788] sd 0:0:0:5: [sdd] Mode Sense: 63 00 00 08
[    1.444875] platform eisa.0: Cannot allocate resource for EISA slot 7
[    1.444956] sd 0:0:0:5: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.447115] sd 0:0:0:4: Attached scsi generic sg4 type 0
[    1.447212] sd 0:0:0:4: Power-on or device reset occurred
[    1.447404] sd 0:0:0:4: [sde] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[    1.447474] sd 0:0:0:4: [sde] Write Protect is off
[    1.447478] sd 0:0:0:4: [sde] Mode Sense: 63 00 00 08
[    1.447645] sd 0:0:0:4: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.449891] sd 0:0:0:5: [sdd] Attached SCSI disk
[    1.449913] platform eisa.0: Cannot allocate resource for EISA slot 8
[    1.451097] sd 0:0:0:4: [sde] Attached SCSI disk
[    1.451264] sd 0:0:0:3: Attached scsi generic sg5 type 0
[    1.451421] sd 0:0:0:3: Power-on or device reset occurred
[    1.451463] scsi 0:0:0:1: Attached scsi generic sg6 type 0
[    1.451647] sd 0:0:0:3: [sdf] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
[    1.451737] sd 0:0:0:1: Power-on or device reset occurred
[    1.451741] sd 0:0:0:3: [sdf] Write Protect is off
[    1.451744] sd 0:0:0:3: [sdf] Mode Sense: 63 00 00 08
[    1.451873] sd 0:0:0:3: [sdf] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.452117] sd 0:0:0:1: [sdg] 41943040 512-byte logical blocks: (21.5 GB/20.0 GiB)
[    1.452243] sd 0:0:0:1: [sdg] Write Protect is off
[    1.452246] sd 0:0:0:1: [sdg] Mode Sense: 63 00 00 08
[    1.452403] sd 0:0:0:1: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.455205] sd 0:0:0:3: [sdf] Attached SCSI disk
[    1.455534] platform eisa.0: EISA: Detected 0 cards
[    1.456119] sd 0:0:0:1: [sdg] Attached SCSI disk
[    1.536806] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
[    1.539887] ledtrig-cpu: registered to indicate activity on CPUs
[    1.541959] drop_monitor: Initializing network drop monitor service
[    1.544049] NET: Registered PF_INET6 protocol family
[    1.554688] Segment Routing with IPv6
[    1.555951] In-situ OAM (IOAM) with IPv6
[    1.557286] NET: Registered PF_PACKET protocol family
[    1.559039] Key type dns_resolver registered
[    1.563502] IPI shorthand broadcast: enabled
[    1.566213] sched_clock: Marking stable (1391006292, 175050668)->(1657973860, -91916900)
[    1.568592] registered taskstats version 1
[    1.571680] Loading compiled-in X.509 certificates
[    1.573575] Loaded X.509 cert 'Build time autogenerated kernel key: 01522eeefe8b0434d72b230b27bafd5639a5648e'
[    1.576673] Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969'
[    1.579562] Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19'
[    1.582027] blacklist: Loading compiled-in revocation X.509 certificates
[    1.583706] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0'
[    1.586148] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03'
[    1.588730] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b'
[    1.591428] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8'
[    1.593997] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d'
[    1.596685] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c'
[    1.600719] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af'
[    1.605404] Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9'
[    1.615306] Key type .fscrypt registered
[    1.617236] Key type fscrypt-provisioning registered
[    1.628950] cryptd: max_cpu_qlen set to 1000
[    1.640210] AVX2 version of gcm_enc/dec engaged.
[    1.642868] AES CTR mode by8 optimization enabled
[    1.667041] Key type encrypted registered
[    1.669679] AppArmor: AppArmor sha256 policy hashing enabled
[    1.673105] ima: No TPM chip found, activating TPM-bypass!
[    1.676350] Loading compiled-in module X.509 certificates
[    1.680621] Loaded X.509 cert 'Build time autogenerated kernel key: 01522eeefe8b0434d72b230b27bafd5639a5648e'
[    1.686611] ima: Allocated hash algorithm: sha256
[    1.689630] ima: No architecture policies found
[    1.692482] evm: Initialising EVM extended attributes:
[    1.695831] evm: security.selinux
[    1.698025] evm: security.SMACK64
[    1.699725] evm: security.SMACK64EXEC
[    1.701360] evm: security.SMACK64TRANSMUTE
[    1.703090] evm: security.SMACK64MMAP
[    1.704658] evm: security.apparmor
[    1.706146] evm: security.ima
[    1.707478] evm: security.capability
[    1.709032] evm: HMAC attrs: 0x1
[    1.711186] PM:   Magic number: 5:776:627
[    1.721551] RAS: Correctable Errors collector initialized.
[    1.724265] clk: Disabling unused clocks
[    1.729914] Freeing unused decrypted memory: 2028K
[    1.732833] Freeing unused kernel image (initmem) memory: 4992K
[    1.735211] Write protecting the kernel read-only data: 38912k
[    1.738280] Freeing unused kernel image (rodata/data gap) memory: 2016K
[    1.796560] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[    1.798010] Run /init as init process
[    1.798900]   with arguments:
[    1.798903]     /init
[    1.798904]   with environment:
[    1.798906]     HOME=/
[    1.798907]     TERM=linux
[    1.798908]     BOOT_IMAGE=/boot/vmlinuz-6.8.0-58-generic
[    1.981434] [drm] pci: virtio-vga detected at 0000:00:01.0
[    1.987465] virtio-pci 0000:00:01.0: vgaarb: deactivate vga console
[    1.995301] xhci_hcd 0000:02:00.0: xHCI Host Controller
[    1.995863] xhci_hcd 0000:02:00.0: new USB bus registered, assigned bus number 1
[    1.996659] xhci_hcd 0000:02:00.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010
[    1.999003] virtio_net virtio5 enp7s0: renamed from eth0
[    2.002132] Console: switching to colour dummy device 80x25
[    2.012359] [drm] features: -virgl +edid -resource_blob -host_visible
[    2.012362] [drm] features: -context_init
[    2.013498] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4
[    2.018730] ahci 0000:00:1f.2: version 3.0
[    2.019129] ACPI: \_SB_.GSIA: Enabled at IRQ 16
[    2.021438] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3
[    2.025717] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode
[    2.029821] ahci 0000:00:1f.2: flags: 64bit ncq only 
[    2.032790] xhci_hcd 0000:02:00.0: xHCI Host Controller
[    2.036178] xhci_hcd 0000:02:00.0: new USB bus registered, assigned bus number 2
[    2.038610] [drm] number of scanouts: 1
[    2.039787] xhci_hcd 0000:02:00.0: Host supports USB 3.0 SuperSpeed
[    2.041260] [drm] number of cap sets: 0
[    2.043208] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.08
[    2.045218] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.045925] [drm] Initialized virtio_gpu 0.1.0 0 for 0000:00:01.0 on minor 0
[    2.046226] scsi host1: ahci
[    2.046476] scsi host2: ahci
[    2.046568] usb usb1: Product: xHCI Host Controller
[    2.046718] scsi host3: ahci
[    2.046888] scsi host4: ahci
[    2.047079] scsi host5: ahci
[    2.047268] scsi host6: ahci
[    2.047782] ata1: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a100 irq 76 lpm-pol 0
[    2.047791] ata2: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a180 irq 76 lpm-pol 0
[    2.047797] ata3: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a200 irq 76 lpm-pol 0
[    2.047803] ata4: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a280 irq 76 lpm-pol 0
[    2.047809] ata5: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a300 irq 76 lpm-pol 0
[    2.047814] ata6: SATA max UDMA/133 abar m4096@0xfea1a000 port 0xfea1a380 irq 76 lpm-pol 0
[    2.073162] usb usb1: Manufacturer: Linux 6.8.0-58-generic xhci-hcd
[    2.073164] fbcon: virtio_gpudrmfb (fb0) is primary device
[    2.073166] usb usb1: SerialNumber: 0000:02:00.0
[    2.073406] hub 1-0:1.0: USB hub found
[    2.073867] Console: switching to colour frame buffer device 160x50
[    2.074116] hub 1-0:1.0: 4 ports detected
[    2.074713] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    2.075722] virtio-pci 0000:00:01.0: [drm] fb0: virtio_gpudrmfb frame buffer device
[    2.077375] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.08
[    2.089919] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.092143] usb usb2: Product: xHCI Host Controller
[    2.093607] usb usb2: Manufacturer: Linux 6.8.0-58-generic xhci-hcd
[    2.095428] usb usb2: SerialNumber: 0000:02:00.0
[    2.097266] hub 2-0:1.0: USB hub found
[    2.099023] hub 2-0:1.0: 4 ports detected
[    2.318121] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    2.362932] ata5: SATA link down (SStatus 0 SControl 300)
[    2.365624] ata4: SATA link down (SStatus 0 SControl 300)
[    2.369052] ata6: SATA link down (SStatus 0 SControl 300)
[    2.371847] ata2: SATA link down (SStatus 0 SControl 300)
[    2.374282] ata3: SATA link down (SStatus 0 SControl 300)
[    2.377515] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[    2.380083] ata1.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[    2.382738] ata1.00: applying bridge limits
[    2.385232] ata1.00: configured for UDMA/100
[    2.388095] scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5
[    2.420537] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[    2.423736] cdrom: Uniform CD-ROM driver Revision: 3.20
[    2.444005] sr 1:0:0:0: Attached scsi CD-ROM sr0
[    2.444338] sr 1:0:0:0: Attached scsi generic sg7 type 5
[    2.447926] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
[    2.452042] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
[    2.456690] usb 1-1: Product: QEMU USB Tablet
[    2.459323] usb 1-1: Manufacturer: QEMU
[    2.461940] usb 1-1: SerialNumber: 28754-0000:00:02.1:00.0-1
[    2.482045] hid: raw HID events driver (C) Jiri Kosina
[    2.492094] usbcore: registered new interface driver usbhid
[    2.496395] usbhid: USB HID core driver
[    2.505370] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:02.1/0000:02:00.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input5
[    2.513835] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:02:00.0-1/input0
[    2.755080] raid6: avx2x4   gen() 17616 MB/s
[    2.774087] raid6: avx2x2   gen() 24068 MB/s
[    2.792073] raid6: avx2x1   gen() 21836 MB/s
[    2.793264] raid6: using algorithm avx2x2 gen() 24068 MB/s
[    2.811070] raid6: .... xor() 17715 MB/s, rmw enabled
[    2.812307] raid6: using avx2x2 recovery algorithm
[    2.816307] xor: automatically using best checksumming function   avx       
[    2.825392] async_tx: api initialized (async)
[    3.125696] Btrfs loaded, zoned=yes, fsverity=yes
[    3.263909] EXT4-fs (sda1): mounted filesystem f184a16b-6eca-41cb-b48a-ff37cdce1d79 ro with ordered data mode. Quota mode: none.
[    3.456535] systemd[1]: Inserted module 'autofs4'
[    3.494564] systemd[1]: systemd 255.4-1ubuntu8.6 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    3.509191] systemd[1]: Detected virtualization kvm.
[    3.516194] systemd[1]: Detected architecture x86-64.
[    3.528177] systemd[1]: Hostname set to <k8s-worker-78818640c23fdbc>.
[    3.798330] systemd[1]: Configuration file /etc/systemd/system/promtail.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway.
[    3.818499] systemd[1]: Configuration file /etc/systemd/system/node_exporter.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway.
[    3.920964] systemd[1]: Queued start job for default target graphical.target.
[    3.940917] systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe.
[    3.951846] systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty.
[    3.963485] systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck.
[    3.975921] systemd[1]: Created slice user.slice - User and Session Slice.
[    3.985120] systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[    3.996879] systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point.
[    4.008259] systemd[1]: Expecting device dev-disk-by\x2duuid-5628\x2d19B6.device - /dev/disk/by-uuid/5628-19B6...
[    4.019875] systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0...
[    4.028831] systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes.
[    4.037921] systemd[1]: Reached target slices.target - Slice Units.
[    4.047289] systemd[1]: Reached target snapd.mounts-pre.target - Mounting snaps.
[    4.055801] systemd[1]: Reached target snapd.mounts.target - Mounted snaps.
[    4.066213] systemd[1]: Reached target time-set.target - System Time Set.
[    4.075890] systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes.
[    4.084977] systemd[1]: Listening on dm-event.socket - Device-mapper event daemon FIFOs.
[    4.097127] systemd[1]: Listening on lvm2-lvmpolld.socket - LVM2 poll daemon socket.
[    4.124050] systemd[1]: Listening on rpcbind.socket - RPCbind Server Activation Socket.
[    4.136759] systemd[1]: Listening on syslog.socket - Syslog Socket.
[    4.145993] systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket.
[    4.156421] systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe.
[    4.168090] systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log).
[    4.178592] systemd[1]: Listening on systemd-journald.socket - Journal Socket.
[    4.188572] systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket.
[    4.201179] systemd[1]: systemd-pcrextend.socket - TPM2 PCR Extension (Varlink) was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[    4.209426] systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket.
[    4.221329] systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket.
[    4.243243] systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System...
[    4.253720] systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System...
[    4.266097] systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System...
[    4.278713] systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System...
[    4.294539] systemd[1]: Starting systemd-journald.service - Journal Service...
[    4.305663] systemd[1]: auth-rpcgss-module.service - Kernel Module supporting RPCSEC_GSS was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab).
[    4.316284] systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout...
[    4.328828] systemd-journald[496]: Collecting audit messages is disabled.
[    4.335904] systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes...
[    4.348286] systemd[1]: Starting lvm2-monitor.service - Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
[    4.363203] systemd[1]: Starting [email protected] - Load Kernel Module configfs...
[    4.378362] systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod...
[    4.392754] systemd[1]: Starting [email protected] - Load Kernel Module drm...
[    4.405867] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore...
[    4.417808] systemd[1]: Starting [email protected] - Load Kernel Module fuse...
[    4.426918] systemd[1]: Starting [email protected] - Load Kernel Module loop...
[    4.437550] systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl).
[    4.449693] systemd[1]: systemd-fsck-root.service - File System Check on Root Device was skipped because of an unmet condition check (ConditionPathExists=!/run/initramfs/fsck-root).
[    4.472290] systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules...
[    4.482419] systemd[1]: systemd-pcrmachine.service - TPM2 PCR Machine ID Measurement was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[    4.492488] systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems...
[    4.505549] systemd[1]: systemd-tpm2-setup-early.service - TPM2 SRK Setup (Early) was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
[    4.522324] EXT4-fs (sda1): re-mounted f184a16b-6eca-41cb-b48a-ff37cdce1d79 r/w. Quota mode: none.
[    4.528330] systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices...
[    4.546563] systemd[1]: Started systemd-journald.service - Journal Service.
[    4.589905] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    4.605313] Bridge firewalling registered
[    4.683918] systemd-journald[496]: Received client request to flush runtime journal.
[    5.242487] audit: type=1400 audit(1746005899.363:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="vscode" pid=882 comm="apparmor_parser"
[    5.242501] audit: type=1400 audit(1746005899.363:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=876 comm="apparmor_parser"
[    5.242657] audit: type=1400 audit(1746005899.363:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=875 comm="apparmor_parser"
[    5.242677] audit: type=1400 audit(1746005899.363:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=870 comm="apparmor_parser"
[    5.242784] audit: type=1400 audit(1746005899.363:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=869 comm="apparmor_parser"
[    5.242865] audit: type=1400 audit(1746005899.363:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="ch-run" pid=880 comm="apparmor_parser"
[    5.242945] audit: type=1400 audit(1746005899.363:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=872 comm="apparmor_parser"
[    5.242994] audit: type=1400 audit(1746005899.363:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="devhelp" pid=884 comm="apparmor_parser"
[    5.243046] audit: type=1400 audit(1746005899.363:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="chrome" pid=881 comm="apparmor_parser"
[    5.403089] RPC: Registered named UNIX socket transport module.
[    5.403097] RPC: Registered udp transport module.
[    5.403098] RPC: Registered tcp transport module.
[    5.403099] RPC: Registered tcp-with-tls transport module.
[    5.403100] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    8.233244] 8021q: 802.1Q VLAN Support v1.8
[    8.233274] 8021q: adding VLAN 0 to HW filter on device enp7s0
[    8.405851] Process accounting resumed
[    8.538419] loop0: detected capacity change from 0 to 8
[   20.920216] evm: overlay not supported
[   28.883672] eth0: renamed from tmp917e6
[   28.918711] eth0: renamed from tmpfa99f
[   28.941951] eth0: renamed from tmpb87c4
[   29.011318] eth0: renamed from tmp77779
[   29.043390] eth0: renamed from tmp899ee
[   29.075867] eth0: renamed from tmpf17b2
[   29.109330] eth0: renamed from tmp02f77
[   29.171542] eth0: renamed from tmp5f7f0
[   29.183111] eth0: renamed from tmp52d0c
[   29.196137] eth0: renamed from tmpc39d6
[   29.259728] eth0: renamed from tmpe8745
[   29.267829] eth0: renamed from tmp1d630
[   29.278228] eth0: renamed from tmpbbce5
[   29.310672] eth0: renamed from tmpf2095
[   29.337771] eth0: renamed from tmp1f9bb
[   31.124663] Initializing XFRM netlink socket
[   46.810856] eth0: renamed from tmp0f1d4
[   46.925630] eth0: renamed from tmpb3713
[   48.786495] eth0: renamed from tmp1be87
[   62.853119] Loading iSCSI transport class v2.0-870.
[   62.884603] iscsi: registered transport (tcp)
[   62.903048] scsi host7: iSCSI Initiator over TCP/IP
[   62.906178] scsi 7:0:0:0: RAID              IET      Controller       0001 PQ: 0 ANSI: 5
[   62.909146] scsi 7:0:0:0: Attached scsi generic sg8 type 12
[   62.909861] scsi 7:0:0:1: Direct-Access     IET      VIRTUAL-DISK     0001 PQ: 0 ANSI: 5
[   62.913302] sd 7:0:0:1: Attached scsi generic sg9 type 0
[   62.913477] sd 7:0:0:1: Power-on or device reset occurred
[   62.914422] sd 7:0:0:1: [sdh] 2097152 512-byte logical blocks: (1.07 GB/1.00 GiB)
[   62.914621] sd 7:0:0:1: [sdh] Write Protect is off
[   62.914626] sd 7:0:0:1: [sdh] Mode Sense: 69 00 10 08
[   62.914994] sd 7:0:0:1: [sdh] Write cache: disabled, read cache: enabled, supports DPO and FUA
[   62.943670] sd 7:0:0:1: [sdh] Attached SCSI disk
[   64.031126] SGI XFS with ACLs, security attributes, realtime, quota, no debug enabled
[   64.038502] XFS (dm-0): Mounting V5 Filesystem 28364769-9736-41a3-a1a5-7b636d627f44
[   64.099489] XFS (dm-0): Ending clean mount
[   64.108614] xfs filesystem being mounted at /var/lib/kubelet/pods/62b18134-d37f-46a7-986a-bab5f92cba8f/volumes/kubernetes.io~csi/pvc-9a591f1f-c60f-4a93-8fbe-91a8196f2e17/mount supports timestamps until 2038-01-19 (0x7fffffff)
[   64.317006] eth0: renamed from tmp7dc77
[   69.340750] EXT4-fs (dm-1): mounted filesystem ab231587-538a-459b-a565-437862f2c980 r/w with ordered data mode. Quota mode: none.
[  103.273895] XFS (dm-2): Mounting V5 Filesystem 0c528bc1-5bdb-46f6-9599-ec411f38c2aa
[  103.534892] XFS (dm-2): Ending clean mount
[  103.565900] xfs filesystem being mounted at /var/lib/kubelet/pods/0497c24d-a634-42f5-8f9e-8aa53b735c3f/volumes/kubernetes.io~csi/pvc-003efbab-6b97-47a7-a968-9d4db791d04d/mount supports timestamps until 2038-01-19 (0x7fffffff)
[  104.017868] eth0: renamed from tmp3705d
[  105.268687] XFS (dm-3): Mounting V5 Filesystem 6e95865a-4710-40a9-a3a6-803eb9e1fe25
[  105.395063] XFS (dm-3): Ending clean mount
[  105.464305] xfs filesystem being mounted at /var/lib/kubelet/pods/c6ca9a63-ad14-45af-a6d1-ceb624aea048/volumes/kubernetes.io~csi/pvc-6ab7d7f5-379d-468e-a641-78461e5180c7/mount supports timestamps until 2038-01-19 (0x7fffffff)
[  105.804802] eth0: renamed from tmpa22cd
[  108.275036] EXT4-fs (dm-4): mounted filesystem a0c18ee4-1aa8-4565-9ccf-614feaa07e45 r/w with ordered data mode. Quota mode: none.
[  108.508962] XFS (dm-5): Mounting V5 Filesystem 0a9c39c8-6311-4de9-aa29-c80d72678f8a
[  108.596036] XFS (dm-5): Ending clean mount
[  108.612890] xfs filesystem being mounted at /var/lib/kubelet/pods/42675307-f6e3-466a-a06f-b109b5cf67ff/volumes/kubernetes.io~csi/pvc-f478066b-1e87-4572-9dd3-32da9985f75d/mount supports timestamps until 2038-01-19 (0x7fffffff)
[  108.864395] EXT4-fs (dm-6): mounted filesystem f93031d9-13e1-4213-96b7-2efdfbe59c12 r/w with ordered data mode. Quota mode: none.
[  109.096105] eth0: renamed from tmpdae86
[  109.128067] eth0: renamed from tmpc1175
[  312.962338] eth0: renamed from tmpb0ef1
[  327.431973] eth0: renamed from tmp2102d
[  337.430931] eth0: renamed from tmpb1ba7
[  347.404734] eth0: renamed from tmp47699
hcloud-csi values.yaml
controller:
  resources:
    csiAttacher:
      limits:
        memory: 200Mi
        cpu: 100m
      requests:
        memory: 40Mi
        cpu: 20m
    csiResizer:
      limits:
        memory: 200Mi
        cpu: 100m
      requests:
        memory: 40Mi
        cpu: 20m
    csiProvisioner:
      limits:
        memory: 200Mi
        cpu: 100m
      requests:
        memory: 40Mi
        cpu: 20m
    livenessProbe:
      limits:
        memory: 200Mi
        cpu: 100m
      requests:
        memory: 40Mi
        cpu: 20m
    hcloudCSIDriver:
      limits:
        memory: 200Mi
        cpu: 200m
      requests:
        memory: 80Mi
        cpu: 20m
  extraEnvVars:
    - name: HTTP_PROXY
      value: <redacted>
    - name: HTTPS_PROXY
      value: <redacted>
  replicaCount: 3
  hcloudVolumeDefaultLocation: fsn1
  priorityClassName: system-cluster-critical
  tolerations:
    - effect: NoSchedule
      key: node-role.kubernetes.io/control-plane
  affinity:
    nodeAffinity:
      requiredDuringSchedulingIgnoredDuringExecution:
        nodeSelectorTerms:
          - matchExpressions:
              - key: node-role.kubernetes.io/control-plane
                operator: Exists
  topologySpreadConstraints:
    - maxSkew: 1
      topologyKey: kubernetes.io/hostname
      whenUnsatisfiable: ScheduleAnyway
      labelSelector:
        matchLabels:
          app.kubernetes.io/name: hcloud-csi
      matchLabelKeys:
        - pod-template-hash
node:
  resources:
    csiNodeDriverRegistrar:
      limits:
        memory: 100Mi
        cpu: 1000m
      requests:
        memory: 40Mi
        cpu: 20m
    livenessProbe:
      limits:
        memory: 100Mi
        cpu: 1000m
      requests:
        memory: 40Mi
        cpu: 20m
    hcloudCSIDriver:
      limits:
        memory: 200Mi
        cpu: 1000m
      requests:
        memory: 80Mi
        cpu: 20m
  affinity:
    nodeAffinity:
      requiredDuringSchedulingIgnoredDuringExecution:
        nodeSelectorTerms:
          - matchExpressions:
              - key: node-role.kubernetes.io/worker
                operator: Exists
metrics:
  enabled: true
storageClasses:
  - name: hcloud-volumes
    defaultStorageClass: false

A little detail: The issue is not 100% reproducible. Sometimes it's necessary to run the steps 3-4 times to reproduce it.

I hope it helps.

bheisig avatar Apr 30 '25 10:04 bheisig

Thank you for the detailed report.

If it really takes multiple times to reproduce the issue, we might need to develop a bit of tooling/scripts and have another go at reproducing the issue. There are some regional holidays for my location, so I won't make it this week, unfortunately.

lukasmetzner avatar Apr 30 '25 10:04 lukasmetzner

Sounds great 👍 No worries, this public holiday also affects us ;-D

bheisig avatar Apr 30 '25 11:04 bheisig

Hi. Any news on this?

bheisig avatar May 14 '25 06:05 bheisig

Hey,

I have started building a small script simulating multiple reschedules including some random write operations, which are partially aborted by deleting the pod. So far I still have no success in reproducing the error. As long as I cannot do that, it is hard to tell whats the underlying issue :/ We currently have a team event, so my capacity is limited this week.

I'm brainstorming what I could try next to reproduce the issue, but my options are getting slimmer.

lukasmetzner avatar May 14 '25 10:05 lukasmetzner

Hey, unfortunately I’m still unable to reproduce the bug. Without an environment where the issue occurs, there's not much more I can do at the moment.

lukasmetzner avatar Jun 02 '25 12:06 lukasmetzner

This issue has been marked as stale because it has not had recent activity. The bot will close the issue if no further action occurs.

github-actions[bot] avatar Aug 31 '25 12:08 github-actions[bot]