Error message related to MIOP in syslog after Ceph crash

Mixtile Blade 3 (Mixtile Cluster Box)
#1

I’ve had some mysterious app crashes today on one of my Blade 3 nodes (blade3n4): The Ceph OSD service (the one, which addresses mass storage on a cluster node; osd0 runs on blade3n4) suddenly disappeared. The latter came right after miop-ep complaining about an unknown IRQ:

[ 5609.295485] miop-ep fe150000.pcie: miop_ep_elbi_int() unknown irq: 100
[ 5620.279945] miop-ep fe150000.pcie: miop_ep_elbi_int() unknown irq: 200
[ 5638.261852] Process 24925(apport) has RLIMIT_CORE set to 1
[ 5638.261871] Aborting core
[ 5638.529445] libceph: osd0 (1)10.20.0.14:6801 socket closed (con state OPEN)
[ 5638.840150] libceph: osd0 (1)10.20.0.14:6801 socket closed (con state V1_BANNER)
[ 5639.097072] libceph: osd0 (1)10.20.0.14:6801 socket error on write
[ 5639.177906] libceph (8aad3073-39a1-11f1-bf6e-f2704a1efa9b e8153): osd0 down

A deeper examination of the syslog surfaced quite a long error message with call trace:

[ 5646.164863] WARNING: CPU: 4 PID: 24883 at kernel/time/timer.c:1425 del_timer_sync+0x34/0x5c
[ 5646.164873] Modules linked in: ceph netfs nf_conntrack_netlink xt_nat veth vxlan ip6_udp_tunnel udp_tunnel xt_policy xt_mark xt_bpf xt_conntrack xt_MASQUERADE br_netfilter bridge stp llc xt_set ip_set nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_addrtype nft_compat nf_tables overlay qrtr miop_ep(O) miop_ep_net(PO) pcie_ep_rk35(PO) miop_reg(O) binfmt_misc pwm_fan rockchip_canfd can_dev panfrost drm_shmem_helper gpu_sched squashfs sch_fq_codel nvme_fabrics fuse nfnetlink ip_tables ipv6 r8169 dm_mod uio_pdrv_genirq uio
[ 5646.164938] CPU: 4 PID: 24883 Comm: queue44:src Tainted: P        W  O       6.1.0-1027-rockchip #27
[ 5646.164942] Hardware name: Mixtile Blade 3 (DT)
[ 5646.164945] pstate: 004000c9 (nzcv daIF +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 5646.164949] pc : del_timer_sync+0x34/0x5c
[ 5646.164952] lr : miop_on_tx_ready+0xb8/0xd8 [miop_ep_net]
[ 5646.164960] sp : ffff80000aa3bdd0
[ 5646.164962] x29: ffff80000aa3bdd0 x28: ffff00015479bf00 x27: 0000000000000000
[ 5646.164967] x26: ffff0001060d0000 x25: ffff8000013131d0 x24: 0000000000000000
[ 5646.164971] x23: ffff0001031bab80 x22: ffff000101373010 x21: 00000000000020b8
[ 5646.164976] x20: ffff0001031b8a00 x19: ffff0001031bb3c0 x18: 0000000000000000
[ 5646.164981] x17: ffff8004f3e60000 x16: ffff80000aa38000 x15: 0000000000000000
[ 5646.164985] x14: 0000000000000000 x13: 0000000000000000 x12: 0000000000000000
[ 5646.164990] x11: ffff0003fc508488 x10: 0000000000000127 x9 : ffff80000130fb90
[ 5646.164994] x8 : 0000000000000000 x7 : 0000000000000000 x6 : ffff000100607d98
[ 5646.164999] x5 : ffff00010945e2a8 x4 : 0000000000000000 x3 : ffff00010ad3e908
[ 5646.165003] x2 : 0000000000000004 x1 : ffff0001032f9000 x0 : 0000000002400005
[ 5646.165008] Call trace:
[ 5646.165010]  del_timer_sync+0x34/0x5c
[ 5646.165014]  miop_on_tx_ready+0xb8/0xd8 [miop_ep_net]
[ 5646.165019]  rk35_ep_interrupt+0xb0/0x74c [pcie_ep_rk35]
[ 5646.165027]  __handle_irq_event_percpu+0xc0/0x1cc
[ 5646.165032]  handle_irq_event_percpu+0x20/0x54
[ 5646.165035]  handle_irq_event+0x50/0x94
[ 5646.165038]  handle_fasteoi_irq+0xac/0x134
[ 5646.165041]  handle_irq_desc+0x28/0x40
[ 5646.165044]  generic_handle_domain_irq+0x20/0x2c
[ 5646.165047]  __gic_handle_irq_from_irqson.isra.0+0x174/0x1c8
[ 5646.165052]  gic_handle_irq+0x88/0x90
[ 5646.165056]  call_on_irq_stack+0x24/0x4c
[ 5646.165059]  do_interrupt_handler+0x88/0xa8
[ 5646.165063]  el0_interrupt+0x78/0xac
[ 5646.165068]  __el0_irq_handler_common+0x18/0x24
[ 5646.165071]  el0t_64_irq_handler+0x10/0x1c
[ 5646.165075]  el0t_64_irq+0x19c/0x1a0

