NetBSD-Bugs archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

kern/59532: Kernel panic enumerating sensors via IPMI/BMC interface



>Number:         59532
>Category:       kern
>Synopsis:       Kernel panic enumerating sensors via IPMI/BMC interface
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Jul 20 17:55:00 +0000 2025
>Originator:     Alex Gendin
>Release:        NetBSD 10.99.14
>Organization:
>Environment:
System: NetBSD monztr 10.99.14 NetBSD 10.99.14 (GENERIC_HUGEMSGBUF) #2: Sat Jul 19 23:10:40 EDT 2025  srcbldr@monztr:/usr/obj/sys/arch/amd64/compile/GENERIC_HUGEMSGBUF amd64
Motherboard: Gigabyte 7PPSH2
>Description:
It takes a while to enumerate SDR records on this particular system.
Sometimes, send-and-receive IPMI message during sensor enumeration gets
interrupted by unknown out-of-band entity (CPU/BIOS/BMC ?) and NetBSD
reads response from unrelated request.

An example of normal request-response exchange:

    [  35.6450611] ipmi_sendcmd: rssa=0x20 nfln=0x28 cmd=0x23 len=0x06
    [  35.6450611] ipmi_sendcmd: 70 02 16 00 00 05
    [  35.6534668] kcs_sendmsg: 28 23 70 02 16 00 00 05
    [  35.6534668] kcs_write_cmd: 0x61
    [  35.6629997] kcs_write_data: 0x28
    [  35.6629997] kcs_write_data: 0x23
    [  35.6629997] kcs_write_data: 0x70
    [  35.6726210] kcs_write_data: 0x02
    [  35.6726210] kcs_write_data: 0x16
    [  35.6726210] kcs_write_data: 00
    [  35.6820669] kcs_write_data: 00
    [  35.6820669] kcs_write_cmd: 0x62
    [  35.6820669] kcs_write_data: 0x05
    [  35.7317205] kcs_read_data: 0x2c
    [  35.7317205] kcs_read_data: 0x23
    [  35.7317205] kcs_read_data: 00
    [  35.7317205] kcs_read_data: 0x17
    [  35.7437923] kcs_read_data: 00
    [  35.7437923] kcs_read_data: 0x16
    [  35.7437923] kcs_read_data: 00
    [  35.7528061] kcs_read_data: 0x51
    [  35.7528061] kcs_read_data: 0x01
    [  35.7528061] kcs_read_data: 0x3a
    [  35.7621667] kcs_recvmsg: 2c 23 00 17 00 16 00 51 01 3a
    [  35.7621667] ipmi_recvcmd: nfln=0x2c cmd=0x23 err=00 len=0x07
    [  35.7729987] ipmi_recvcmd: 17 00 16 00 51 01 3a

And here is what happens when request-response exchange is interrupted:

    [  35.5264457] ipmi_sendcmd: rssa=0x20 nfln=0x28 cmd=0x23 len=0x06
    [  35.5355461] ipmi_sendcmd: 70 02 16 00 00 05
    [  35.5355461] kcs_sendmsg: 28 23 70 02 16 00 00 05
    [  35.5422190] kcs_write_cmd: 0x61
    [  35.5422190] kcs_write_data: 0x28
    [  35.5422190] kcs_write_data: 0x23
    [  35.5540061] kcs_write_data: 0x70
    [  35.5540061] kcs_write_data: 0x02
    [  35.5540061] kcs_write_data: 0x16
    [  35.5636269] kcs_write_data: 00
    [  35.5636269] kcs_write_data: 00
    [  35.5636269] kcs_write_cmd: 0x62
    [  35.5728129] kcs_write_data: 0x05
    [  35.6217206] kcs_read_data: 0x1c
    [  35.6217206] kcs_read_data: 0x34
    [  35.6217206] kcs_read_data: 00
    [  35.6217206] kcs_recvmsg: 1c 34 00
    [  35.6331006] ipmi_recvcmd: ERR: rawlen=0x03 nfln=0x1c cmd=0x34 err=00
    [  35.6331006] ipmi0: get_sdr_partial: recvcmd fails

The message received, 1c 34 00, is a successful response to [NETFN 0x06: APP],
[CMD 0x34: SendMessage].
Correct response should start with 2c 23 00 when reading SDR records.

