atom feed1 message in org.freebsd.freebsd-stablesmp_tlb_shootdown bottleneck?
FromSent OnAttachments
pluknetJan 28, 2009 8:05 am 
Subject:smp_tlb_shootdown bottleneck?
From:pluknet (pluk@gmail.com)
Date:Jan 28, 2009 8:05:24 am
List:org.freebsd.freebsd-stable

Hi.

Sometimes I see much contention in smp_tlb_shootdown while running sysbench: sysbench --test=fileio --num-threads=8 --file-test-mode=rndrd --file-total-size=3G run

kern.smp.cpus: 8 FreeBSD 7.1-R

CPU: 0.8% user, 0.0% nice, 93.8% system, 0.0% interrupt, 5.4% idle Mem: 11M Active, 2873M Inact, 282M Wired, 8K Cache, 214M Buf, 765M Free Swap: 4096M Total, 4096M Free

PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND 810 root 115 0 11568K 2408K RUN 3 0:04 89.60% sysbench 810 root 114 0 11568K 2408K CPU0 0 0:18 87.06% sysbench 810 root 114 0 11568K 2408K CPU2 2 0:18 86.67% sysbench 810 root 114 0 11568K 2408K CPU6 6 0:18 84.47% sysbench 810 root 114 0 11568K 2408K CPU3 3 0:04 84.08% sysbench 810 root 114 0 11568K 2408K CPU7 7 0:17 81.69% sysbench 810 root 113 0 11568K 2408K CPU4 4 0:17 78.08% sysbench 810 root 113 0 11568K 2408K CPU1 1 0:17 77.88% sysbench

This high system load appears from time to time. Usually this sysbench test passed in a few seconds, and at this time it runs in more than 10 seconds.

breaking to ddb while seen too much system load shows many sysbench threads waiting for a mutex in smp_tlb_shootdown:

db> bt 100133 Tracing pid 810 tid 100133 td 0xffffff00032d56e0 cpustop_handler() at cpustop_handler+0x40 ipi_nmi_handler() at ipi_nmi_handler+0x30 trap() at trap+0x378 nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip = 0xffffffff8074c912, rsp = 0xffffffffab79fff0, rbp = 0xffffffffb4acf6f0 --- smp_tlb_shootdown() at smp_tlb_shootdown+0x82 pmap_invalidate_range() at pmap_invalidate_range+0xae vfs_vmio_release() at vfs_vmio_release+0x120 getnewbuf() at getnewbuf+0x7be getblk() at getblk+0x308 cluster_read() at cluster_read+0xc5 ffs_read() at ffs_read+0x37d vn_read() at vn_read+0x17b dofileread() at dofileread+0xa1 kern_preadv() at kern_preadv+0x66 pread() at pread+0x58 syscall() at syscall+0x1ce Xfast_syscall() at Xfast_syscall+0xab --- syscall (475, FreeBSD ELF64, pread), rip = 0x800cf7b5c, rsp = 0x7ffffeff8e78, rbp = 0x7ffffeff8f60 --- db> bt 100132 Tracing pid 810 tid 100132 td 0xffffff00036426e0 cpustop_handler() at cpustop_handler+0x40 ipi_nmi_handler() at ipi_nmi_handler+0x30 trap() at trap+0x378 nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip = 0xffffffff8048b49c, rsp = 0xffffffff80b564b0, rbp = 0xffffffffb4aca680 --- _mtx_lock_spin() at _mtx_lock_spin+0x6c _mtx_lock_spin_flags() at _mtx_lock_spin_flags+0x124 smp_tlb_shootdown() at smp_tlb_shootdown+0x58 pmap_invalidate_range() at pmap_invalidate_range+0xae vfs_vmio_release() at vfs_vmio_release+0x120 getnewbuf() at getnewbuf+0x7be getblk() at getblk+0x308 cluster_read() at cluster_read+0xc5 ffs_read() at ffs_read+0x37d vn_read() at vn_read+0x17b dofileread() at dofileread+0xa1 kern_preadv() at kern_preadv+0x66 pread() at pread+0x58 syscall() at syscall+0x1ce Xfast_syscall() at Xfast_syscall+0xab --- syscall (475, FreeBSD ELF64, pread), rip = 0x800cf7b5c, rsp = 0x7fffff1f9e78, rbp = 0x7fffff1f9f60 --- db> bt 100131 Tracing pid 810 tid 100131 td 0xffffff0003a75000 cpustop_handler() at cpustop_handler+0x40 ipi_nmi_handler() at ipi_nmi_handler+0x30 trap() at trap+0x378 nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip = 0xffffffff8048b4a1, rsp = 0xffffffffab7a4ff0, rbp = 0xffffffffb4ac5680 --- _mtx_lock_spin() at _mtx_lock_spin+0x71 _mtx_lock_spin_flags() at _mtx_lock_spin_flags+0x124 smp_tlb_shootdown() at smp_tlb_shootdown+0x58 pmap_invalidate_range() at pmap_invalidate_range+0xae vfs_vmio_release() at vfs_vmio_release+0x120 getnewbuf() at getnewbuf+0x7be getblk() at getblk+0x308 cluster_read() at cluster_read+0xc5 ffs_read() at ffs_read+0x37d vn_read() at vn_read+0x17b dofileread() at dofileread+0xa1 kern_preadv() at kern_preadv+0x66 pread() at pread+0x58 syscall() at syscall+0x1ce Xfast_syscall() at Xfast_syscall+0xab --- syscall (475, FreeBSD ELF64, pread), rip = 0x800cf7b5c, rsp = 0x7fffff3fae78, rbp = 0x7fffff3faf60 ---

Is that a normal behavior and if yes then how can I help with that?