From owner-freebsd-geom@FreeBSD.ORG Mon Aug 6 10:10:04 2012 Return-Path: Delivered-To: freebsd-geom@hub.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 6AA251065674 for ; Mon, 6 Aug 2012 10:10:04 +0000 (UTC) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 507088FC17 for ; Mon, 6 Aug 2012 10:10:04 +0000 (UTC) Received: from freefall.freebsd.org (localhost [127.0.0.1]) by freefall.freebsd.org (8.14.5/8.14.5) with ESMTP id q76AA44u004198 for ; Mon, 6 Aug 2012 10:10:04 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.14.5/8.14.5/Submit) id q76AA4Fx004197; Mon, 6 Aug 2012 10:10:04 GMT (envelope-from gnats) Date: Mon, 6 Aug 2012 10:10:04 GMT Message-Id: <201208061010.q76AA4Fx004197@freefall.freebsd.org> To: freebsd-geom@FreeBSD.org From: "Pavel Polyakov" Cc: Subject: Re: kern/158197: [geom] geom_cache with size> 1000 leads to panics X-BeenThere: freebsd-geom@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Pavel Polyakov List-Id: GEOM-specific discussions and implementations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 06 Aug 2012 10:10:04 -0000 The following reply was made to PR kern/158197; it has been noted by GNATS. From: "Pavel Polyakov" To: bug-followup@freebsd.org, bsd@kobyla.org Cc: ru@freebsd.org Subject: Re: kern/158197: [geom] geom_cache with size>1000 leads to panics Date: Mon, 06 Aug 2012 12:54:53 +0300 Increasing kern.geom.cache.timeout sysctl (from 10 to 30-40 secs) rises the panic risk. Increasing the block size forces cache usage & overfill. Problem mostly appears after number of CacheFull events, cache memory release and filling it again with read operations. So sometimes such situation comes (Entries > Size!): # gcache list usr0 Geom name: usr0 WroteBytes: 2001752576 Writes: 93866 CacheFull: 65 CacheMisses: 1387 CacheHits: 4120 CacheReadBytes: 22902272 CacheReads: 5442 ReadBytes: 27303424 Reads: 6262 InvalidEntries: 0 UsedEntries: 0 Entries: 1025 TailOffset: 21474705408 BlockSize: 131072 Size: 1024 Few more info from the fresh stable version: ----- Architecture: amd64 Architecture Version: 1 Dump Length: 833024B (0 MB) Blocksize: 512 Dumptime: Mon Aug 6 04:54:04 2012 Hostname: cel.home Magic: FreeBSD Text Dump Version String: FreeBSD 9.1-PRERELEASE #1 r239036M: Sat Aug 4 15:38:54 EEST 2012 root@cel.home:/usr/obj/usr/src/sys/PDC90 Panic String: Bad tailq NEXT(0xfffffe0012be7ab8->tqh_last) != NULL Dump Parity: 3722464325 Bounds: 148 Dump Status: good panic: Bad tailq NEXT(0xfffffe0012be7ab8->tqh_last) != NULL cpuid = 0 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff802defca = db_trace_self_wrapper+0x2a kdb_backtrace() at 0xffffffff805a52e7 = kdb_backtrace+0x37 panic() at 0xffffffff8056e088 = panic+0x1d8 g_cache_deliver() at 0xffffffff81038b46 = g_cache_deliver+0x276 g_cache_read() at 0xffffffff81038d13 = g_cache_read+0x1a3 g_cache_start() at 0xffffffff8103920e = g_cache_start+0x34e g_io_schedule_down() at 0xffffffff80506c24 = g_io_schedule_down+0x1d4 g_down_procbody() at 0xffffffff805070a2 = g_down_procbody+0x72 fork_exit() at 0xffffffff80540565 = fork_exit+0x135 fork_trampoline() at 0xffffffff807fbeae = fork_trampoline+0xe --- trap 0, rip = 0, rsp = 0xffffff800027fcf0, rbp = 0 --- KDB: enter: panic db:1:on> run lockinfo db:2:lockinfo> show locks exclusive sleep mutex GEOM CACHE mutex (GEOM CACHE mutex) r = 0 (0xfffffe0012be7a20) locked @ /usr/src/sys/modules/geom/geom_cache/../../../geom/cache/g_cache.c:262 db:2:locks> show alllocks Process 77823 (perl5.14.2) thread 0xfffffe01b6d288e0 (131440) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe0214f6a0f8) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77822 (perl5.14.2) thread 0xfffffe0136bbf470 (100575) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe00b9a488f0) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77821 (perl5.14.2) thread 0xfffffe0184d158e0 (150562) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe00417a93a0) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77820 (perl5.14.2) thread 0xfffffe0118db5470 (149413) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe006bfa50f8) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77819 (perl5.14.2) thread 0xfffffe020654f000 (102636) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe00410abe40) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77818 (perl5.14.2) thread 0xfffffe02066428e0 (127656) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe01817cdb98) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 77817 (perl5.14.2) thread 0xfffffe0012ca1470 (100117) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe0172cf8b98) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 6250 (darktable) thread 0xfffffe01816de000 (100720) exclusive sleep mutex pmap (pmap) r = 0 (0xfffffe01810a6a60) locked @ /usr/src/sys/amd64/amd64/pmap.c:3533 exclusive rw pvh global (pvh global) r = 0 (0xffffffff80e4cc00) locked @ /usr/src/sys/amd64/amd64/pmap.c:3532 exclusive sleep mutex vm object (standard object) r = 0 (0xfffffe0181366000) locked @ /usr/src/sys/vm/vm_fault.c:1067 shared sx user map (user map) r = 0 (0xfffffe01810a69a8) locked @ /usr/src/sys/vm/vm_fault.c:823 Process 6250 (darktable) thread 0xfffffe01816de470 (100718) shared sx user map (user map) r = 0 (0xfffffe01810a69a8) locked @ /usr/src/sys/vm/vm_fault.c:823 Process 3201 (mysqld) thread 0xfffffe00bec8e8e0 (133280) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe0181d6cb98) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 3201 (mysqld) thread 0xfffffe00410f2000 (100545) exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffffe018119c3a0) locked @ /usr/src/sys/kern/uipc_sockbuf.c:148 Process 13 (geom) thread 0xfffffe0010177000 (100016) exclusive sleep mutex GEOM CACHE mutex (GEOM CACHE mutex) r = 0 (0xfffffe0012be7a20) locked @ /usr/src/sys/modules/geom/geom_cache/../../../geom/cache/g_cache.c:262 db:2:alllocks> show lockedvnods Locked vnodes db:1:lockedvnods> show pcpu cpuid = 0 dynamic pcpu = 0x538a00 curthread = 0xfffffe0010177000: pid 13 "g_down" curpcb = 0xffffff800027fd00 fpcurthread = none idlethread = 0xfffffe001015d470: tid 100003 "idle: cpu0" curpmap = 0xffffffff80c30190 tssp = 0xffffffff80e37fe0 commontssp = 0xffffffff80e37fe0 rsp0 = 0xffffff800027fd00 gs32p = 0xffffffff80e36138 ldt = 0xffffffff80e36178 tss = 0xffffffff80e36168 spin locks held: db:1:pcpu> bt Tracing pid 13 tid 100016 td 0xfffffe0010177000 kdb_enter() at 0xffffffff805a4fab = kdb_enter+0x3b panic() at 0xffffffff8056e081 = panic+0x1d1 g_cache_deliver() at 0xffffffff81038b46 = g_cache_deliver+0x276 g_cache_read() at 0xffffffff81038d13 = g_cache_read+0x1a3 g_cache_start() at 0xffffffff8103920e = g_cache_start+0x34e g_io_schedule_down() at 0xffffffff80506c24 = g_io_schedule_down+0x1d4 g_down_procbody() at 0xffffffff805070a2 = g_down_procbody+0x72 fork_exit() at 0xffffffff80540565 = fork_exit+0x135 fork_trampoline() at 0xffffffff807fbeae = fork_trampoline+0xe --- trap 0, rip = 0, rsp = 0xffffff800027fcf0, rbp = 0 --- db:1:bt> -- Using Opera's revolutionary email client: http://www.opera.com/mail/