Thus, when this happens, function ipmi_recvcmd() returns success, and the
length of message equal to 0.

In turn, function get_sdr_partial(), upon successful read by ipmi_recvcmd(),
will try to copy 0xfffffffffffffffe bytes via this code:

    memcpy(buffer, u.msg.data, len - offsetof(typeof(u.msg), data));

The above situation will trigger kernel panic:

    [  35.9097532] ipmi_sendcmd: rssa=0x20 nfln=0x28 cmd=0x23 len=0x06
    [  35.9097532] ipmi_sendcmd: 59 09 16 00 05 10
    [  35.9197532] kcs_sendmsg: 28 23 59 09 16 00 05 10
    [  35.9197532] kcs_write_cmd: 0x61
    [  35.9297530] kcs_write_data: 0x28
    [  35.9297530] kcs_write_data: 0x23
    [  35.9297530] kcs_write_data: 0x59
    [  35.9397530] kcs_write_data: 0x09
    [  35.9397530] kcs_write_data: 0x16
    [  35.9397530] kcs_write_data: 00
    [  35.9397530] kcs_write_data: 0x05
    [  35.9497529] kcs_write_cmd: 0x62
    [  35.9497529] kcs_write_data: 0x10
    [  35.9997543] kcs_read_data: 0x1c
    [  35.9997543] kcs_read_data: 0x34
    [  36.0097534] kcs_read_data: 00
    [  36.0097534] kcs_recvmsg: 1c 34 00
    [  36.0097534] ipmi_recvcmd: nfln=0x1c cmd=0x34 err=00 len=00
    [  36.0197529] uvm_fault(0xffffffff81912fe0, 0xffffb81238578000, 1) -> e
    [  36.0297529] fatal page fault in supervisor mode
    [  36.0297529] trap type 6 code 0 rip 0xffffffff80ff4542 cs 0x8 rflags 0x10a06 cr2 0xffffb81238578000 ilevel 0 rsp 0xffffb81238576d78
    [  36.0397528] curlwp 0xffff97cc1e00bc00 pid 0.576 lowest kstack 0xffffb812385722c0
    kernel: page fault trap, code=0
    Stopped in pid 0.576 (system) at        netbsd:memcpy+0x42:     repe movsq
    (%rsi),%es:(%rdi)
    memcpy() at netbsd:memcpy+0x42
    ipmi_thread() at netbsd:ipmi_thread+0x266
    ds          6da0
    es          64c7
    fs          6d70
    gs          b800
    rdi         ffff97f8b6ec3418
    rsi         ffffb81238577ffd
    rbp         ffffb81238576ef0
    rbx         0
    rdx         ff3a10050016
    rcx         1ffffffffffffdb6
    rax         ffff97f8b6ec21cd
    r8          ffff97f8b6ec21cd
    r9          ffff97f8b6ec21c3
    r10         80e2536e
    r11         fffffffffffffffb
    r12         ffff97cc1e09b800
    r13         ffffb81238576db0
    r14         ffff97cc1e09b8a8
    r15         0
    rip         ffffffff80ff4542    memcpy+0x42
    cs          8
    rflags      10a06
    rsp         ffffb81238576d78
    ss          10
    netbsd:memcpy+0x42:     repe movsq      (%rsi),%es:(%rdi)
    db{5}> bt
    memcpy() at netbsd:memcpy+0x42
    ipmi_thread() at netbsd:ipmi_thread+0x266

Register rcx went down from 0x1ffffffffffffffe to 0x1ffffffffffffdb6.
memcopy() copied 0x248 qwords when kernel panic happened, while the caller
requested only 0x10 bytes.

OpenBSD has protection for situation when length 0 is returned by
ipmi_recvcmd() in the following two commits:
    https://github.com/openbsd/src/commit/161b560c2729068d28bc2355936eaa73db6298d5
    https://github.com/openbsd/src/commit/2409b544c6ac03fa48a66e98f10a7d5a1373dc83
But those changes are not robust enough, as get_sdr_partial() still reports
invalid NextRecordId in the above error scenario.
Also, with OpenBSD patches, SDR record enumeration stops when failure occurs.

The bug does not happen on every boot. Sometimes it takes 15 reboots to
reproduce the bug.