Is this a flaw in MIOP? Could please one of your developers look into this matter? Ceph can recover itself when one OSD crashes, but I really don’t wanna wait for a failure of the whole Ceph cluster. Thank you.

#2

This may be a MIOP issue, but it should not occur here. I have changed del_timer_sync to del_timer. However, the most likely cause of this issue is a loose hardware connection. You may choose to perform an update.

#3

Will this update also work on Ubuntu 24.04 LTS?

Do you mean this issue could be because of the node going loose from the backplane, and I should reseat it?

#4

Yes, it is still running on Ubuntu 24.04 LTS.

I’m also not sure whether the issue is caused by an unstable connection. If your environment is still available, you can check whether the external SSD on the n4 node is functioning properly. If it is not, that would indicate a connectivity issue.

#5

OK, I’m gonna install the package you sent me on the nodes.

Another problem: Just after updating the control board, one of my nodes froze and couldn’t be brought back to life. In the serial console, I got a bunch of error messages pointing to the eMMC storage:

[14612.236001] I/O error, dev mmcblk0, sector 22611056 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2
[14612.236055] Buffer I/O error on device mmcblk0p3, logical block 2822286
[14612.242990] miop-ep fe150000.pcie: miop_ep_elbi_int() unknown irq: 100
[14634.479752] miop-ep fe150000.pcie: miop_ep_elbi_int() unknown irq: 800
[14673.665873] mmc0: cqhci: timeout for tag 0, qcnt 31

At this point, a lengthy register dump follows. Do you need it?

And: The installation of the new driver ended in a warning:

Preparing to unpack miop-driver-service_2.0.0_arm64.deb ...
Unpacking miop-driver-service (2.0.0) over (1.0.0) ...
dpkg: warning: unable to delete old directory '/usr/local': Directory not empty
Setting up miop-driver-service (2.0.0) ...

Even worse: After installing the driver package on the nodes and rebooting the whole cluster, the internal network is suddenly gone! ip a | grep pci0 on the control board returns nothing.

Is this a serious problem?

#6

You can try repairing the filesystem for the eMMC error. The installation warnings are normal.
Did you not update the OpenWrt version according to my instructions?

#7

I did! Neverthleless, the error persists. Here is a strange message I’ve found in the syslog (irrelevant lines omitted):

[   40.610085] pci 0000:01:00.0: 2.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x1 link at 0000:00:00.0 (capable of 63.008 Gb/s with 8.0 GT/s PCIe x8 link)
[…]
[   40.732048] pci 0000:00:00.0: BAR 0: no space for [mem size 0x80000000]
[   40.738840] pci 0000:00:00.0: BAR 0: failed to assign [mem size 0x80000000]
[   40.745978] pci 0000:00:00.0: BAR 1: assigned [mem 0x20000000-0x2000ffff]
#8

And this is what I’ve found in the syslogs of all nodes:

mixtile@blade3n1:~$ sudo dmesg | grep pci | tail -35
[sudo] password for mixtile: 
[    3.025763] pci 0002:22:07.0: PCI bridge to [bus 24]
[    3.025773] pci 0002:22:07.0:   bridge window [io  0x101000-0x101fff]
[    3.025790] pci 0002:22:07.0:   bridge window [mem 0xf2300000-0xf23fffff]
[    3.025819] pci 0002:21:00.0: PCI bridge to [bus 22-24]
[    3.025828] pci 0002:21:00.0:   bridge window [io  0x100000-0x101fff]
[    3.025845] pci 0002:21:00.0:   bridge window [mem 0xf2200000-0xf23fffff]
[    3.025874] pci 0002:20:00.0: PCI bridge to [bus 21-24]
[    3.025880] pci 0002:20:00.0:   bridge window [io  0x100000-0x101fff]
[    3.025887] pci 0002:20:00.0:   bridge window [mem 0xf2200000-0xf23fffff]
[    3.026797] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    3.028121] pcieport 0002:20:00.0: PME: Signaling with IRQ 134
[    3.028339] pcieport 0002:21:00.0: enabling device (0000 -> 0003)
[    3.028658] pcieport 0002:22:03.0: enabling device (0000 -> 0003)
[    3.029113] pcieport 0002:22:07.0: enabling device (0000 -> 0003)
[    3.053454] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    3.080148] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    3.106983] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    3.133488] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    5.623499] rk-pcie fe180000.pcie: PCIe Link Fail, LTSSM is 0x3, hw_retries=0
[    5.833489] rk-pcie fe160000.pcie: PCIe Link Fail, LTSSM is 0x200003, hw_retries=0
[    7.923412] rk_pcie_establish_link: 262 callbacks suppressed
[    7.923418] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    7.940112] rk-pcie fe160000.pcie: PCIe Linking... LTSSM is 0x2
[    7.950093] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    7.966826] rk-pcie fe160000.pcie: PCIe Linking... LTSSM is 0x2
[    7.976752] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    7.993423] rk-pcie fe160000.pcie: PCIe Linking... LTSSM is 0x2
[    8.003413] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    8.020118] rk-pcie fe160000.pcie: PCIe Linking... LTSSM is 0x2
[    8.033416] rk-pcie fe180000.pcie: PCIe Linking... LTSSM is 0x3
[    8.050148] rk-pcie fe160000.pcie: PCIe Linking... LTSSM is 0x2
[    9.560192] rk-pcie fe180000.pcie: PCIe Link Fail, LTSSM is 0x3, hw_retries=1
[    9.790136] rk-pcie fe160000.pcie: PCIe Link Fail, LTSSM is 0x3, hw_retries=1
[   10.580171] rk-pcie fe180000.pcie: failed to initialize host
[   10.825330] rk-pcie fe160000.pcie: failed to initialize host

