From owner-freebsd-hackers@FreeBSD.ORG Mon Mar 4 20:58:01 2013 Return-Path: Delivered-To: hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by hub.freebsd.org (Postfix) with ESMTP id CA661522 for ; Mon, 4 Mar 2013 20:58:01 +0000 (UTC) (envelope-from nevans@talkpoint.com) Received: from mailbox.talkpoint.com (mailbox.talkpoint.com [204.141.10.74]) by mx1.freebsd.org (Postfix) with ESMTP id 5A1DD1489 for ; Mon, 4 Mar 2013 20:58:01 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by mailbox.talkpoint.com (Postfix) with ESMTP id E5213F66003 for ; Mon, 4 Mar 2013 15:50:22 -0500 (EST) X-Virus-Scanned: amavisd-new at talkpoint.com Received: from mailbox.talkpoint.com ([127.0.0.1]) by localhost (mailbox.talkpoint.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id qK+XDB-wVVqN for ; Mon, 4 Mar 2013 15:50:21 -0500 (EST) Received: from pleiades.nextvenue.com (pleiades.nextvenue.com [204.141.15.194]) by mailbox.talkpoint.com (Postfix) with ESMTP id 11D04F66001 for ; Mon, 4 Mar 2013 15:50:21 -0500 (EST) Date: Mon, 4 Mar 2013 15:50:20 -0500 From: Nick Evans To: hackers@freebsd.org Subject: MySQL Data_free = 0 Slowness (appending to files slow?) Message-ID: <20130304155020.77e470da@pleiades.nextvenue.com> X-Mailer: Claws Mail 3.8.0 (GTK+ 2.24.6; amd64-portbld-freebsd9.0) Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 04 Mar 2013 20:58:01 -0000 Hackers, I ran into this issue while setting up a performance testing environment with MySQL 5.6/MyISAM tables. I have an arbitrarily sized test table, in this case with a base number of rows over 1 million. When I insert new rows into this table with super-smack, and the on disk table file is full (Data_free=0 in SHOW TABLE STATUS;), I see an average queries per second of around 1500-1600. If I then delete a subset of the table's rows, reboot the test environment, and rerun my super-smack inserts, I'll see an average qps of 8000 until the table fills up again. In this second state, the on-disk MyISAM table file is not full, ie, Data_free is some non-zero value as reported by SHOW TABLE STATUS;. I'm assuming mysqld is just seeking to a spot and writing in this case vs whatever append operation has to be done by the OS when there's no more space in the table file. I'm not entirely sure where the problem lies, but I've tried this with SU+J, SU, a MD device, async, noatime, etc and have not found a way to speed up the case where I'm appending to the table file. I've also tried dumping indexes from the table to make sure they were not interfering, no change. I have ktraces showing mysqld doing the same number of pwrite operations for my test inserts when the table file is full vs not. The test system is running 9-STABLE from last week, and is an 8 core, dual package Xeon with 24GB ram, an LSI 9260-8i with two volumes, one raid1, one raid6 both using Raptor 300's. I'm aware of raid6's write speed issues, but the limiting factor here does not appear to be the card or the disks/arrays based on how well it performs in the "fast" case. I've started to look at DTrace to maybe help diagnose the problem but I still have to learn enough of it to be useful and I can't seem to get mysql56-server to compile with DTrace. The kernel is GENERIC with DTRACE hooks added. I'd appreciate any help you guys and gals can offer. Thanks, Nick iostat (slow case): tty mfid0 mfid1 cd0 cpu tin tout KB/t tps MB/s KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 479 0.00 0 0.00 80.00 2 0.16 0.00 0 0.00 11 0 1 0 88 0 1723 0.00 0 0.00 128.00 2 0.25 0.00 0 0.00 11 0 0 0 89 0 442 0.00 0 0.00 128.00 2 0.25 0.00 0 0.00 10 0 1 0 88 0 642 0.00 0 0.00 80.00 2 0.16 0.00 0 0.00 11 0 1 0 88 0 608 0.00 0 0.00 96.00 3 0.28 0.00 0 0.00 11 0 0 0 88 0 681 0.00 0 0.00 64.00 3 0.19 0.00 0 0.00 11 0 1 0 88 0 1477 0.00 0 0.00 64.00 6 0.37 0.00 0 0.00 11 0 0 0 88 0 592 0.00 0 0.00 128.00 1 0.12 0.00 0 0.00 11 0 1 0 88 0 709 32.00 10 0.31 80.00 2 0.16 0.00 0 0.00 12 0 1 0 86 0 3925 0.00 0 0.00 22.00 4 0.09 0.00 0 0.00 14 0 1 0 85 0 590 8.00 1 0.01 32.00 2 0.06 0.00 0 0.00 13 0 1 0 86 0 1707 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 615 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 594 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 618 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 14 0 1 0 85 0 531 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 1640 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 13 0 0 0 86 0 497 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 554 32.00 2 0.06 127.16 757 94.03 0.00 0 0.00 14 0 2 0 84 0 590 0.00 0 0.00 117.33 24 2.75 0.00 0 0.00 14 0 1 0 85 0 533 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 85 0 1711 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 0 0 86 0 557 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 0 0 86 0 502 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 717 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 86 0 564 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 13 0 1 0 86 0 1548 0.00 0 0.00 32.00 4 0.12 0.00 0 0.00 14 0 1 0 85 0 559 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 85 0 543 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 493 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 86 0 623 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 1656 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 14 0 1 0 85 0 569 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 86 0 540 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 608 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 85 0 580 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 86 tty mfid0 mfid1 cd0 cpu tin tout KB/t tps MB/s KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 1644 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 85 0 752 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 575 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 13 0 1 0 86 0 498 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 495 0.00 0 0.00 18.67 3 0.05 0.00 0 0.00 13 0 1 0 86 0 1618 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 15 0 1 0 84 0 586 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 86 0 537 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 14 0 1 0 85 0 600 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 13 0 1 0 86 0 553 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 13 0 1 0 85 0 1631 0.00 0 0.00 38.40 5 0.19 0.00 0 0.00 14 0 1 0 85 0 665 0.00 0 0.00 32.00 4 0.12 0.00 0 0.00 14 0 1 0 85 0 737 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 15 0 1 0 84 0 485 32.00 2 0.06 127.05 770 95.56 0.00 0 0.00 13 0 1 0 85 0 624 0.00 0 0.00 126.95 61 7.55 0.00 0 0.00 13 0 1 0 85 0 1586 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 565 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 85 0 488 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 515 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 85 0 532 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 14 0 1 0 85 0 1554 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 532 0.00 0 0.00 42.67 3 0.12 0.00 0 0.00 14 0 1 0 85 0 529 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 1 85 0 472 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 0 0 86 0 534 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 14 0 1 0 84 0 1628 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 86 0 892 0.00 0 0.00 32.00 1 0.03 0.00 0 0.00 13 0 1 0 86 0 604 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 650 0.00 0 0.00 32.00 4 0.12 0.00 0 0.00 13 0 1 0 86 0 568 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 0 1 85 0 1587 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 1 0 85 0 513 0.00 0 0.00 32.00 5 0.16 0.00 0 0.00 14 0 1 0 85 0 536 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 14 0 0 0 85 0 420 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 14 0 0 0 86 0 563 0.00 0 0.00 32.00 3 0.09 0.00 0 0.00 14 0 1 0 85 0 1592 0.00 0 0.00 18.67 3 0.05 0.00 0 0.00 13 0 1 0 86 iostat (fast case): tty mfid0 mfid1 cd0 cpu tin tout KB/t tps MB/s KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 505 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 1541 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 1229 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 438 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 326 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 310 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 317 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 1201 0.00 0 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 390 1.00 1 0.00 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 357 0.00 0 0.00 32.00 2 0.06 0.00 0 0.00 0 0 0 0 100 0 1453 0.00 0 0.00 32.00 65 2.03 0.00 0 0.00 3 0 1 0 95 0 2840 0.00 0 0.00 32.00 291 9.08 0.00 0 0.00 10 0 5 1 85 0 1975 0.00 0 0.00 32.00 307 9.58 0.00 0 0.00 14 0 5 1 79 0 685 0.00 0 0.00 32.00 326 10.18 0.00 0 0.00 13 0 6 1 80 0 691 0.00 0 0.00 32.00 289 9.02 0.00 0 0.00 12 0 6 1 81 0 649 0.00 0 0.00 32.00 268 8.37 0.00 0 0.00 13 0 6 1 80 0 552 0.00 0 0.00 32.00 302 9.43 0.00 0 0.00 14 0 5 1 79 0 1754 0.00 0 0.00 32.00 299 9.33 0.00 0 0.00 14 0 5 2 79 0 630 0.00 0 0.00 32.00 316 9.87 0.00 0 0.00 13 0 6 1 80 0 606 0.00 0 0.00 32.00 287 8.96 0.00 0 0.00 13 0 6 1 80 0 587 0.00 0 0.00 32.00 305 9.52 0.00 0 0.00 15 0 6 1 78 0 576 0.00 0 0.00 32.00 272 8.49 0.00 0 0.00 14 0 6 0 80 0 1763 0.00 0 0.00 32.00 317 9.90 0.00 0 0.00 14 0 6 1 79 0 724 0.00 0 0.00 32.00 379 11.83 0.00 0 0.00 13 0 6 2 79 0 590 4.00 2 0.01 32.00 346 10.80 0.00 0 0.00 14 0 5 1 80 0 580 0.00 0 0.00 32.00 274 8.55 0.00 0 0.00 14 0 6 1 80 0 829 0.00 0 0.00 32.00 338 10.55 0.00 0 0.00 14 0 5 1 80 0 1912 0.00 0 0.00 32.00 326 10.18 0.00 0 0.00 13 0 6 2 79 0 541 0.00 0 0.00 32.00 350 10.93 0.00 0 0.00 13 0 6 1 80 0 652 0.00 0 0.00 32.00 302 9.43 0.00 0 0.00 14 0 6 1 80 0 616 0.00 0 0.00 32.00 297 9.27 0.00 0 0.00 15 0 5 1 79 0 564 0.00 0 0.00 32.00 326 10.18 0.00 0 0.00 14 0 6 1 79 0 1853 0.00 0 0.00 32.00 303 9.46 0.00 0 0.00 13 0 6 1 80 0 752 0.00 0 0.00 32.00 280 8.74 0.00 0 0.00 14 0 6 1 79 0 542 0.00 0 0.00 32.00 300 9.37 0.00 0 0.00 14 0 6 1 79 0 540 32.00 10 0.31 32.00 318 9.93 0.00 0 0.00 14 0 5 1 79 0 688 0.00 0 0.00 32.00 331 10.33 0.00 0 0.00 14 0 5 1 79 0 1863 8.00 2 0.02 32.00 300 9.37 0.00 0 0.00 14 0 6 1 79 0 720 0.00 0 0.00 32.00 306 9.55 0.00 0 0.00 14 0 5 1 80 0 565 0.00 0 0.00 32.00 299 9.33 0.00 0 0.00 14 0 6 0 79 0 1470 0.00 0 0.00 116.51 3413 388.27 0.00 0 0.00 10 0 5 1 83 0 553 0.00 0 0.00 32.00 303 9.46 0.00 0 0.00 13 0 7 1 79 0 1730 0.00 0 0.00 32.00 337 10.52 0.00 0 0.00 14 0 6 0 80 0 649 0.00 0 0.00 32.00 342 10.68 0.00 0 0.00 14 0 6 1 79 0 901 0.00 0 0.00 32.00 317 9.90 0.00 0 0.00 14 0 6 1 80 0 1654 0.00 0 0.00 32.00 328 10.24 0.00 0 0.00 15 0 5 1 79 ktrace (fast case): kdump -f ktrace_noappend.out | grep CALL 2005 mysqld CALL _umtx_op(0x801243140,0xf,0,0,0x7ffffe1f0e20) 2005 mysqld CALL _umtx_op(0x8012431d0,0xf,0,0,0x7ffffd5eade0) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x8012431b8,0xf,0,0,0x7ffffd7ebe40) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243140,0xf,0,0,0x7ffffe1f0e20) 2005 mysqld CALL _umtx_op(0x8012431d0,0xf,0,0,0x7ffffd5eade0) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0x4,0,0,0) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0xf1,0,0,0) 2005 mysqld CALL lseek(0xbb,0x12c4fb1c,SEEK_SET) 2005 mysqld CALL read(0xbb,0x7ffffd2e4150,0x14) 2005 mysqld CALL pwrite(0xbb,0xa17a2d014,0x90,0x12c4fb1c) 2005 mysqld CALL pwrite(0xba,0x8a3e91c00,0x400,0x3ee8c00) 2005 mysqld CALL pwrite(0xba,0x8a3e84000,0x400,0x26b6e400) 2005 mysqld CALL pwrite(0xba,0x8a3e84400,0x400,0x26b6e800) 2005 mysqld CALL pwrite(0xba,0x8a3e84800,0x400,0x26b6ec00) 2005 mysqld CALL pwrite(0xba,0x8a3e84c00,0x400,0x26b6f000) 2005 mysqld CALL pwrite(0xba,0x8a93c9800,0x400,0x27a27000) 2005 mysqld CALL pwrite(0xba,0x7ffffd2e33a0,0xb4,0) 2005 mysqld CALL sendto(0x1f,0xa12389800,0xb,0,0,0) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0x4,0,0,0) 2005 mysqld CALL poll(0x7ffffd2e5d70,0x1,0x1b77400) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243140,0xf,0,0,0x7ffffe1f0e20) 2005 mysqld CALL _umtx_op(0x8012431d0,0xf,0,0,0x7ffffd5eade0) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) ktrace (slow case): kdump -f ktrace_append.out | grep CALL 2005 mysqld CALL _umtx_op(0x8012431b8,0xf,0,0,0x7ffffd7ebe40) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243140,0xf,0,0,0x7ffffe1f0e20) 2005 mysqld CALL _umtx_op(0x8012431d0,0xf,0,0,0x7ffffd5eade0) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243140,0xf,0,0,0x7ffffe1f0e20) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x8012431d0,0xf,0,0,0x7ffffd5eade0) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0x4,0,0,0) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0xf1,0,0,0) 2005 mysqld CALL pwrite(0xbb,0xa17a2d015,0x84,0x50f37138) 2005 mysqld CALL pwrite(0xba,0x8a93c9800,0x400,0x27a27000) 2005 mysqld CALL pwrite(0xba,0x8aaf71400,0x400,0x295cec00) 2005 mysqld CALL pwrite(0xba,0x8aaf71800,0x400,0x295cf000) 2005 mysqld CALL pwrite(0xba,0x8aaf71c00,0x400,0x295cf400) 2005 mysqld CALL pwrite(0xba,0x8aaf72000,0x400,0x295cf800) 2005 mysqld CALL pwrite(0xba,0x8aaf7f800,0x400,0x295dd000) 2005 mysqld CALL pwrite(0xba,0x7ffffd2e33a0,0xb4,0) 2005 mysqld CALL sendto(0x1f,0xa12389800,0xb,0,0,0) 2005 mysqld CALL recvfrom(0x1f,0xa12389800,0x4,0,0,0) 2005 mysqld CALL poll(0x7ffffd2e5d70,0x1,0x1b77400) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x8012431b8,0xf,0,0,0x7ffffd7ebe40) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) 2005 mysqld CALL _umtx_op(0x801243110,0xf,0,0,0x7ffffe5f2e20) 2005 mysqld CALL select(0,0,0,0,0x7ffffdfeff70) 2005 mysqld CALL select(0,0,0,0,0x7ffffdbedf70) 2005 mysqld CALL _umtx_op(0x801243128,0xf,0,0,0x7ffffe3f1e10) mfiutil: aegis10:/usr/ports/databases/mysql56-server # mfiutil show adapter mfi0 Adapter: Product Name: LSI MegaRAID SAS 9260-8i Serial Number: SV12003271 Firmware: 12.7.0-0007 RAID Levels: JBOD, RAID0, RAID1, RAID5, RAID6, RAID10, RAID50 Battery Backup: not present NVRAM: 32K Onboard Memory: 512M Minimum Stripe: 8k Maximum Stripe: 1M aegis10:/usr/ports/databases/mysql56-server # mfiutil show config mfi0 Configuration: 2 arrays, 2 volumes, 0 spares array 0 of 2 drives: drive 10 ( 279G) ONLINE SATA drive 11 ( 279G) ONLINE SATA array 1 of 6 drives: drive 9 ( 279G) ONLINE SATA drive 8 ( 279G) ONLINE SATA drive 14 ( 279G) ONLINE SATA drive 12 ( 279G) ONLINE SATA drive 15 ( 279G) ONLINE SATA drive 13 ( 279G) ONLINE SATA volume mfid0 (279G) RAID-1 64k OPTIMAL spans: array 0 volume mfid1 (1115G) RAID-6 64k OPTIMAL spans: array 1 dmesg: Copyright (c) 1992-2013 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD is a registered trademark of The FreeBSD Foundation. FreeBSD 9.1-STABLE #0: Wed Feb 27 20:12:45 UTC 2013 root@aegis10:/usr/obj/usr/src/sys/GENERIC amd64 CPU: Intel(R) Xeon(R) CPU E5606 @ 2.13GHz (2133.38-MHz K8-class CPU) Origin = "GenuineIntel" Id = 0x206c2 Family = 0x6 Model = 0x2c Stepping = 2 Features=0xbfebfbff Features2=0x29ee3ff AMD Features=0x2c100800 AMD Features2=0x1 TSC: P-state invariant, performance statistics real memory = 25769803776 (24576 MB) avail memory = 24793403392 (23644 MB) Event timer "LAPIC" quality 600 ACPI APIC Table: <052711 APIC2011> FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs FreeBSD/SMP: 2 package(s) x 4 core(s) cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 2 cpu2 (AP): APIC ID: 18 cpu3 (AP): APIC ID: 20 cpu4 (AP): APIC ID: 32 cpu5 (AP): APIC ID: 34 cpu6 (AP): APIC ID: 50 cpu7 (AP): APIC ID: 52 ioapic0: Changing APIC ID to 1 ioapic1: Changing APIC ID to 3 ioapic0 irqs 0-23 on motherboard ioapic1 irqs 24-47 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, bff00000 (3) failed cpu0: on acpi0 ACPI Warning: Incorrect checksum in table [OEMB] - 0x7D, should be 0x7A (20110527/tbutils-282) cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 cpu4: on acpi0 cpu5: on acpi0 cpu6: on acpi0 cpu7: on acpi0 attimer0: port 0x40-0x43 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 atrtc0: port 0x70-0x71 irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 950 Event timer "HPET" frequency 14318180 Hz quality 450 Event timer "HPET1" frequency 14318180 Hz quality 440 Event timer "HPET2" frequency 14318180 Hz quality 440 Event timer "HPET3" frequency 14318180 Hz quality 440 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: at device 1.0 on pci0 pci5: on pcib1 igb0: port 0xef80-0xef9f mem 0xfafe0000-0xfaffffff,0xfafc0000-0xfafdffff,0xfaf9c000-0xfaf9ffff irq 28 at device 0.0 on pci5 igb0: Using MSIX interrupts with 9 vectors igb0: Ethernet address: 00:25:90:2b:8e:d4 igb0: Bound queue 0 to cpu 0 igb0: Bound queue 1 to cpu 1 igb0: Bound queue 2 to cpu 2 igb0: Bound queue 3 to cpu 3 igb0: Bound queue 4 to cpu 4 igb0: Bound queue 5 to cpu 5 igb0: Bound queue 6 to cpu 6 igb0: Bound queue 7 to cpu 7 igb1: port 0xef40-0xef5f mem 0xfaf60000-0xfaf7ffff,0xfaf40000-0xfaf5ffff,0xfaf1c000-0xfaf1ffff irq 40 at device 0.1 on pci5 igb1: Using MSIX interrupts with 9 vectors igb1: Ethernet address: 00:25:90:2b:8e:d5 igb1: Bound queue 0 to cpu 0 igb1: Bound queue 1 to cpu 1 igb1: Bound queue 2 to cpu 2 igb1: Bound queue 3 to cpu 3 igb1: Bound queue 4 to cpu 4 igb1: Bound queue 5 to cpu 5 igb1: Bound queue 6 to cpu 6 igb1: Bound queue 7 to cpu 7 pcib2: at device 3.0 on pci0 pci4: on pcib2 mfi0: port 0xd000-0xd0ff mem 0xfae7c000-0xfae7ffff,0xfaec0000-0xfaefffff irq 24 at device 0.0 on pci4 mfi0: Using MSI mfi0: Megaraid SAS driver Ver 4.23 pcib3: at device 5.0 on pci0 pci3: on pcib3 pcib4: at device 7.0 on pci0 pci2: on pcib4 pci0: at device 20.0 (no driver attached) pci0: at device 20.1 (no driver attached) pci0: at device 20.2 (no driver attached) pci0: at device 20.3 (no driver attached) pci0: at device 22.0 (no driver attached) pci0: at device 22.1 (no driver attached) pci0: at device 22.2 (no driver attached) pci0: at device 22.3 (no driver attached) pci0: at device 22.4 (no driver attached) pci0: at device 22.5 (no driver attached) pci0: at device 22.6 (no driver attached) pci0: at device 22.7 (no driver attached) uhci0: port 0xcea0-0xcebf irq 16 at device 26.0 on pci0 uhci0: LegSup = 0x2f00 usbus0 on uhci0 uhci1: port 0xce80-0xce9f irq 21 at device 26.1 on pci0 uhci1: LegSup = 0x2f00 usbus1 on uhci1 uhci2: port 0xce20-0xce3f irq 19 at device 26.2 on pci0 uhci2: LegSup = 0x2f00 usbus2 on uhci2 ehci0: mem 0xfadf4000-0xfadf43ff irq 18 at device 26.7 on pci0 usbus3: EHCI version 1.0 usbus3 on ehci0 uhci3: port 0xcf20-0xcf3f irq 23 at device 29.0 on pci0 uhci3: LegSup = 0x2f00 usbus4 on uhci3 uhci4: port 0xcf00-0xcf1f irq 19 at device 29.1 on pci0 uhci4: LegSup = 0x2f00 usbus5 on uhci4 uhci5: port 0xcec0-0xcedf irq 18 at device 29.2 on pci0 uhci5: LegSup = 0x2f00 usbus6 on uhci5 ehci1: mem 0xfadf6000-0xfadf63ff irq 23 at device 29.7 on pci0 usbus7: EHCI version 1.0 usbus7 on ehci1 pcib5: at device 30.0 on pci0 pci1: on pcib5 vgapci0: mem 0xf8000000-0xf8ffffff,0xf9ffc000-0xf9ffffff,0xfa000000-0xfa7fffff irq 16 at device 3.0 on pci1 isab0: at device 31.0 on pci0 isa0: on isab0 ahci0: port 0xcff0-0xcff7,0xcfac-0xcfaf,0xcfe0-0xcfe7,0xcfa8-0xcfab,0xcf80-0xcf9f mem 0xfadfa000-0xfadfa7ff irq 19 at device 31.2 on pci0 ahci0: AHCI v1.20 with 6 3Gbps ports, Port Multiplier not supported ahcich0: at channel 0 on ahci0 ahcich1: at channel 1 on ahci0 ahcich2: at channel 2 on ahci0 ahcich3: at channel 3 on ahci0 ahcich4: at channel 4 on ahci0 ahcich5: at channel 5 on ahci0 pci0: at device 31.3 (no driver attached) acpi_button0: on acpi0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 uart2: <16550 or compatible> port 0x3e8-0x3ef irq 5 on acpi0 qpi0: on motherboard pcib6: pcibus 255 on qpi0 pci255: on pcib6 pcib7: pcibus 254 on qpi0 pci254: on pcib7 orm0: at iomem 0xc0000-0xc7fff,0xd1000-0xd1fff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ppc0: cannot reserve I/O port range ctl: CAM Target Layer loaded est0: on cpu0 p4tcc0: on cpu0 est1: on cpu1 p4tcc1: on cpu1 est2: on cpu2 p4tcc2: on cpu2 est3: on cpu3 p4tcc3: on cpu3 est4: on cpu4 p4tcc4: on cpu4 est5: on cpu5 p4tcc5: on cpu5 est6: on cpu6 p4tcc6: on cpu6 est7: on cpu7 p4tcc7: on cpu7 Timecounters tick every 1.000 msec mfi0: 891 (415298016s/0x0020/info) - Shutdown command received from host mfi0: 892 (boot + 3s/0x0020/info) - Firmware initialization started (PCI ID 0079/1000/9261/1000) mfi0: 893 (boot + 3s/0x0020/info) - Firmware version 2.70.03-0862 mfi0: 894 (boot + 5s/0x0020/info) - Board Revision 60A mfi0: 895 (boot + 22s/0x0002/info) - Inserted: PD 08(e0xff/s8) usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 12Mbps Full Speed USB v1.0 usbus3: 480Mbps High Speed USB v2.0 usbus4: 12Mbps Full Speed USB v1.0 usbus5: 12Mbps Full Speed USB v1.0 usbus6: 12Mbps Full Speed USB v1.0 usbus7: 480Mbps High Speed USB v2.0 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 ugen4.1: at usbus4 uhub4: on usbus4 ugen5.1: at usbus5 uhub5: on usbus5 ugen6.1: at usbus6 uhub6: on usbus6 ugen7.1: at usbus7 uhub7: on usbus7 mfid0 on mfi0 mfid0: 285632MB (584974336 sectors) RAID volume (no label) is optimal mfid1 on mfi0 mfid1: 1142528MB (2339897344 sectors) RAID volume (no label) is optimal mfi0: 896 (boot + 22s/0x0002/info) - Inserted: PD 08(e0xff/s8) Info: enclPd=ffff, scsiType=0, portMap=00, sasAddr=4433221100000000,0000000000000000 mfi0: 897 (boot + 22s/0x0002/info) - Inserted: PD 09(e0xff/s9) mfi0: 898 (boot + 22s/0x0002/info) - Inserted: PD 09(e0xff/s9) Info: enclPd=ffff, scsiType=0, portMap=06, sasAddr=4433221101000000,0000000000000000 mfi0: 899 (boot + 22s/0x0002/info) - Inserted: PD 0a(e0xff/s10) mfi0: 900 (boot + 22s/0x0002/info) - Inserted: PD 0a(e0xff/s10) Info: enclPd=ffff, scsiType=0, portMap=05, sasAddr=4433221103000000,0000000000000000 mfi0: 901 (boot + 22s/0x0002/info) - Inserted: PD 0b(e0xff/s11) mfi0: 902 (boot + 22s/0x0002/info) - Inserted: PD 0b(e0xff/s11) Info: enclPd=ffff, scsiType=0, portMap=03, sasAddr=4433221102000000,0000000000000000 mfi0: 903 (boot + 22s/0x0002/info) - Inserted: PD 0c(e0xff/s12) mfi0: 904 (boot + 22s/0x0002/info) - Inserted: PD 0c(e0xff/s12) Info: enclPd=ffff, scsiType=0, portMap=04, sasAddr=4433221105000000,0000000000000000 mfi0: 905 (boot + 22s/0x0002/info) - Inserted: PD 0d(e0xff/s13) mfi0: 906 (boot + 22s/0x0002/info) - Inserted: PD 0d(e0xff/s13) Info: enclPd=ffff, scsiType=0, portMap=07, sasAddr=4433221107000000,0000000000000000 mfi0: 907 (boot + 22s/0x0002/info) - Inserted: PD 0e(e0xff/s14) mfi0: 908 (boot + 22s/0x0002/info) - Inserted: PD 0e(e0xff/s14) Info: enclPd=ffff, scsiType=0, portMap=02, sasAddr=4433221104000000,0000000000000000 mfi0: 909 (boot + 22s/0x0002/info) - Inserted: PD 0f(e0xff/s15) mfi0: 910 (boot + 22s/0x0002/info) - Inserted: PD 0f(e0xff/s15) Info: enclPd=ffff, scsiType=0, portMap=01, sasAddr=4433221106000000,0000000000000000 mfi0: 911 (415311926s/0x0020/info) - Time established as 02/27/13 20:25:26; (30 seconds since power on) SMP: AP CPU #1 Launched! SMP: AP CPU #6 Launched! SMP: AP CPU #2 Launched! cd0 at ahcich0 bus 0 scbus0 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device cd0: 150.000MB/s transfers (SATA 1.x, UDMA5, ATAPI 12bytes, PIO 8192bytes) SMP: AP CPU #4 Launched! cd0: Attempt to query device size failed: NOT READY, Medium not present - tray closed SMP: AP CPU #3 Launched! SMP: AP CPU #7 Launched! SMP: AP CPU #5 Launched! Timecounter "TSC" frequency 2133382316 Hz quality 1000 Root mount waiting for: usbus7 usbus6 usbus5 usbus4 usbus3 usbus2 usbus1 usbus0 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered uhub2: 2 ports with 2 removable, self powered uhub4: 2 ports with 2 removable, self powered uhub5: 2 ports with 2 removable, self powered uhub6: 2 ports with 2 removable, self powered Root mount waiting for: usbus7 usbus3 Root mount waiting for: usbus7 usbus3 uhub3: 6 ports with 6 removable, self powered uhub7: 6 ports with 6 removable, self powered Trying to mount root from ufs:/dev/mfid0p2 [rw]... ugen2.2: at usbus2 ukbd0: on usbus2 kbd2 at ukbd0 ums0: on usbus2 igb0: link state changed to UP