The bug can also be reproduced with NetBSD-10.1-amd64 USB bootable image.

The fix proposed attempts to re-read SDR data on failure.

Example of error recovery and repeating SDR record read request:

    [  36.1098323] ipmi_sendcmd: rssa=0x20 nfln=0x28 cmd=0x23 len=0x06
    [  36.1198329] ipmi_sendcmd: da 01 16 00 25 10
    [  36.1198329] kcs_sendmsg: 28 23 da 01 16 00 25 10
    [  36.1198329] kcs_write_cmd: 0x61
    [  36.1298324] kcs_write_data: 0x28
    [  36.1298324] kcs_write_data: 0x23
    [  36.1298324] kcs_write_data: 0xda
    [  36.1398325] kcs_write_data: 0x01
    [  36.1398325] kcs_write_data: 0x16
    [  36.1398325] kcs_write_data: 00
    [  36.1498324] kcs_write_data: 0x25
    [  36.1498324] kcs_write_cmd: 0x62
    [  36.1498324] kcs_write_data: 0x10
    [  36.1998338] kcs_read_data: 0x1c
    [  36.2098328] kcs_read_data: 0x34
    [  36.2098328] kcs_read_data: 00
    [  36.2098328] kcs_recvmsg: 1c 34 00
    [  36.2198328] ipmi_recvcmd: ERR: rawlen=0x03 nfln=0x1c cmd=0x34 err=00
    [  36.2198328] ipmi0: get_sdr_partial: recvcmd fails
    [  36.2298324] ipmi_sendcmd: rssa=0x20 nfln=0x28 cmd=0x23 len=0x06
    [  36.2298324] ipmi_sendcmd: da 01 16 00 25 10
    [  36.2398324] kcs_sendmsg: 28 23 da 01 16 00 25 10
    [  36.2398324] kcs_write_cmd: 0x61
    [  36.2498324] kcs_write_data: 0x28
    [  36.2498324] kcs_write_data: 0x23
    [  36.2498324] kcs_write_data: 0xda
    [  36.2598324] kcs_write_data: 0x01
    [  36.2598324] kcs_write_data: 0x16
    [  36.2598324] kcs_write_data: 00
    [  36.2698324] kcs_write_data: 0x25
    [  36.2698324] kcs_write_cmd: 0x62
    [  36.2698324] kcs_write_data: 0x10
    [  36.3098339] kcs_read_data: 0x2c
    [  36.3198328] kcs_read_data: 0x23
    [  36.3198328] kcs_read_data: 00
    [  36.3198328] kcs_read_data: 0x17
    [  36.3298327] kcs_read_data: 00
    [  36.3298327] kcs_read_data: 0x55
    [  36.3298327] kcs_read_data: 0x50
    [  36.3398324] kcs_read_data: 0x80
    [  36.3398324] kcs_read_data: 00
    [  36.3398324] kcs_read_data: 00
    [  36.3398324] kcs_read_data: 0x02
    [  36.3498325] kcs_read_data: 0x02
    [  36.3498325] kcs_read_data: 00
    [  36.3498325] kcs_read_data: 00
    [  36.3598324] kcs_read_data: 00
    [  36.3598324] kcs_read_data: 0xcf
    [  36.3598324] kcs_read_data: 0x54
    [  36.3698324] kcs_read_data: 0x45
    [  36.3698324] kcs_read_data: 0x4d
    [  36.3698324] kcs_read_data: 0x50
    [  36.3798324] kcs_read_data: 0x5f
    [  36.3798324] kcs_recvmsg: 2c 23 00 17 00 55 50 80 00 00 02 02 00 00 00 cf 54 45 4d 50 5f
    [  36.3898323] ipmi_recvcmd: nfln=0x2c cmd=0x23 err=00 len=0x12
    [  36.3898323] ipmi_recvcmd: 17 00 55 50 80 00 00 02 02 00 00 00 cf 54 45 4d 50 5f

