Folks, I'm puzzling at an odd performance behavior that I see with various versions of the OpenIPMI drivers.
This is on a Dell PowerEdge 1800. The OS is VMware ESX 3.0.1, specifically its Console OS portion which is a modified Linux 2.4.21 (based on RHEL3). The IPMI drivers are various tweaked versions based on Corey's v35, v37 and v39 releases. I don't believe the driver is using IPMI interrupts in any incarnation. Some of the drivers I'm poking at have the "kipmi0" kernel thread, some do not. Performance differs greatly between those versions, but in all cases there is an anomaly. This anomaly is visible when watching the output of `ipmitool sdr` or especially `ipmitool sensor`. For "sdr", what I see is that it takes an exceptionally long time to read one particular sensor (ECC Corr Err). For "sensor", that sensor _and_ all subsequent ones are slow. Following is output which shows the problem. Each of these outputs is tagged with '#' characters representing elapsed time; the mechanism for this is displayed. I have also edited the tabular output to make it readable (eliminating some white space, '.000' at the end of numbers, etc. -- no material changes). The first output is from the VMware ESX 3.0.1 standard IPMI driver (calls itself "version 37", has no kernel thread). Each '#' represents one second: # while :; do echo -n \#; sleep 1; done & ipmitool sdr [1] 15411 ###Temp | 47 degrees C | ok ##Temp | 42 degrees C | ok #Ambient Temp | 20 degrees C | ok ##Planar Temp | 33 degrees C | ok ##VRD 0 Temp | 36 degrees C | ok #VRD 1 Temp | 35 degrees C | ok ##Temp | 40 degrees C | ok #Temp | 40 degrees C | ok ##CMOS Battery | 3.04 Volts | ok #VCORE | 0x01 | ok #VCORE | 0x01 | ok ##PROC VTT | 0x01 | ok #1.5V PG | 0x01 | ok #1.8V PG | 0x01 | ok #3.3V PG | 0x01 | ok #5V PG | 0x01 | ok ##Presence | 0x01 | ok #Presence | 0x01 | ok #Presence | Not Readable | ns #Presence | Not Readable | ns ##Fan 1 | 1500 RPM | ok ##Fan 2 | 1425 RPM | ok #Status | 0x80 | ok #Status | 0x80 | ok #Status | Not Readable | ns #Status | Not Readable | ns ##VRM | 0x01 | ok #VRM | 0x01 | ok #OS Watchdog | 0x00 | ok #SEL | Not Readable | ns ##Intrusion | 0x00 | ok #PS Redundancy | Not Readable | ns #Drive | 0x00 | ok ########ECC Corr Err | 0xc0 | ok #ECC Uncorr Err | 0xc0 | ok #I/O Channel Chk | 0xc0 | ok #PCI Parity Err | 0xc0 | ok ##PCI System Err | 0xc0 | ok #SBE Log Disabled | 0xc0 | ok ##Logging Disabled | Not Readable | ns #Unknown | Not Readable | ns #PROC Protocol | Not Readable | ns #PROC Bus PERR | Not Readable | ns ##PROC Init Err | Not Readable | ns #PROC Machine Chk | Not Readable | ns ##Memory Spared | 0x01 | ok #Memory Mirrored | 0x01 | ok #Memory RAID | 0x01 | ok #Memory Added | 0x01 | ok ##Memory Removed | 0x01 | ok #PCIE Fatal Err | Not Readable | ns #Chipset Err | Not Readable | ns #Err Reg Pointer | Not Readable | ns Notice the anomalously long time for "ECC Corr Err". Next we have similar output from Corey's recent "v39" backport to Linux 2.4. For this much faster driver, each '#' represents a small amount of time (about 1/30 second): # while :; do echo -n \#; sleep .01; done & ipmitool sdr [1] 15706 #####Temp | 47 degrees C | ok ##Temp | 42 degrees C | ok ##Ambient Temp | 20 degrees C | ok ##Planar Temp | 33 degrees C | ok ##VRD 0 Temp | 36 degrees C | ok ##VRD 1 Temp | 35 degrees C | ok ##Temp | 40 degrees C | ok ##Temp | 40 degrees C | ok ##CMOS Battery | 3.06 Volts | ok #VCORE | 0x01 | ok ##VCORE | 0x01 | ok ##PROC VTT | 0x01 | ok #1.5V PG | 0x01 | ok ##1.8V PG | 0x01 | ok ##3.3V PG | 0x01 | ok ##5V PG | 0x01 | ok ##Presence | 0x01 | ok #Presence | 0x01 | ok ##Presence | Not Readable | ns ##Presence | Not Readable | ns ##Fan 1 | 1500 RPM | ok ##Fan 2 | 1500 RPM | ok #Status | 0x80 | ok ##Status | 0x80 | ok ##Status | Not Readable | ns #Status | Not Readable | ns ##VRM | 0x01 | ok ##VRM | 0x01 | ok #OS Watchdog | 0x00 | ok ##SEL | Not Readable | ns ##Intrusion | 0x00 | ok #PS Redundancy | Not Readable | ns ##Drive | 0x00 | ok ##########ECC Corr Err | 0xc0 | ok ##ECC Uncorr Err | 0xc0 | ok #I/O Channel Chk | 0xc0 | ok ##PCI Parity Err | 0xc0 | ok ##PCI System Err | 0xc0 | ok ##SBE Log Disabled | 0xc0 | ok ##Logging Disabled | Not Readable | ns #Unknown | Not Readable | ns ##PROC Protocol | Not Readable | ns ##PROC Bus PERR | Not Readable | ns #PROC Init Err | Not Readable | ns ##PROC Machine Chk | Not Readable | ns ##Memory Spared | 0x01 | ok ##Memory Mirrored | 0x01 | ok #Memory RAID | 0x01 | ok ##Memory Added | 0x01 | ok ##Memory Removed | 0x01 | ok #PCIE Fatal Err | Not Readable | ns ##Chipset Err | Not Readable | ns ##Err Reg Pointer | Not Readable | ns Same anomaly, in fast motion. Finally, again using Corey's v39, here is output of a full `ipmitool sensor`: # while :; do echo -n \#; sleep .01; done & ipmitool sensor [1] 15904 #####Temp |47.0 |degreesC|ok |na |na |na |120.0 |125.0|na ###Temp |42.0 |degreesC|ok |na |na |na |120.0 |125.0|na ##Ambient Temp |20.0 |degreesC|ok |na |3.0 |8.0|40.0 |45.0 |na ##Planar Temp |33.0 |degreesC|ok |na |3.0 |8.0|62.0 |67.0 |na ##VRD 0 Temp |36.0 |degreesC|ok |na |3.0 |8.0|70.0 |75.0 |na ###VRD 1 Temp |35.0 |degreesC|ok |na |3.0 |8.0|70.0 |75.0 |na ##Temp |40.0 |degreesC|ok |64.0|na |0.0|-128.0|na |na ##Temp |40.0 |degreesC|ok |64.0|na |0.0|-128.0|na |na ###CMOS Battery |3.044 |Volts |ok |na |2.645|na |na |na |na #VCORE |0x0 |discrete|0x0180|na |na |na |na |na |na ##VCORE |0x0 |discrete|0x0180|na |na |na |na |na |na ##PROC VTT |0x0 |discrete|0x0180|na |na |na |na |na |na #1.5V PG |0x0 |discrete|0x0180|na |na |na |na |na |na ##1.8V PG |0x0 |discrete|0x0180|na |na |na |na |na |na ##3.3V PG |0x0 |discrete|0x0180|na |na |na |na |na |na #5V PG |0x0 |discrete|0x0180|na |na |na |na |na |na ##Presence |0x0 |discrete|0x0180|na |na |na |na |na |na ##Presence |0x0 |discrete|0x0180|na |na |na |na |na |na #Presence |0x0 |discrete|0x0180|na |na |na |na |na |na ##Presence |0x0 |discrete|0x0180|na |na |na |na |na |na ##Fan 1 |1500.0|RPM |ok |na |750.0|na |na |na |na ##Fan 2 |1425.0|RPM |ok |na |675.0|na |na |na |na ##Status |0x0 |discrete|0x8080|na |na |na |na |na |na ##Status |0x0 |discrete|0x8080|na |na |na |na |na |na #Status |0x0 |discrete|0x0080|na |na |na |na |na |na ##Status |0x0 |discrete|0x0080|na |na |na |na |na |na ##VRM |0x0 |discrete|0x0180|na |na |na |na |na |na #VRM |0x0 |discrete|0x0180|na |na |na |na |na |na ##OS Watchdog |0x0 |discrete|0x0080|na |na |na |na |na |na ##SEL |na |discrete|na |na |na |na |na |na |na #Intrusion |0x0 |discrete|0x0080|na |na |na |na |na |na ##PS Redundancy |0x0 |discrete|0x0080|na |na |na |na |na |na ##Drive |0x0 |discrete|0x0080|na |na |na |na |na |na ##############ECC Corr Err|na |discrete|na |na |na |na |na |na |na #####ECC Uncorr Err |na |discrete|na |na |na |na |na |na |na #####I/O Channel Chk |na |discrete|na |na |na |na |na |na |na ######PCI Parity Err |na |discrete|na |na |na |na |na |na |na #####PCI System Err |na |discrete|na |na |na |na |na |na |na ######SBE Log Disabled |na |discrete|na |na |na |na |na |na |na ######Logging Disabled |na |discrete|na |na |na |na |na |na |na #####Unknown |na |discrete|na |na |na |na |na |na |na ######PROC Protocol |na |discrete|na |na |na |na |na |na |na #####PROC Bus PERR |na |discrete|na |na |na |na |na |na |na ######PROC Init Err |na |discrete|na |na |na |na |na |na |na ######PROC Machine Chk |na |discrete|na |na |na |na |na |na |na ######Memory Spared |na |discrete|na |na |na |na |na |na |na #####Memory Mirrored |na |discrete|na |na |na |na |na |na |na ######Memory RAID |na |discrete|na |na |na |na |na |na |na #####Memory Added |na |discrete|na |na |na |na |na |na |na ######Memory Removed |na |discrete|na |na |na |na |na |na |na ######PCIE Fatal Err |na |discrete|na |na |na |na |na |na |na #####Chipset Err |na |discrete|na |na |na |na |na |na |na ######Err Reg Pointer |na |discrete|na |na |na |na |na |na |na Notice how "ECC Corr Err" and all following sensors are much slower then the preceding ones. I have a hunch this is being caused by some driver glitch, not by hardware behavior. It looks like something about the "ECC Corr Err" sensor is making the driver forget it's collecting input, so that it falls back to timer tick polling. Just a guess... might also be something about this machine's BMC. I do note that Matt Domsch claimed the kernel thread sped `ipmitool sensor` up to about 5 seconds realtime, which is about what I'm seeing. I would imagine he's using similar hardware (or was, back when he developed the patch). This machine would finish in < 2.5s if all sensors were as fast as the first group. Using `strace -T`, I see the following. This is from the last example (v39, `sensor`): ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed70) = 0 <0.000011> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009704> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedc0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.010175> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000008> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009853> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009449> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000009> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed50) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009758> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffeda0) = 0 <0.000007> write(1, "Drive | 0x0 | "..., 124) = 124 <0.000488> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed70) = 0 <0.000011> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.004845> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedc0) = 0 <0.000009> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.010246> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009850> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed80) = 0 <0.000008> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.009829> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffedd0) = 0 <0.000008> ioctl(3, IPMICTL_SEND_COMMAND, 0xbfffed50) = 0 <0.000009> select(4, [3], NULL, NULL, NULL) = 1 (in [3]) <0.124139> ioctl(3, IPMICTL_RECEIVE_MSG_TRUNC, 0xbfffeda0) = 0 <0.000008> write(1, "ECC Uncorr Err | na | "..., 124) = 124 <0.000229> For all sensors before "ECC Corr Err", that final select() completes in about 10ms (range: 7.634-11.125ms). For all later sensors, it completes in about 125ms (range: 115.528-143.657ms). I also note that IPMI_TIMEOUT_TIME == 100ms in this driver build. Driver startup reports one of: Nov 27 11:45:48 blubkin-esx kernel: ipmi message handler version 37 Nov 27 11:45:48 blubkin-esx kernel: IPMI System Interface driver version 37, KCS version 37, SMIC version 37, BT version 37 Nov 27 11:45:48 blubkin-esx kernel: ipmi_si: Found SMBIOS-specified state machine at I/O address 0xca8 Nov 27 11:45:50 blubkin-esx kernel: IPMI kcs interface [0] initialized Nov 27 11:45:50 blubkin-esx kernel: ipmi device interface version 37 Nov 27 11:49:04 blubkin-esx kernel: ipmi message handler version 39 Nov 27 11:49:04 blubkin-esx kernel: IPMI System Interface driver version 39, KCS version 39, SMIC version 39, BT version 39 Nov 27 11:49:04 blubkin-esx kernel: ipmi_si: Found SMBIOS-specified state machine at I/O address 0xca8 Nov 27 11:49:04 blubkin-esx kernel: IPMI kcs interface initialized Nov 27 11:49:04 blubkin-esx kernel: ipmi device interface version 39 Nov 27 11:49:04 blubkin-esx ipmi: succeeded Thoughts? Whoops, just panic'd the machine I was testing on, d'oh! >Bela< ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys - and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ Openipmi-developer mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/openipmi-developer
