NetBSD Problem Report #47937
From riz@slash.lan Sun Jun 16 18:10:41 2013
Return-Path: <riz@slash.lan>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
(using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits))
(Client CN "mail.NetBSD.org", Issuer "Postmaster NetBSD.org" (verified OK))
by mollari.NetBSD.org (Postfix) with ESMTPS id 842E070A04
for <gnats-bugs@gnats.NetBSD.org>; Sun, 16 Jun 2013 18:10:41 +0000 (UTC)
Message-Id: <20130616180833.CA005D504D@slash.lan>
Date: Sun, 16 Jun 2013 11:08:33 -0700 (PDT)
From: riz@NetBSD.org
Reply-To: riz@NetBSD.org
To: gnats-bugs@NetBSD.org
Subject: mount -o discard,log is broken
X-Send-Pr-Version: 3.95
>Number: 47937
>Category: kern
>Synopsis: mounting ffs with both discard and log triggers lock assertion
>Confidential: no
>Severity: serious
>Priority: high
>Responsible: kern-bug-people
>State: open
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Sun Jun 16 18:15:00 +0000 2013
>Last-Modified: Wed Mar 18 15:35:00 +0000 2015
>Originator: Jeff Rizzo
>Release: NetBSD 6.99.21
>Organization:
>Environment:
System: NetBSD slash.lan 6.99.21 NetBSD 6.99.21 (DTRACE) #13: Sun Jun 16 10:18:36 PDT 2013 riz@slash.lan:/usr/src/sys/arch/amd64/compile/DTRACE amd64
Architecture: x86_64
Machine: amd64
>Description:
Mounting a file system with both "discard" and "log" options
triggers an assert in the WAPBL code the first time
ffs_discardcb() is called.
(transcribed by hand):
panic: kernel diagnostic assertion "rw_lock_held(&wl->wl_rwlock)" failed: ../../../../kern/vfs_wapbl.c". line 1725
backtrace:
kern_assert()
wapbl_add_buf()
bdwrite()
ffs_blkfree_cg()
ffs_discardcb()
workqueue_worker()
Naively wrapping the call to ffs_blkfree_cb() in ffs_blkfree_td() with
a WAPBL transaction doesn't help, because the pointers seem to
be different (as printed by the added debug printfs):
Index: ./ufs/ffs/ffs_alloc.c
===================================================================
RCS file: /cvsroot/src/sys/ufs/ffs/ffs_alloc.c,v
retrieving revision 1.133
diff -u -r1.133 ffs_alloc.c
--- ./ufs/ffs/ffs_alloc.c 22 Jan 2013 09:39:15 -0000 1.133
+++ ./ufs/ffs/ffs_alloc.c 16 Jun 2013 17:32:51 -0000
@@ -1571,7 +1571,9 @@
cg = dtog(fs, bno);
dev = devvp->v_rdev;
ump = VFSTOUFS(devvp->v_specmountpoint);
+ printf("ffs_blkfree_cg: mountpoint %p\n", ump->um_fs);
KASSERT(fs == ump->um_fs);
+ UFS_WAPBL_JLOCK_ASSERT(ump->um_mountp);
cgblkno = fsbtodb(fs, cgtod(fs, cg));
error = bread(devvp, cgblkno, (int)fs->fs_cgsize,
@@ -1613,11 +1615,17 @@
ffs_blkfree_td(struct fs *fs, struct discardopdata *td)
{
long todo;
+ int err;
while (td->size) {
todo = min(td->size,
lfragtosize(fs, (fs->fs_frag - fragnum(fs, td->bno))));
+ printf("mountpoint = %p\n", td->devvp->v_mount);
+ err = UFS_WAPBL_BEGIN(td->devvp->v_mount);
+ KASSERT(err == 0);
ffs_blkfree_cg(fs, td->devvp, td->bno, todo);
+ if ( err == 0 )
+ UFS_WAPBL_END(td->devvp->v_mount);
td->bno += numfrags(fs, todo);
td->size -= todo;
}
>How-To-Repeat:
mount -o log,discard /dev/dk4 /mnt # testing discard on wedges
rm -f /mnt/*
>Fix:
none given.
>Audit-Trail:
From: Jeff Rizzo <riz@NetBSD.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Sun, 16 Jun 2013 16:19:53 -0700
This is a multi-part message in MIME format.
--------------000306020501040407070609
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit
With some help from riastradh@, this actually seems to make it work:
Index: ufs/ffs/ffs_alloc.c
===================================================================
RCS file: /cvsroot/src/sys/ufs/ffs/ffs_alloc.c,v
retrieving revision 1.133
diff -u -r1.133 ffs_alloc.c
--- ufs/ffs/ffs_alloc.c 22 Jan 2013 09:39:15 -0000 1.133
+++ ufs/ffs/ffs_alloc.c 16 Jun 2013 23:16:47 -0000
@@ -1572,6 +1572,7 @@
dev = devvp->v_rdev;
ump = VFSTOUFS(devvp->v_specmountpoint);
KASSERT(fs == ump->um_fs);
+ UFS_WAPBL_JLOCK_ASSERT(ump->um_mountp);
cgblkno = fsbtodb(fs, cgtod(fs, cg));
error = bread(devvp, cgblkno, (int)fs->fs_cgsize,
@@ -1613,11 +1614,18 @@
ffs_blkfree_td(struct fs *fs, struct discardopdata *td)
{
long todo;
+ int err;
+ struct ufsmount *ump;
+
+ ump = VFSTOUFS(td->devvp->v_specmountpoint);
while (td->size) {
todo = min(td->size,
lfragtosize(fs, (fs->fs_frag - fragnum(fs, td->bno))));
+ err = UFS_WAPBL_BEGIN(ump->um_mountp);
ffs_blkfree_cg(fs, td->devvp, td->bno, todo);
+ if ( err == 0 )
+ UFS_WAPBL_END(ump->um_mountp);
td->bno += numfrags(fs, todo);
td->size -= todo;
}
--------------000306020501040407070609
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit
<html>
<head>
<meta content="text/html; charset=ISO-8859-1"
http-equiv="Content-Type">
</head>
<body bgcolor="#FFFFFF" text="#000000">
With some help from riastradh@, this actually seems to make it work:<br>
<br>
<meta charset="utf-8">
<pre style="color: rgb(0, 0, 0); font-style: normal; font-variant: normal; font-weight: normal; letter-spacing: normal; line-height: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; widows: auto; word-spacing: 0px; -webkit-text-stroke-width: 0px; word-wrap: break-word; white-space: pre-wrap;">Index: ufs/ffs/ffs_alloc.c
===================================================================
RCS file: /cvsroot/src/sys/ufs/ffs/ffs_alloc.c,v
retrieving revision 1.133
diff -u -r1.133 ffs_alloc.c
--- ufs/ffs/ffs_alloc.c 22 Jan 2013 09:39:15 -0000 1.133
+++ ufs/ffs/ffs_alloc.c 16 Jun 2013 23:16:47 -0000
@@ -1572,6 +1572,7 @@
dev = devvp->v_rdev;
ump = VFSTOUFS(devvp->v_specmountpoint);
KASSERT(fs == ump->um_fs);
+ UFS_WAPBL_JLOCK_ASSERT(ump->um_mountp);
cgblkno = fsbtodb(fs, cgtod(fs, cg));
error = bread(devvp, cgblkno, (int)fs->fs_cgsize,
@@ -1613,11 +1614,18 @@
ffs_blkfree_td(struct fs *fs, struct discardopdata *td)
{
long todo;
+ int err;
+ struct ufsmount *ump;
+
+ ump = VFSTOUFS(td->devvp->v_specmountpoint);
while (td->size) {
todo = min(td->size,
lfragtosize(fs, (fs->fs_frag - fragnum(fs, td->bno))));
+ err = UFS_WAPBL_BEGIN(ump->um_mountp);
ffs_blkfree_cg(fs, td->devvp, td->bno, todo);
+ if ( err == 0 )
+ UFS_WAPBL_END(ump->um_mountp);
td->bno += numfrags(fs, todo);
td->size -= todo;
}
</pre>
<br>
</body>
</html>
--------------000306020501040407070609--
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Mon, 17 Jun 2013 00:33:30 +0000
On Sun, Jun 16, 2013 at 11:20:01PM +0000, Jeff Rizzo wrote:
> With some help from riastradh@, this actually seems to make it work:
>
> [snip]
It would probably be a good idea to make sure it doesn't break
recovery. In WAPBL block freeing already goes through one layer of
delayed action; it's quite possible that delaying things longer will
violate assumptions made by the recovery logic.
The case I'd be particularly worried about is if you delete a bunch of
things, it goes to commit all the transactions and does so and then
writes a snapshot; but the blocks haven't actually been freed yet so
if you then crash and recover to that snapshot you'll leak all the
blocks.
But that's not the only one.
It would be helpful to test it. Testing recovery is in general
difficult, but for this it's probably sufficient to try these cases:
(a) put an unconditional panic in the discard path before starting a
wapbl transaction;
(b) put "if (counter++ == 500) panic()" inside the wapbl transaction;
and for both cases rm -r a sizeable tree (including at least some
large files that have indirect blocks...). Then afterwards let the
journal recovery run and then fsck.
I'll be much more comfortable with this if it fscks clean reliably
under such circumstances.
Why does TRIM get run in the background like this at all, anyway? Are
we concerned about it being slow?
--
David A. Holland
dholland@netbsd.org
From: "Kai-Uwe Eckhardt" <kuehro@gmx.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Thu, 25 Dec 2014 18:54:15 +0100
I get the same kernel assertion on 7.99.3 amd64 (now in line 1715):
panic: kernel diagnostic assertion "rw_lock_held(&wl->wl_rwlock)" failed:
file "/home/source/ab/HEAD/src/sys/kern/vfs_wapbl.c", line 1715
I will try to do some tests with the suggested patch applied.
From: "Kai-Uwe Eckhardt" <kuehro@gmx.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Fri, 26 Dec 2014 11:34:42 +0100
It was neccessary to adjust the patch to some API changes:
--- /usr/src/sys/ufs/ffs/ffs_alloc.c.orig 2014-12-25 21:14:15.000000000 +0100
+++ /usr/src/sys/ufs/ffs/ffs_alloc.c 2014-12-25 23:42:43.000000000 +0100
@@ -1564,6 +1564,7 @@
cg = dtog(fs, bno);
dev = devvp->v_rdev;
ump = VFSTOUFS(spec_node_getmountedfs(devvp));
+ UFS_WAPBL_JLOCK_ASSERT(ump->um_mountp);
KASSERT(fs == ump->um_fs);
cgblkno = FFS_FSBTODB(fs, cgtod(fs, cg));
@@ -1606,11 +1607,18 @@
ffs_blkfree_td(struct fs *fs, struct discardopdata *td)
{
long todo;
+ int err;
+ struct ufsmount *ump;
+
+ ump = VFSTOUFS(spec_node_getmountedfs(td->devvp));
while (td->size) {
todo = min(td->size,
ffs_lfragtosize(fs, (fs->fs_frag - ffs_fragnum(fs, td->bno))));
+ err = UFS_WAPBL_BEGIN(ump->um_mountp);
ffs_blkfree_cg(fs, td->devvp, td->bno, todo);
+ if ( err == 0 )
+ UFS_WAPBL_END(ump->um_mountp);
td->bno += ffs_numfrags(fs, todo);
td->size -= todo;
}
After updating the system I did an fsck and changed mount option log to log,discard.
After reboot I created copies of the releasedir directory with the install iso and
img files and pressed the power button of my laptop after the first 3 copies:
for a in 1 2 3 4 5; do echo $a; cp -R /usr/releasdir /usr/releasedir$a; done
After reboot to multiuser an fsck -f / found some errors and successfully recovered
(typed in from a photo):
FREE BLK COUNTS WRONG IN SUPERBLK
SALVAGE? [yn] y
SUMMARY INFORMATION BAD
SALVAGE? [yn] y
BLK(S) MISSING IN BIT MAPS
SALVAGE [yn] y
592952 files, 7329159 used, 45425312 free (10200 frags, 5676889 blocks, 0.0 % fragment
MARK FILE SYSTEM CLEAN? [yn] y
**** FILE SYSTEM MARKED CLEAN ****
**** FILE SYSTEM WAS MODIFIED ***
**** REBOOT NOW ****
After reboot I compared checksums of copies and original files. Everything was
correct except the last file copied, where only 30 MB of the iso was copied,
when the system was switched off. That's OK, we cannot expect miracles ;-)
I will stress the file system by compiling src and many pkgsrc packages.
From: "Kai-Uwe Eckhardt" <kuehro@gmx.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Sat, 27 Dec 2014 12:05:44 +0100
I have built 170 packages (including firefox) which involves creation
and deletion of thousands of directories. After reboot to single user
an fsck -f / shows a clean filesystem with no errors.
I will try to do the panic tests as suggested by dholland.
Kai-Uwe
From: "Kai-Uwe Eckhardt" <kuehro@gmx.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Sat, 27 Dec 2014 14:33:54 +0100
I have built a kernel with options TRIMDEBUG and doing an rm -rf *
in a directory containing the firefox-34.0.5.source.tar.bz (157M)
and a directory with a second copy of it gave 45000 lines of output
in /var/log/messages. The last 60 lines for documentation purposes.
Sadly I have to replace NetBSD with debian and cannot perform further
tests, due to excessive fan noise and problems with KMS on this Lenovo
x201 system. Some data from atactl wd0 identify:
Model: takeMS SSD UTX-PO318 120GB, Rev: S8FM06.6, Serial #: F6280...
Device type: ATA, fixed
Capacity 120 Gbytes, 234441648 sectors, 512 bytes/sector
Cylinders: 16383, heads: 16, sec/track: 63
Command queue depth: 32
...
TRIM supported
Dec 27 14:10:23 x201 /netbsd: trim(27474672,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474624,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474576,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474528,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474480,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474432,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474384,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474336,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474288,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474240,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474192,98304):0
Dec 27 14:10:23 x201 /netbsd: trim(27474176,32768):0
Dec 27 14:10:23 x201 /netbsd: trim(27474120,98304):0
Dec 27 14:10:30 x201 /netbsd: blkfree(27824168,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27474072,98304)
Dec 27 14:10:30 x201 /netbsd: blkfre27824168,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27729528,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27824168,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27729528,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27634888,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27729528,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27634888,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27540256,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27634888,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27540256,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27540248,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27540248,32768)
Dec 27 14:10:30 x201 /netbsd: blkfree(27450760,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27540248,32768)
Dec 27 14:10:30 x201 /netbsd: defer(27450760,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(28202728,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27450760,16384)
Dec 27 14:10:30 x201 /netbsd: defer(28202728,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(28108088,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(28202728,16384)
Dec 27 14:10:30 x201 /netbsd: defer(28108088,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(28013448,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(28108088,16384)
Dec 27 14:10:30 x201 /netbsd: defer(28013448,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27918816,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(28013448,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27918816,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27918808,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27918808,32768)
Dec 27 14:10:30 x201 /netbsd: blkfree(27474168,16384)
Dec 27 14:10:30 x201 /netbsd: enq old(27918808,32768)
Dec 27 14:10:30 x201 /netbsd: defer(27474168,16384)
Dec 27 14:10:30 x201 /netbsd: blkfree(27459371,2048)
Dec 27 14:10:30 x201 /netbsd: enq old(27474168,16384)
Dec 27 14:10:30 x201 /netbsd: defer(27459371,2048)
Dec 27 14:10:30 x201 /netbsd: trim(27474072,98304):0
Dec 27 14:10:30 x201 /netbsd: trim(27824168,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(27729528,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(27634888,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(27540248,32768):0
Dec 27 14:10:30 x201 /netbsd: trim(27450760,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(28202728,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(28108088,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(28013448,16384):0
Dec 27 14:10:30 x201 /netbsd: trim(27918808,32768):0
Dec 27 14:10:30 x201 /netbsd: trim(27474168,16384):0
From: "Kai-Uwe Eckhardt" <kuehro@gmx.de>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/47937: mount -o discard,log is broken
Date: Wed, 18 Mar 2015 16:34:38 +0100
I have run with log,discard for three month now, on different
kernels up to 7.99.6, without any problem. In this time I
have compiled several NetBSD versions, libreoffice, firefox
and dozens of gcc versions. The patch clearly allows to run a
stable system, but I didn't find the time and courage to test
recovery in case of a crash in a systematic way.
As a side note: the problems with KMS on this Lenovo X201
are resolved on 7.99.6 by using Option "AccelMethod" "SNA"
in xorg.conf and the excessive fan noise can be cured with
sysutils/estd and settings '-M 2399 -s'.
Kai-Uwe
>Unformatted:
(Contact us)
$NetBSD: query-full-pr,v 1.39 2013/11/01 18:47:49 spz Exp $
$NetBSD: gnats_config.sh,v 1.8 2006/05/07 09:23:38 tsutsui Exp $
Copyright © 1994-2014
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.
Home