>How-To-Repeat:
Boot on a system with BMC controller and ipmi driver enabled.
It might be important to have lots of sensors.
>Fix:
Index: sys/dev/ipmi.c
===================================================================
RCS file: /cvsroot/src/sys/dev/ipmi.c,v
retrieving revision 1.14
diff -u -r1.14 ipmi.c
--- sys/dev/ipmi.c	4 Dec 2024 15:26:07 -0000	1.14
+++ sys/dev/ipmi.c	20 Jul 2025 01:21:11 -0000
@@ -207,12 +207,14 @@
 static	int add_sdr_sensor(struct ipmi_softc *, uint8_t *);
 static	int get_sdr_partial(struct ipmi_softc *, uint16_t, uint16_t,
 	    uint8_t, uint8_t, void *, uint16_t *);
+static	int get_sdr_chunk_with_retry(struct ipmi_softc *, uint16_t, uint16_t,
+	    uint8_t, uint8_t, void *, uint16_t *, int);
 static	int get_sdr(struct ipmi_softc *, uint16_t, uint16_t *);
 
 static	char *ipmi_buf_acquire(struct ipmi_softc *, size_t);
 static	void ipmi_buf_release(struct ipmi_softc *, char *);
 static	int ipmi_sendcmd(struct ipmi_softc *, int, int, int, int, int, const void*);
-static	int ipmi_recvcmd(struct ipmi_softc *, int, int *, void *);
+static	int ipmi_recvcmd(struct ipmi_softc *, int, int, int, int, int *, void *);
 static	void ipmi_delay(struct ipmi_softc *, int);
 
 static	int ipmi_get_device_id(struct ipmi_softc *, struct ipmi_device_id *);
@@ -1049,19 +1051,31 @@
  * ipmi_recvcmd: caller must hold sc_cmd_mtx.
  */
 static int
