Slawa Olhovchenkov
2016-Mar-06 19:45 UTC
kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains.
I am use 10-STABLE r295539 and LSI SAS2008. mps0: <Avago Technologies (LSI) SAS2008> port 0x8000-0x80ff mem 0xdfc00000-0xdfc03fff,0xdfb80000-0xdfbbffff irq 32 at device 0.0 on pci2 mps0: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd mps0: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> mps1: <Avago Technologies (LSI) SAS2008> port 0x7000-0x70ff mem 0xdf600000-0xdf603fff,0xdf580000-0xdf5bffff irq 34 at device 0.0 on pci3 mps1: Firmware: 17.00.01.00, Driver: 20.00.00.00-fbsd mps1: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> mps2: <Avago Technologies (LSI) SAS2008> port 0xf000-0xf0ff mem 0xfba00000-0xfba03fff,0xfb980000-0xfb9bffff irq 50 at device 0.0 on pci129 mps2: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd mps2: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> mps3: <Avago Technologies (LSI) SAS2008> port 0xe000-0xe0ff mem 0xfb400000-0xfb403fff,0xfb380000-0xfb3bffff irq 56 at device 0.0 on pci130 mps3: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd mps3: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> Some time ago I am see in log messages like this: Mar 6 22:28:27 edge02 kernel: mps3: Out of chain frames, consider increasing hw.mps.max_chains. Mar 6 22:28:28 edge02 kernel: mps1: Out of chain frames, consider increasing hw.mps.max_chains. Mar 6 22:28:28 edge02 kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains. Mar 6 22:29:39 edge02 kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains. Mar 6 22:30:07 edge02 kernel: mps3: Out of chain frames, consider increasing hw.mps.max_chains. Mar 6 22:30:09 edge02 kernel: mps1: Out of chain frames, consider increasing hw.mps.max_chains. This is peak hour. I am try to monitoring: root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active dev.mps.3.chain_free: 70 dev.mps.3.io_cmds_active: 901 dev.mps.2.chain_free: 504 dev.mps.2.io_cmds_active: 725 dev.mps.1.chain_free: 416 dev.mps.1.io_cmds_active: 896 dev.mps.0.chain_free: 39 dev.mps.0.io_cmds_active: 12 root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active dev.mps.3.chain_free: 412 dev.mps.3.io_cmds_active: 572 dev.mps.2.chain_free: 718 dev.mps.2.io_cmds_active: 687 dev.mps.1.chain_free: 211 dev.mps.1.io_cmds_active: 906 dev.mps.0.chain_free: 65 dev.mps.0.io_cmds_active: 144 root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active dev.mps.3.chain_free: 500 dev.mps.3.io_cmds_active: 629 dev.mps.2.chain_free: 623 dev.mps.2.io_cmds_active: 676 dev.mps.1.chain_free: 251 dev.mps.1.io_cmds_active: 907 dev.mps.0.chain_free: 139 dev.mps.0.io_cmds_active: 144 [...] root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active dev.mps.3.chain_free: 1874 dev.mps.3.io_cmds_active: 78 dev.mps.2.chain_free: 1888 dev.mps.2.io_cmds_active: 64 dev.mps.1.chain_free: 1922 dev.mps.1.io_cmds_active: 42 dev.mps.0.chain_free: 1936 dev.mps.0.io_cmds_active: 48 root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active dev.mps.3.chain_free: 1890 dev.mps.3.io_cmds_active: 78 dev.mps.2.chain_free: 1890 dev.mps.2.io_cmds_active: 82 dev.mps.1.chain_free: 1729 dev.mps.1.io_cmds_active: 150 dev.mps.0.chain_free: 1893 dev.mps.0.io_cmds_active: 57 What this mean? Why with allocated 2048 chains per controller I see 65 free and 144 allocated? How I got 976 active commands? I am use SATA HDD suported only 32 tags on NCQ, with 8 ports this maximum 256 outstanding commands per controller. How I can resolve this issue?
Scott Long
2016-Mar-06 21:10 UTC
kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains.
Hi, The message is harmless, it's a reminder that you should tune the kernel for your workload. When the message is triggered, it means that a potential command was deferred, likely for only a few microseconds, and then everything moved on as normal. A command uses anywhere from 0 to a few dozen chain frames per I/o, depending on the size of the io. The chain frame memory is allocated at boot so that it's always available, not allocated on the fly. When I wrote this driver, I felt that it would be wasteful to reserve memory for a worst case scenario of all large io's by default, so I put in this deferral system with a console reminder to for tuning. Yes, you actually do have 900 io's outstanding. The controller buffers the io requests and allows the system to queue up much more than what sata disks might allow on their own. It's debatable if this is good or bad, but it's tunable as well. Anyways, the messages should not cause alarm. Either tune up the chain frame count, or tune down the max io count. Scott Sent from my iPhone> On Mar 6, 2016, at 11:45 AM, Slawa Olhovchenkov <slw at zxy.spb.ru> wrote: > > I am use 10-STABLE r295539 and LSI SAS2008. > > mps0: <Avago Technologies (LSI) SAS2008> port 0x8000-0x80ff mem 0xdfc00000-0xdfc03fff,0xdfb80000-0xdfbbffff irq 32 at device 0.0 on pci2 > mps0: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd > mps0: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> > mps1: <Avago Technologies (LSI) SAS2008> port 0x7000-0x70ff mem 0xdf600000-0xdf603fff,0xdf580000-0xdf5bffff irq 34 at device 0.0 on pci3 > mps1: Firmware: 17.00.01.00, Driver: 20.00.00.00-fbsd > mps1: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> > mps2: <Avago Technologies (LSI) SAS2008> port 0xf000-0xf0ff mem 0xfba00000-0xfba03fff,0xfb980000-0xfb9bffff irq 50 at device 0.0 on pci129 > mps2: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd > mps2: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> > mps3: <Avago Technologies (LSI) SAS2008> port 0xe000-0xe0ff mem 0xfb400000-0xfb403fff,0xfb380000-0xfb3bffff irq 56 at device 0.0 on pci130 > mps3: Firmware: 15.00.00.00, Driver: 20.00.00.00-fbsd > mps3: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR> > > Some time ago I am see in log messages like this: > > Mar 6 22:28:27 edge02 kernel: mps3: Out of chain frames, consider increasing hw.mps.max_chains. > Mar 6 22:28:28 edge02 kernel: mps1: Out of chain frames, consider increasing hw.mps.max_chains. > Mar 6 22:28:28 edge02 kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains. > Mar 6 22:29:39 edge02 kernel: mps0: Out of chain frames, consider increasing hw.mps.max_chains. > Mar 6 22:30:07 edge02 kernel: mps3: Out of chain frames, consider increasing hw.mps.max_chains. > Mar 6 22:30:09 edge02 kernel: mps1: Out of chain frames, consider increasing hw.mps.max_chains. > > This is peak hour. I am try to monitoring: > > root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active > dev.mps.3.chain_free: 70 > dev.mps.3.io_cmds_active: 901 > dev.mps.2.chain_free: 504 > dev.mps.2.io_cmds_active: 725 > dev.mps.1.chain_free: 416 > dev.mps.1.io_cmds_active: 896 > dev.mps.0.chain_free: 39 > dev.mps.0.io_cmds_active: 12 > root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active > dev.mps.3.chain_free: 412 > dev.mps.3.io_cmds_active: 572 > dev.mps.2.chain_free: 718 > dev.mps.2.io_cmds_active: 687 > dev.mps.1.chain_free: 211 > dev.mps.1.io_cmds_active: 906 > dev.mps.0.chain_free: 65 > dev.mps.0.io_cmds_active: 144 > root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active > dev.mps.3.chain_free: 500 > dev.mps.3.io_cmds_active: 629 > dev.mps.2.chain_free: 623 > dev.mps.2.io_cmds_active: 676 > dev.mps.1.chain_free: 251 > dev.mps.1.io_cmds_active: 907 > dev.mps.0.chain_free: 139 > dev.mps.0.io_cmds_active: 144 > > [...] > > root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active > dev.mps.3.chain_free: 1874 > dev.mps.3.io_cmds_active: 78 > dev.mps.2.chain_free: 1888 > dev.mps.2.io_cmds_active: 64 > dev.mps.1.chain_free: 1922 > dev.mps.1.io_cmds_active: 42 > dev.mps.0.chain_free: 1936 > dev.mps.0.io_cmds_active: 48 > root at edge02:/ # sysctl dev.mps | grep -e chain_free: -e io_cmds_active > dev.mps.3.chain_free: 1890 > dev.mps.3.io_cmds_active: 78 > dev.mps.2.chain_free: 1890 > dev.mps.2.io_cmds_active: 82 > dev.mps.1.chain_free: 1729 > dev.mps.1.io_cmds_active: 150 > dev.mps.0.chain_free: 1893 > dev.mps.0.io_cmds_active: 57 > > What this mean? Why with allocated 2048 chains per controller I see 65 free and 144 allocated? > How I got 976 active commands? I am use SATA HDD suported only 32 tags on NCQ, with 8 ports > this maximum 256 outstanding commands per controller. > > How I can resolve this issue? > _______________________________________________ > freebsd-stable at freebsd.org mailing list > https://lists.freebsd.org/mailman/listinfo/freebsd-stable > To unsubscribe, send any mail to "freebsd-stable-unsubscribe at freebsd.org"