So apparently, the updated driver is not working correctly.

#9

This is a raw SDK error. Ignore it.

#10

These are not errors. In fact, the PCIe value we use is fe150000, so this is unrelated to the errors above.

The real reason you cannot use it is that the Debian package I uploaded accidentally removed the driver loading service. I have updated the Debian package, so you only need to run wget again and install it.

#11

I’m getting errors when trying to install the package you sent me:

(Reading database ... 174592 files and directories currently installed.)
Preparing to unpack .../miop-driver-service_2.0.0_arm64.deb ...
Unpacking miop-driver-service (2.0.0) over (2.0.0) ...
Setting up miop-driver-service (2.0.0) ...
[  743.850316] cma: cma_alloc: miop_dma@0x0e000000: alloc failed, req-size: 1 pages, ret: -12

After a reboot of the complete cluster, I can access my nodes via nodectl console, but before I get a login prompt (and even after that), I see tons of error messages like this one:

[  102.781614] miop-ep fe150000.pcie: RX[0] RC slot 0 pull failed: -22

And none of the nodes gets an IP from the control board:

mixtile@blade3n4:~$ ip a
[…]
5: pci0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65200 qdisc fq_codel state UP group default qlen 1000
    link/ether 02:a4:f1:25:38:0a brd ff:ff:ff:ff:ff:ff

…despite the fact that the control board does assign IPs:

mixtile@ClusterBox:~$ sudo tail -20 /var/log/dnsmasq.log
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 available DHCP range: 10.20.0.100 -- 10.20.0.249
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 client provides name: blade3n1
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 DHCPDISCOVER(pci0) 10.20.0.11 02:9f:f1:8e:cb:0a 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 tags: eth_pci, known, pci0
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 DHCPOFFER(pci0) 10.20.0.11 02:9f:f1:8e:cb:0a 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 requested options: 1:netmask, 2:time-offset, 6:dns-server, 12:hostname, 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 requested options: 15:domain-name, 26:mtu, 28:broadcast, 121:classless-static-route, 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 requested options: 3:router, 33:static-route, 40:nis-domain, 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 requested options: 41:nis-server, 42:ntp-server, 119:domain-search, 
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 requested options: 249, 252, 17:root-path
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 next server: 10.20.0.1
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  1 option: 53 message-type  2
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option: 54 server-identifier  10.20.0.1
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option: 51 lease-time  infinite
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option:  1 netmask  255.255.255.0
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option: 28 broadcast  10.20.0.255
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option:  3 router  10.20.0.1
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  4 option:  6 dns-server  10.20.0.1
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  3 option: 15 domain-name  lan
Jun 22 16:14:24 dnsmasq-dhcp[1]: 1373044305 sent size:  8 option: 12 hostname  blade3n1

On the control board side, pci0 seems to work fine:

mixtile@ClusterBox:~$ ip a
[…]
7: pci0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65200 qdisc fq_codel state UP qlen 1000
    link/ether 02:77:f6:58:3b:0b brd ff:ff:ff:ff:ff:ff
    inet 10.20.0.1/24 brd 10.20.0.255 scope global pci0
       valid_lft forever preferred_lft forever
    inet6 fdb0:557a:1911:10::1/64 scope global noprefixroute 
       valid_lft forever preferred_lft forever
    inet6 fe80::77:f6ff:fe58:3b0b/64 scope link 
       valid_lft forever preferred_lft forever
#12

The installation error is expected because the driver missed the loading window, so after installing the driver, you should shut down the node using poweroff.

I did not see any useful errors. You can repeat the entire installation process, and make sure to remember to use poweroff. If it still does not work fine, please attach the node errors. The IP information is not useful to me.

#13

I’ve just given the driver installation another try (with poweroff, of course), but no use. I still get a bunch of these error messages, and the network is unreachable from any of the nodes:

[  218.425228] miop-ep fe150000.pcie: RX[0] RC slot 0 pull failed: -22

You stated this driver download URL last time. Is it still correct:

#14

Please confirm that there is no /overlay/upper/lib/modules/5.15.150/miop.ko file on the control board to prevent the driver from being overwritten.

#15

Yeah:

mixtile@ClusterBox:~$ ls -al /overlay/upper/lib/modules/5.15.150/miop.ko
ls: /overlay/upper/lib/modules/5.15.150/miop.ko: No such file or directory