-ipmi_recvcmd(struct ipmi_softc *sc, int maxlen, int *rxlen, void *data)
+ipmi_recvcmd(struct ipmi_softc *sc, int rslun, int netfn, int cmd, int maxlen,
+    int *rxlen, void *data)
 {
 	uint8_t	*buf, rc = 0;
 	int		rawlen;
 
 	/* Need three extra bytes: netfn/cmd/ccode + data */
-	buf = ipmi_buf_acquire(sc, maxlen + 3);
+	buf = ipmi_buf_acquire(sc, maxlen + IPMI_MSG_DATARCV);
 	if (buf == NULL) {
 		aprint_error_dev(sc->sc_dev, "%s: malloc fails\n", __func__);
 		return -1;
 	}
 	/* Receive message from interface, copy out result data */
-	if (sc->sc_if->recvmsg(sc, maxlen + 3, &rawlen, buf)) {
+	if (sc->sc_if->recvmsg(sc, maxlen + IPMI_MSG_DATARCV, &rawlen, buf)) {
+		ipmi_buf_release(sc, buf);
+		return -1;
+	}
+
+	if (rawlen < IPMI_MSG_DATARCV ||
+	    buf[IPMI_MSG_NFLN] != NETFN_LUN(netfn | 1, rslun) ||
+	    buf[IPMI_MSG_CMD] != cmd) {
+		dbg_printf(1,
+		    "%s: ERR: rawlen=%#.2x nfln=%#.2x cmd=%#.2x err=%#.2x\n",
+		    __func__, rawlen, buf[IPMI_MSG_NFLN], buf[IPMI_MSG_CMD],
+		    buf[IPMI_MSG_CCODE]);
 		ipmi_buf_release(sc, buf);
 		return -1;
 	}
@@ -1131,46 +1145,84 @@
 		aprint_error_dev(sc->sc_dev, "%s: sendcmd fails\n", __func__);
 		return -1;
 	}
-	if (ipmi_recvcmd(sc, 8 + length, &len, &u.msg)) {
+	if (ipmi_recvcmd(sc, 0, STORAGE_NETFN, STORAGE_GET_SDR, 8 + length,
+	    &len, &u.msg)) {
 		mutex_exit(&sc->sc_cmd_mtx);
 		aprint_error_dev(sc->sc_dev, "%s: recvcmd fails\n", __func__);
 		return -1;
 	}
 	mutex_exit(&sc->sc_cmd_mtx);
-	if (nxtRecordId)
-		*nxtRecordId = u.msg.nxtRecordId;
-	memcpy(buffer, u.msg.data, len - offsetof(typeof(u.msg), data));
+	if (len > offsetof(typeof(u.msg), data)) {
+		if (nxtRecordId)
+			*nxtRecordId = u.msg.nxtRecordId;
+		memcpy(buffer, u.msg.data, len - offsetof(typeof(u.msg),
+		    data));
+	} else {
+		aprint_error_dev(sc->sc_dev, "%s: protocol error\n", __func__);
+		return -1;
+	}
 
 	return 0;
 }
 
+/* Read partial SDR with retry on error */
+static int
+get_sdr_chunk_with_retry(struct ipmi_softc *sc, uint16_t recordId,
+    uint16_t reserveId, uint8_t offset, uint8_t length, void *buffer,
+    uint16_t *nxtRecordId, int retry_count)
+{
+	int rc;
+
+	do {
+		rc = get_sdr_partial(sc, recordId, reserveId, offset, length,
+		    buffer, nxtRecordId);
+		if (!rc)
+			break;
+	} while(retry_count--);
+
+	return rc;
+}
+
 static int maxsdrlen = 0x10;
+static int maxretry = 3;
 
 /* Read an entire SDR; pass to add sensor */
 static int
 get_sdr(struct ipmi_softc *sc, uint16_t recid, uint16_t *nxtrec)
 {
 	uint16_t	resid = 0;
-	int		len, sdrlen, offset;
+	int		len, sdrlen, offset, retry_count;
 	uint8_t	*psdr;
 	struct sdrhdr	shdr;
 
 	mutex_enter(&sc->sc_cmd_mtx);
 	/* Reserve SDR */
-	if (ipmi_sendcmd(sc, BMC_SA, 0, STORAGE_NETFN, STORAGE_RESERVE_SDR,
-	    0, NULL)) {
-		mutex_exit(&sc->sc_cmd_mtx);
-		aprint_error_dev(sc->sc_dev, "reserve send fails\n");
-		return -1;
-	}
-	if (ipmi_recvcmd(sc, sizeof(resid), &len, &resid)) {
-		mutex_exit(&sc->sc_cmd_mtx);
-		aprint_error_dev(sc->sc_dev, "reserve recv fails\n");
-		return -1;
-	}
+	retry_count = maxretry;
+	do {
+		len = 0;
+		if (ipmi_sendcmd(sc, BMC_SA, 0, STORAGE_NETFN,
+		    STORAGE_RESERVE_SDR, 0, NULL)) {
+			aprint_error_dev(sc->sc_dev, "reserve send fails\n");
+			continue;
+		}
+		if (ipmi_recvcmd(sc, 0, STORAGE_NETFN, STORAGE_RESERVE_SDR,
+		    sizeof(resid), &len, &resid)) {
+			aprint_error_dev(sc->sc_dev, "reserve recv fails\n");
+			continue;
+		}
+		if (len == 2)
+			break;
+		else
+			aprint_error_dev(sc->sc_dev, "%s: protocol error\n", __func__);
+	} while (retry_count--);
 	mutex_exit(&sc->sc_cmd_mtx);
+
+	if (len != 2)
+		return -1;
+
 	/* Get SDR Header */
-	if (get_sdr_partial(sc, recid, resid, 0, sizeof shdr, &shdr, nxtrec)) {
+	if (get_sdr_chunk_with_retry(sc, recid, resid, 0, sizeof shdr, &shdr,
+	    nxtrec, maxretry)) {
 		aprint_error_dev(sc->sc_dev, "get header fails\n");
 		return -1;
 	}
@@ -1189,8 +1241,8 @@
 		if (len > maxsdrlen)
 			len = maxsdrlen;
 
-		if (get_sdr_partial(sc, recid, resid, offset, len,
-		    psdr + offset, NULL)) {
+		if (get_sdr_chunk_with_retry(sc, recid, resid, offset, len,
+		    psdr + offset, NULL, maxretry)) {
 			aprint_error_dev(sc->sc_dev,
 			    "get chunk : %d,%d fails\n", offset, len);
 			free(psdr, M_DEVBUF);
@@ -1569,7 +1621,8 @@
 	failure =
 	    ipmi_sendcmd(sc, s1->owner_id, s1->owner_lun,
 			 SE_NETFN, SE_GET_SENSOR_THRESHOLD, 1, data) ||
-	    ipmi_recvcmd(sc, sizeof(data), &rxlen, data);
+	    ipmi_recvcmd(sc, s1->owner_lun, SE_NETFN, SE_GET_SENSOR_THRESHOLD,
+			 sizeof(data), &rxlen, data);
 	mutex_exit(&sc->sc_cmd_mtx);
 	if (failure)
 		return;
@@ -1720,7 +1773,8 @@
 	    SE_GET_SENSOR_READING, 1, data))
 		goto err;
 
-	if (ipmi_recvcmd(sc, sizeof(data), &rxlen, data))
+	if (ipmi_recvcmd(sc, s1->owner_lun, SE_NETFN, SE_GET_SENSOR_READING,
+	    sizeof(data), &rxlen, data))
 		goto err;
 	mutex_exit(&sc->sc_cmd_mtx);
 
@@ -2242,7 +2296,8 @@
 		    "command\n");
 		goto done;
 	}
-	rc = ipmi_recvcmd(sc, sizeof(buf), &len, buf);
+	rc = ipmi_recvcmd(sc, 0, APP_NETFN, APP_GET_DEVICE_ID, sizeof(buf),
+	    &len, buf);
 	if (rc) {
 		dbg_printf(1, ": unable to retrieve device id\n");
 	}
@@ -2283,7 +2338,8 @@
 	/* see if we can properly task to the watchdog */
 	rc = ipmi_sendcmd(sc, BMC_SA, BMC_LUN, APP_NETFN,
 	    APP_GET_WATCHDOG_TIMER, 0, NULL);
-	rc = ipmi_recvcmd(sc, sizeof(gwdog), &len, &gwdog);
+	rc = ipmi_recvcmd(sc, BMC_LUN, APP_NETFN, APP_GET_WATCHDOG_TIMER,
+	    sizeof(gwdog), &len, &gwdog);
 	mutex_exit(&sc->sc_cmd_mtx);
 	if (rc) {
 		aprint_error_dev(sc->sc_dev,
@@ -2303,7 +2359,8 @@
 	mutex_enter(&sc->sc_cmd_mtx);
 	if ((rc = ipmi_sendcmd(sc, BMC_SA, BMC_LUN, APP_NETFN,
 	    APP_SET_WATCHDOG_TIMER, sizeof(swdog), &swdog)) == 0)
-		rc = ipmi_recvcmd(sc, 0, &len, NULL);
+		rc = ipmi_recvcmd(sc, BMC_LUN, APP_NETFN,
+		    APP_SET_WATCHDOG_TIMER, 0, &len, NULL);
 	mutex_exit(&sc->sc_cmd_mtx);
 	if (rc) {
 		aprint_error_dev(sc->sc_dev,
@@ -2335,7 +2392,8 @@
 	/* tickle the watchdog */
 	if ((rc = ipmi_sendcmd(sc, BMC_SA, BMC_LUN, APP_NETFN,
 	    APP_RESET_WATCHDOG, 0, NULL)) == 0)
-		rc = ipmi_recvcmd(sc, 0, &len, NULL);
+		rc = ipmi_recvcmd(sc, BMC_LUN, APP_NETFN, APP_RESET_WATCHDOG,
+		    0, &len, NULL);
 	mutex_exit(&sc->sc_cmd_mtx);
 	if (rc != 0) {
 		aprint_error_dev(sc->sc_dev, "watchdog tickle returned %#x\n",
@@ -2430,7 +2488,8 @@
 
 		/* clear pending result */
 		if (sc->sc_sent)
-			(void)ipmi_recvcmd(sc, IPMI_MAX_RX, &len, buf);
+			(void)ipmi_recvcmd(sc, 0, sc->sc_netfn, sc->sc_cmd,
+			    IPMI_MAX_RX, &len, buf);
 
 		/* XXX */
 		error = copyin(req->addr, &addr, sizeof(addr));
@@ -2475,7 +2534,8 @@
 		}
 
 		len = 0;
-		error = ipmi_recvcmd(sc, IPMI_MAX_RX, &len, buf);
+		error = ipmi_recvcmd(sc, 0, sc->sc_netfn, sc->sc_cmd,
+		    IPMI_MAX_RX, &len, buf);
 		if (error < 0) {
 			error = EIO;
 			break;



Home | Main Index | Thread Index | Old Index