panic: ffs_valloc: dup alloc in 7 GENERIC

2016-05-26 Thread smj
Hello, recently we've had an issue with our root filesystem getting some
pretty strange inconsistencies resulting in kernel panics.  fsck must be
run manually and typically result in a lot of noise regarding dupes, but
after a few forced runs the system can be brought back up and runs.  However
recently no matter how many 'marked clean' fscks are run bringing up the
system just results in a kernel panic.  There are no disk errors (its a
250GB allocation on a 23tb RAID) so it was decided to regen the root file
system with a fresh install of the recently released 7.0.1 which seems like
the only real way to go forward.  

We do have crash dumps and the kernel we were using was 7.0 GERNERIC with 
some tweaks in /etc/sysctl.conf.  Because of the sensitivity of the data,
would saitoh or manuel be willing to work with us directly to investigate?

dmode 8180 mode 8180 dgen 2eae3be7 gen 2eae3be7^M
size 3000 blocks 18^M
ino 2830913 ipref 2826056^M
panic: ffs_valloc: dup alloc^M
cpu0: Begin traceback...^M
vpanic() at netbsd:vpanic+0x13c^M
snprintf() at netbsd:snprintf^M
ffs_valloc() at netbsd:ffs_valloc+0x889^M
ufs_makeinode() at netbsd:ufs_makeinode+0x5e^M
ufs_create() at netbsd:ufs_create+0x5b^M
VOP_CREATE() at /ne:t bbsadd: VdOiPr_ CiRnEoA 2T8E+003x13583^M
atv no_fofpseent()  17a1t6 n5:et bmsadn:gvlne_do peenntr+y0^Mx
330^M
do_open() at netbsd:do_open+0x111^M
do_sys_openat() at netbsd:do_sys_openat+0x68^M
sys_open() at netbsd:sys_open+0x24^M
syscall() at netbsd:syscall+0x9a^M
--- syscall (number 5) ---^M
7f7ff5a3c40a:^M
cpu0: End traceback...^M

panic: ffs_valloc: dup alloc^M
cpu1: Begin traceback...^M
vpanic() at netbsd:vpanic+0x13c^M
snprintf() at netbsd:snprintf^M
ffs_valloc() at netbsd:ffs_valloc+0x889^M
ufs_makeinode() at netbsd:ufs_makeinode+0x5e^M
udmfso_dcer e8a1t8e0 (m) oadte  8ne1t80b sdd:geufns _2cc0re3a4t3e7b+0 gx5enb ^M
2VcO0P3_4C37REb^MA
TEs(iz) ea ta 6nede4t bsbld:ocVOkPs _C5R60E^MA
TEi+n0ox 23883^M0
9vn1_5o ippenre(f)  a28t 26n0e5tb6s^M
d:vn_open+0x330^M
do_open() at netbsd:do_open+0x111^M
l^M
See /var/run/do_sys_openat() at netbsd:do_sys_openat+0x68^M
rc.log for more sys_open() at netbsd:sys_open+0x24^M
informsyscall() at netbsd:syscall+0x9a^M
--- syscall (number 5) ---^M
7f7ff5a3c40a:^M
cpu1: End traceback...^M

panic: ffs_blkfree: bad size^M
cpu0: Begin traceback...^M
vpanic() at netbsd:vpanic+0x13c^M
snprintf() at netbsd:snprintf^M
ffs_freefile_common.isra.6() at netbsd:ffs_freefile_common.isra.6^M
ffs_blkfree() at netbsd:ffs_blkfree+0x82^M
ffs_truncate() at netbsd:ffs_truncate+0xe48^M
ufs_truncate() at netbsd:ufs_truncate+0x18d^M
ufs_inactive() at netbsd:ufs_inactive+0x1e1^M
VOP_INACTIVE() at netbsd:VOP_INACTIVE+0x33^M
uvvmr_fealuellt(()0 xatff nffefteb8s1de:v4dre1dlae3l+8,0 x03x50a,^M
2do) _-s>y se_s^M
tfaattaatl( )p aagte n featublstd :dino _ssuypse_rsvtiastaort +0moxd8ef^M^M

stryasp__ t_ylpset a6t 50co(d) e a2t  rneipt bfsfdf:fsfyfs_ff_8_0l5sdtba4t3590 +
c0sx 258 ^Mr
fslyasgcsa l1l0()21 2a tc rne2 tb84s di:lseyvseclal 8l+ r0sxp9 af^Mf
-ff--fe 8s1y0sfca7el1lc 4(8nu^M
mcbuerrl w4p4 1)0x f-f-f-f^M
fe7f817bf6f6764aa770600 ap:i^Md
 c5pu5907:. 1E0n dl otwreascte bkacstka.c..k ^M0

dmode 81b4 mode 81b4 dgen 9b79cb7 gen 9b79cb7^M
size a8 blocks 8^M
ino 2829968 ipref 2826056^M
panic: ffs_valloc: dup alloc^M
cpu0: Begin traceback...^M
vpanic() at netbsd:vpanic+0x13c^M
snprintf() at netbsd:snprintf^M
ffs_valloc() at netbsd:ffs_valloc+0x889^M
ufs_makeinode() at netbsd:ufs_makeinode+0x5e^M
ufs_create() at netbsd:ufs_create+0x5b^M
VOP_CREATE() at netbsd:VOP_CREATE+0x38^M
vn_open() at netbsd:vn_open+0x330^M
do_open() at netbsd:do_open+0x111^M
do_sys_openat() at netbsd:do_sys_openat+0x68^M
sys_open() at netbsd:sys_open+0x24^M
syscall() at netbsd:syscall+0x9a^M
--- syscall (number 5) ---^M
7f7ff5a3c40a:^M
cpu0: End traceback...^M



Re: panic: ffs_valloc: dup alloc

2010-10-20 Thread Brett Lymn
On Wed, Oct 20, 2010 at 01:11:20PM -0500, KAMADA Ken'ichi wrote:
> 
> I had no crash for a week (two weeks if the "skip-wdstart" test is
> counted).  Seems good.  I'm back to -current.
> 

It seems good to me too, no crashes.  Prior to this I was getting a
crash at least once a day possibly more frequently.  I have been doing
a fsck -fn on my cgd partition and that is always coming up clean
too.  Good stuff.

-- 
Brett Lymn
"Warning:
The information contained in this email and any attached files is
confidential to BAE Systems Australia. If you are not the intended
recipient, any use, disclosure or copying of this email or any
attachments is expressly prohibited.  If you have received this email
in error, please notify us immediately. VIRUS: Every care has been
taken to ensure this email and its attachments are virus free,
however, any loss or damage incurred in using this email is not the
sender's responsibility.  It is your responsibility to ensure virus
checks are completed before installing any data sent in this email to
your computer."




Re: panic: ffs_valloc: dup alloc

2010-10-20 Thread KAMADA Ken'ichi
At Tue, 19 Oct 2010 22:37:52 +1030, Brett Lymn wrote:
> On Wed, Oct 13, 2010 at 11:26:05AM -0500, KAMADA Ken'ichi wrote:
> > 
> > Yes, I was testing a similar patch to yours (skip calling wdstart()
> > when !device_is_active()) after my previous email.  It did not crash
> > so far.  I'm now running with your patch and will be back in a
> > week or so.  It will take some time because the panic tends to occur
> > after an overnight sleep rather than a short nap.
> 
> I am seeing good results with David's patch too - multiple
> sleep/resumes over the course of the day without a kernel panic.  For
> me, the panics were quite frequent so this is a big improvement.  I
> will report back after a few days... or sooner if I have issues.

I had no crash for a week (two weeks if the "skip-wdstart" test is
counted).  Seems good.  I'm back to -current.

-- 
KAMADA Ken'ichi 


Re: panic: ffs_valloc: dup alloc

2010-10-19 Thread Brett Lymn
On Wed, Oct 13, 2010 at 11:26:05AM -0500, KAMADA Ken'ichi wrote:
> 
> Yes, I was testing a similar patch to yours (skip calling wdstart()
> when !device_is_active()) after my previous email.  It did not crash
> so far.  I'm now running with your patch and will be back in a
> week or so.  It will take some time because the panic tends to occur
> after an overnight sleep rather than a short nap.
> 

I am seeing good results with David's patch too - multiple
sleep/resumes over the course of the day without a kernel panic.  For
me, the panics were quite frequent so this is a big improvement.  I
will report back after a few days... or sooner if I have issues.

-- 
Brett Lymn
"Warning:
The information contained in this email and any attached files is
confidential to BAE Systems Australia. If you are not the intended
recipient, any use, disclosure or copying of this email or any
attachments is expressly prohibited.  If you have received this email
in error, please notify us immediately. VIRUS: Every care has been
taken to ensure this email and its attachments are virus free,
however, any loss or damage incurred in using this email is not the
sender's responsibility.  It is your responsibility to ensure virus
checks are completed before installing any data sent in this email to
your computer."




Re: panic: ffs_valloc: dup alloc

2010-10-13 Thread KAMADA Ken'ichi
At Tue, 12 Oct 2010 11:34:03 -0500, David Young wrote:
> On Tue, Oct 05, 2010 at 04:23:39PM -0500, KAMADA Ken'ichi wrote:
> > At Fri, 19 Mar 2010 17:51:46 -0500, myself wrote:
> > > 
> > > I'm seeing a panic: ffs_valloc: dup alloc.
> > > Does anyone have a similar panic?
> > > 
> > > The kernel is -current from March 15.
> > > I cannot repeat the panic reliably, but it seems to occur after
> > > suspend/resume (immediately or several minutes later).
> > > The panic occured in /home, which is a ffs on cgd on wd.
> > > "fsck -f" does not report any error on it.
> > 
> > I finally found a clue for this problem.
> > With the attached patch [1], my system seems to be stable again.
> 
> That patch will break some things.  Try this patch, instead?

Yes, I was testing a similar patch to yours (skip calling wdstart()
when !device_is_active()) after my previous email.  It did not crash
so far.  I'm now running with your patch and will be back in a
week or so.  It will take some time because the panic tends to occur
after an overnight sleep rather than a short nap.

-- 
KAMADA Ken'ichi 


Re: panic: ffs_valloc: dup alloc

2010-10-12 Thread David Young
On Tue, Oct 05, 2010 at 04:23:39PM -0500, KAMADA Ken'ichi wrote:
> At Fri, 19 Mar 2010 17:51:46 -0500, myself wrote:
> > 
> > I'm seeing a panic: ffs_valloc: dup alloc.
> > Does anyone have a similar panic?
> > 
> > The kernel is -current from March 15.
> > I cannot repeat the panic reliably, but it seems to occur after
> > suspend/resume (immediately or several minutes later).
> > The panic occured in /home, which is a ffs on cgd on wd.
> > "fsck -f" does not report any error on it.
> 
> I finally found a clue for this problem.
> With the attached patch [1], my system seems to be stable again.

That patch will break some things.  Try this patch, instead?

Dave

-- 
David Young OJC Technologies
dyo...@ojctech.com  Urbana, IL * (217) 278-3933
Index: sys/dev/ata/wd.c
===
RCS file: /cvsroot/src/sys/dev/ata/wd.c,v
retrieving revision 1.384
diff -u -p -r1.384 wd.c
--- sys/dev/ata/wd.c24 Feb 2010 22:37:57 -  1.384
+++ sys/dev/ata/wd.c12 Oct 2010 16:28:40 -
@@ -489,9 +489,10 @@ wdstrategy(struct buf *bp)
}
 
/* If device invalidated (e.g. media change, door open,
-* device suspension), then error.
+* device detachment), then error.
 */
-   if ((wd->sc_flags & WDF_LOADED) == 0 || !device_is_active(wd->sc_dev)) {
+   if ((wd->sc_flags & WDF_LOADED) == 0 ||
+   !device_is_enabled(wd->sc_dev)) {
bp->b_error = EIO;
goto done;
}
@@ -573,6 +574,10 @@ wdstart(void *arg)
 
ATADEBUG_PRINT(("wdstart %s\n", device_xname(wd->sc_dev)),
DEBUG_XFERS);
+
+   if (!device_is_active(wd->sc_dev))
+   return;
+
while (wd->openings > 0) {
 
/* Is there a buf for us ? */


Re: panic: ffs_valloc: dup alloc

2010-10-05 Thread KAMADA Ken'ichi
At Fri, 19 Mar 2010 17:51:46 -0500, myself wrote:
> 
> I'm seeing a panic: ffs_valloc: dup alloc.
> Does anyone have a similar panic?
> 
> The kernel is -current from March 15.
> I cannot repeat the panic reliably, but it seems to occur after
> suspend/resume (immediately or several minutes later).
> The panic occured in /home, which is a ffs on cgd on wd.
> "fsck -f" does not report any error on it.

I finally found a clue for this problem.
With the attached patch [1], my system seems to be stable again.
With the patch, I see "channel reset" [2] on resume.
Without the patch (i.e., unmodified -current), I see
a lot of "cgd0: error 5" messages [3] instead.

It seems to me that cgd is just passing EIO around, so I suspect that
errors are not correctly handled somewhere in FFS...

[1]
Index: sys/dev/ata/wd.c
===
RCS file: /cvsroot/src/sys/dev/ata/wd.c,v
retrieving revision 1.384
diff -u -r1.384 wd.c
--- sys/dev/ata/wd.c24 Feb 2010 22:37:57 -  1.384
+++ sys/dev/ata/wd.c5 Oct 2010 20:46:04 -
@@ -489,9 +489,9 @@
}
 
/* If device invalidated (e.g. media change, door open,
-* device suspension), then error.
+* XXX device suspension), then error.
 */
-   if ((wd->sc_flags & WDF_LOADED) == 0 || !device_is_active(wd->sc_dev)) {
+   if ((wd->sc_flags & WDF_LOADED) == 0) {
bp->b_error = EIO;
goto done;
}

[2]
Suspending system...
acpi0: entering state S3
Flushing disk caches: done
ath0: deleting keyix 1 w/o power
ioapic0 reenabling
wd0h: channel reset writing fsbn 1164848 (wd0 bn 31540991; cn 31290 tn 10 sn 41\
), retrying
cbb0: interrupting at ioapic0 pin 16
wd0: soft error (corrected)

[3]
ioapic0 reenabling
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cgd0: error 5
cbb0: interrupting at ioapic0 pin 16

-- 
KAMADA Ken'ichi 


Re: panic: ffs_valloc: dup alloc

2010-04-14 Thread KAMADA Ken'ichi
> Does stuffing a couple sync calls somewhere before it starts
> suspending devices (wherever that is, I don't know) make the problems
> go away?

I use ACPI S3 sleep, and sys_sync() is called in pmf_system_suspend()
from acpi_enter_sleep_state().  I'm not sure if it is late enough.

> You're right.  When a disk driver is suspended, it should exit from
> its strategy/start routine early, without error.  It looks to me like
> sdstrategy() and wdstrategy() may each get this wrong.

I was running a kernel with the following diff.  I saw
"strategy_in_suspend = 0" on every resume, but still, I encountered
a crash today.
I couldn't see the panicstr or get a crash dump this time.

-- 
KAMADA Ken'ichi 
Index: dev/ata/wd.c
===
RCS file: /cvsroot/src/sys/dev/ata/wd.c,v
retrieving revision 1.384
diff -p -u -r1.384 wd.c
--- dev/ata/wd.c24 Feb 2010 22:37:57 -  1.384
+++ dev/ata/wd.c14 Apr 2010 19:05:08 -
@@ -127,8 +127,11 @@ void   wdperror(const struct wd_softc *);
 
 static int wdlastclose(device_t);
 static boolwd_suspend(device_t, const pmf_qual_t *);
+static boolwd_resume(device_t, const pmf_qual_t *);
 static int wd_standby(struct wd_softc *, int);
 
+static int strategy_in_suspend;
+
 CFATTACH_DECL3_NEW(wd, sizeof(struct wd_softc),
 wdprobe, wdattach, wddetach, NULL, NULL, NULL, DVF_DETACH_SHUTDOWN);
 
@@ -389,7 +392,7 @@ wdattach(device_t parent, device_t self,
/* Discover wedges on this disk. */
dkwedge_discover(&wd->sc_dk);
 
-   if (!pmf_device_register1(self, wd_suspend, NULL, wd_shutdown))
+   if (!pmf_device_register1(self, wd_suspend, wd_resume, wd_shutdown))
aprint_error_dev(self, "couldn't establish power handler\n");
 }
 
@@ -398,11 +401,22 @@ wd_suspend(device_t dv, const pmf_qual_t
 {
struct wd_softc *sc = device_private(dv);
 
+   sc->suspended = 1;
wd_flushcache(sc, AT_WAIT);
wd_standby(sc, AT_WAIT);
return true;
 }
 
+static bool
+wd_resume(device_t dv, const pmf_qual_t *qual)
+{
+   struct wd_softc *sc = device_private(dv);
+
+   sc->suspended = 0;
+   printf("strategy_in_suspend = %d\n", strategy_in_suspend);
+   return true;
+}
+
 int
 wddetach(device_t self, int flags)
 {
@@ -553,7 +567,10 @@ wdstrategy(struct buf *bp)
/* Queue transfer on drive, activate drive and controller if idle. */
s = splbio();
bufq_put(wd->sc_q, bp);
-   wdstart(wd);
+   if (wd->suspended)
+   strategy_in_suspend++;
+   else
+   wdstart(wd);
splx(s);
return;
 done:
Index: dev/ata/wdvar.h
===
RCS file: /cvsroot/src/sys/dev/ata/wdvar.h,v
retrieving revision 1.38
diff -p -u -r1.38 wdvar.h
--- dev/ata/wdvar.h 17 Dec 2009 21:03:10 -  1.38
+++ dev/ata/wdvar.h 14 Apr 2010 19:05:08 -
@@ -69,6 +69,7 @@ struct wd_softc {
 #if NRND > 0
rndsource_element_t rnd_source;
 #endif
+   int suspended;
 };
 
 #define sc_drive sc_wdc_bio.drive


Re: panic: ffs_valloc: dup alloc

2010-03-21 Thread Brett Lymn
On Sun, Mar 21, 2010 at 04:49:05PM -0400, Steven Bellovin wrote:
> 
> > That sounds like maybe the problem is not on the suspend side but on
> > the resume side, that is, that stuff is being written out before (some
> > layer of) the disk subsystem is ready to go again. With vanilla FFS
> > such writes should be synchronous so it should be (relatively) easy to
> > figure out what's going on. Do you feel like trying out dtrace? :-)
> 
> If you'd asked a week ago, sure; now, I don't have the time.

I need to update my -current to something more recent...

>  I don't think it's just named pipes anymore; the last crash I had
> did pretty horrific things to the file system, probably because some
> processes were busy creating files at the time I suspended.  >

I was seeing the corruption on plain files, mostly duplicate
allocations or freeing a free frag.  It looks to me like the kernel
thinks that the FS operation has been committed to disk but the bits
on the physical media have not changed.

-- 
Brett Lymn
"Warning:
The information contained in this email and any attached files is
confidential to BAE Systems Australia. If you are not the intended
recipient, any use, disclosure or copying of this email or any
attachments is expressly prohibited.  If you have received this email
in error, please notify us immediately. VIRUS: Every care has been
taken to ensure this email and its attachments are virus free,
however, any loss or damage incurred in using this email is not the
sender's responsibility.  It is your responsibility to ensure virus
checks are completed before installing any data sent in this email to
your computer."




Re: panic: ffs_valloc: dup alloc

2010-03-21 Thread Steven Bellovin

On Mar 20, 2010, at 7:17 PM, David Holland wrote:

> On Sat, Mar 20, 2010 at 05:03:16PM -0400, Steven Bellovin wrote:
>>> Let me see if I can find my first note on the subject -- it might
>>> give a clue about the date of any changes.
>> 
>> Turns out that I sendpr-ed it in September: kern/42104.
> 
> I even responded to the PR, not that I had any useful ideas at the
> time.
> 
> That sounds like maybe the problem is not on the suspend side but on
> the resume side, that is, that stuff is being written out before (some
> layer of) the disk subsystem is ready to go again. With vanilla FFS
> such writes should be synchronous so it should be (relatively) easy to
> figure out what's going on. Do you feel like trying out dtrace? :-)

If you'd asked a week ago, sure; now, I don't have the time.
> 
> On the other hand, if fsck thinks the inode for a named pipe is
> unallocated (or particularly, has duplicate blocks, since pipes
> shouldn't have blocks at all)... that means that whatever went wrong
> went wrong when the pipe was created, not when something exited and
> removed it. And with vanilla ffs, those are synchronous writes and
> they should happen in quick succession; if the inode didn't get
> written but the directory did, something's more badly wrong than just
> the disk not being ready yet. And I strongly suspect that the pipe
> creation isn't tied to suspending, that is, the pipe should have been
> created long before you suspended and should not in general be removed
> and recreated by suspending. And that means either something is
> severely wrong in general and you're only seeing it after crashing due
> to suspend (which is possible, but seems not too likely) or the
> suspend cycle is actively writing garbage and corrupting the fs.

I don't think it's just named pipes anymore; the last crash I had did pretty 
horrific things to the file system, probably because some processes were busy 
creating files at the time I suspended.
> 
> Meanwhile, getting traps while dumping is Very Strange (TM). Do we
> have any kind of debug code that can checksum memory before and after
> the suspend? I wonder if something ACPI-related is garbaging memory.

--Steve Bellovin, http://www.cs.columbia.edu/~smb







Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread David Holland
On Sat, Mar 20, 2010 at 05:03:16PM -0400, Steven Bellovin wrote:
 > > Let me see if I can find my first note on the subject -- it might
 > > give a clue about the date of any changes.
 > 
 > Turns out that I sendpr-ed it in September: kern/42104.

I even responded to the PR, not that I had any useful ideas at the
time.

That sounds like maybe the problem is not on the suspend side but on
the resume side, that is, that stuff is being written out before (some
layer of) the disk subsystem is ready to go again. With vanilla FFS
such writes should be synchronous so it should be (relatively) easy to
figure out what's going on. Do you feel like trying out dtrace? :-)

On the other hand, if fsck thinks the inode for a named pipe is
unallocated (or particularly, has duplicate blocks, since pipes
shouldn't have blocks at all)... that means that whatever went wrong
went wrong when the pipe was created, not when something exited and
removed it. And with vanilla ffs, those are synchronous writes and
they should happen in quick succession; if the inode didn't get
written but the directory did, something's more badly wrong than just
the disk not being ready yet. And I strongly suspect that the pipe
creation isn't tied to suspending, that is, the pipe should have been
created long before you suspended and should not in general be removed
and recreated by suspending. And that means either something is
severely wrong in general and you're only seeing it after crashing due
to suspend (which is possible, but seems not too likely) or the
suspend cycle is actively writing garbage and corrupting the fs.

Meanwhile, getting traps while dumping is Very Strange (TM). Do we
have any kind of debug code that can checksum memory before and after
the suspend? I wonder if something ACPI-related is garbaging memory.

-- 
David A. Holland
dholl...@netbsd.org


Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread David Young
On Sat, Mar 20, 2010 at 04:06:32PM -0400, Steven Bellovin wrote:
> Of course, rejecting them wouldn't seem to do any good; what's needed,
> I suspect, is for the device to queue them (as usual) but not fire up
> the disk when in suspending mode.

Steven,

You're right.  When a disk driver is suspended, it should exit from
its strategy/start routine early, without error.  It looks to me like
sdstrategy() and wdstrategy() may each get this wrong.

A pseudo-disk driver such as cgd(4) may as well get out of its
strategy/start routine early, but it cannot do as much harm if it does
not: its buffer I/O will queue in the hardware driver underneath.  That
is, cgdstart() may as well exit early if the unit is suspended, but it's
probably ok as-is.

BTW, I took care to get this right in fd(4)/fdc(4).  I have put fdc(4)
to sleep using drvctl in the middle of read/write/format operations.
When I wake it, it carries on where it left off.

Programmers should beware that

1) device_is_active() is a blunt instrument that does not distinguish
   "device is presently suspended" from "device is not present."

2) the system has to behave consistently when some devices are awake
   and some are asleep.  Even if every device will go to sleep (please,
   don't count on it), you cannot put it to sleep in an instant.

Dave

-- 
David Young OJC Technologies
dyo...@ojctech.com  Urbana, IL * (217) 278-3933


Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread Steven Bellovin

On Mar 20, 2010, at 4:50 PM, Steven Bellovin wrote:

> 
> On Mar 20, 2010, at 4:17 PM, David Holland wrote:
> 
>> On Sat, Mar 20, 2010 at 04:06:32PM -0400, Steven Bellovin wrote:
 That suggests that something is flushing buffers to a device that's
 suspended and it's throwing them away instead of rejecting them or
 panicing.
>>> 
>>> Possibly
>> 
>> Although it doesn't quite make sense, because in most cases this could
>> only corrupt the fs if the same block was left untouched afterwards
>> for long enough for the (allegedly) clean buffer to be discarded, and
>> that shouldn't cause a panic right after resume. Unless the fs was
>> already broken from a previous suspend, I guess.
>> 
>> Maybe there's suspend code somewhere that writes out and also discards
>> buffers in the hopes of cleaning up for some future suspend-to-disk
>> work? Could be, I guess, but I'd tend to think not. I ought to go look
>> at the code but I don't think I have time for that this weekend. :-|
>> 
 Does stuffing a couple sync calls somewhere before it starts
 suspending devices (wherever that is, I don't know) make the problems
 go away?
>>> 
>>> No -- I've had a sync call in my suspend script for years.  More
>>> precisely, at the moment it's
>>> 
>>> sync; sleep 1
>>> 
>>> to let things flush.  No joy.
>> 
>> That might not be late enough; I was thinking of inside the kernel.
>> 
>>> Of course, rejecting them wouldn't seem to do any good; what's
>>> needed, I suspect, is for the device to queue them (as usual) but
>>> not fire up the disk when in suspending mode.
>> 
>> Or for the writes to not be issued at all until after resume.
>> 
>> ISTM it must be either the syncer firing at the wrong time or
>> something's gotten out of order in the suspend sequencing.
>> 
> 
> Let me see if I can find my first note on the subject -- it might give a clue 
> about the date of any changes.

Turns out that I sendpr-ed it in September: kern/42104.

--Steve Bellovin, http://www.cs.columbia.edu/~smb







Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread Steven Bellovin

On Mar 20, 2010, at 4:17 PM, David Holland wrote:

> On Sat, Mar 20, 2010 at 04:06:32PM -0400, Steven Bellovin wrote:
>>> That suggests that something is flushing buffers to a device that's
>>> suspended and it's throwing them away instead of rejecting them or
>>> panicing.
>> 
>> Possibly
> 
> Although it doesn't quite make sense, because in most cases this could
> only corrupt the fs if the same block was left untouched afterwards
> for long enough for the (allegedly) clean buffer to be discarded, and
> that shouldn't cause a panic right after resume. Unless the fs was
> already broken from a previous suspend, I guess.
> 
> Maybe there's suspend code somewhere that writes out and also discards
> buffers in the hopes of cleaning up for some future suspend-to-disk
> work? Could be, I guess, but I'd tend to think not. I ought to go look
> at the code but I don't think I have time for that this weekend. :-|
> 
>>> Does stuffing a couple sync calls somewhere before it starts
>>> suspending devices (wherever that is, I don't know) make the problems
>>> go away?
>> 
>> No -- I've had a sync call in my suspend script for years.  More
>> precisely, at the moment it's
>> 
>>  sync; sleep 1
>> 
>> to let things flush.  No joy.
> 
> That might not be late enough; I was thinking of inside the kernel.
> 
>> Of course, rejecting them wouldn't seem to do any good; what's
>> needed, I suspect, is for the device to queue them (as usual) but
>> not fire up the disk when in suspending mode.
> 
> Or for the writes to not be issued at all until after resume.
> 
> ISTM it must be either the syncer firing at the wrong time or
> something's gotten out of order in the suspend sequencing.
> 

Let me see if I can find my first note on the subject -- it might give a clue 
about the date of any changes.
> 


--Steve Bellovin, http://www.cs.columbia.edu/~smb







Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread David Holland
On Sat, Mar 20, 2010 at 04:06:32PM -0400, Steven Bellovin wrote:
 > > That suggests that something is flushing buffers to a device that's
 > > suspended and it's throwing them away instead of rejecting them or
 > > panicing.
 > 
 > Possibly

Although it doesn't quite make sense, because in most cases this could
only corrupt the fs if the same block was left untouched afterwards
for long enough for the (allegedly) clean buffer to be discarded, and
that shouldn't cause a panic right after resume. Unless the fs was
already broken from a previous suspend, I guess.

Maybe there's suspend code somewhere that writes out and also discards
buffers in the hopes of cleaning up for some future suspend-to-disk
work? Could be, I guess, but I'd tend to think not. I ought to go look
at the code but I don't think I have time for that this weekend. :-|

 > > Does stuffing a couple sync calls somewhere before it starts
 > > suspending devices (wherever that is, I don't know) make the problems
 > > go away?
 >
 > No -- I've had a sync call in my suspend script for years.  More
 > precisely, at the moment it's
 > 
 >  sync; sleep 1
 > 
 > to let things flush.  No joy.

That might not be late enough; I was thinking of inside the kernel.

 > Of course, rejecting them wouldn't seem to do any good; what's
 > needed, I suspect, is for the device to queue them (as usual) but
 > not fire up the disk when in suspending mode.

Or for the writes to not be issued at all until after resume.

ISTM it must be either the syncer firing at the wrong time or
something's gotten out of order in the suspend sequencing.

-- 
David A. Holland
dholl...@netbsd.org


Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread Steven Bellovin

On Mar 20, 2010, at 3:49 PM, David Holland wrote:

> On Sat, Mar 20, 2010 at 10:29:44PM +1030, Brett Lymn wrote:
>> I have given up on suspending because my filesystems would be
>> corrupted with monotonous regularity.  The chances of a corruption
>> seems to increase with the amount of disk activity happening on
>> suspend.   It seems like something is not being flushed (or not being
>> marked as flushed) when the suspend happens.
> 
> We don't support suspend-to-disk, right? So the contents of kernel
> memory are supposed to be preserved in this suspend? Because if so,
> unflushed buffers shouldn't matter. One would think.
> 
> That suggests that something is flushing buffers to a device that's
> suspended and it's throwing them away instead of rejecting them or
> panicing.

Possibly
> 
> Does stuffing a couple sync calls somewhere before it starts
> suspending devices (wherever that is, I don't know) make the problems
> go away?
> 
> -- 

No -- I've had a sync call in my suspend script for years.  More precisely, at 
the moment it's

sync; sleep 1

to let things flush.  No joy.

Of course, rejecting them wouldn't seem to do any good; what's needed, I 
suspect, is for the device to queue them (as usual) but not fire up the disk 
when in suspending mode.


--Steve Bellovin, http://www.cs.columbia.edu/~smb







Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread David Holland
On Sat, Mar 20, 2010 at 10:29:44PM +1030, Brett Lymn wrote:
 > I have given up on suspending because my filesystems would be
 > corrupted with monotonous regularity.  The chances of a corruption
 > seems to increase with the amount of disk activity happening on
 > suspend.   It seems like something is not being flushed (or not being
 > marked as flushed) when the suspend happens.

We don't support suspend-to-disk, right? So the contents of kernel
memory are supposed to be preserved in this suspend? Because if so,
unflushed buffers shouldn't matter. One would think.

That suggests that something is flushing buffers to a device that's
suspended and it's throwing them away instead of rejecting them or
panicing.

Does stuffing a couple sync calls somewhere before it starts
suspending devices (wherever that is, I don't know) make the problems
go away?

-- 
David A. Holland
dholl...@netbsd.org


Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread Steven Bellovin

On Mar 20, 2010, at 7:59 AM, Brett Lymn wrote:

> On Fri, Mar 19, 2010 at 05:51:46PM -0500, KAMADA Ken'ichi wrote:
>> 
>> I'm seeing a panic: ffs_valloc: dup alloc.
>> Does anyone have a similar panic?
>> 
> 
> I have seen various file system panics after suspend/resume for quite
> a while:
> 
> NetBSD rover 5.99.18 NetBSD 5.99.18 (ROVER2) #10: Tue Sep 29 08:18:23 CST 
> 2009  bl...@rover:/usr/src/sys/arch/i386/compile/ROVER2 i386
> 
> I have given up on suspending because my filesystems would be
> corrupted with monotonous regularity.  The chances of a corruption
> seems to increase with the amount of disk activity happening on
> suspend.   It seems like something is not being flushed (or not being
> marked as flushed) when the suspend happens.
> 
> -- 

Same here -- it's why my production laptop is now a Mac; -current is horribly 
unreliable on suspend/resume.  I've mentioned it here several times, but have 
never gotten a good dump to show anyone.


--Steve Bellovin, http://www.cs.columbia.edu/~smb







Re: panic: ffs_valloc: dup alloc

2010-03-20 Thread Brett Lymn
On Fri, Mar 19, 2010 at 05:51:46PM -0500, KAMADA Ken'ichi wrote:
> 
> I'm seeing a panic: ffs_valloc: dup alloc.
> Does anyone have a similar panic?
> 

I have seen various file system panics after suspend/resume for quite
a while:

NetBSD rover 5.99.18 NetBSD 5.99.18 (ROVER2) #10: Tue Sep 29 08:18:23 CST 2009  
bl...@rover:/usr/src/sys/arch/i386/compile/ROVER2 i386

I have given up on suspending because my filesystems would be
corrupted with monotonous regularity.  The chances of a corruption
seems to increase with the amount of disk activity happening on
suspend.   It seems like something is not being flushed (or not being
marked as flushed) when the suspend happens.

-- 
Brett Lymn
"Warning:
The information contained in this email and any attached files is
confidential to BAE Systems Australia. If you are not the intended
recipient, any use, disclosure or copying of this email or any
attachments is expressly prohibited.  If you have received this email
in error, please notify us immediately. VIRUS: Every care has been
taken to ensure this email and its attachments are virus free,
however, any loss or damage incurred in using this email is not the
sender's responsibility.  It is your responsibility to ensure virus
checks are completed before installing any data sent in this email to
your computer."




panic: ffs_valloc: dup alloc

2010-03-19 Thread KAMADA Ken'ichi
Hi,

I'm seeing a panic: ffs_valloc: dup alloc.
Does anyone have a similar panic?

The kernel is -current from March 15.
I cannot repeat the panic reliably, but it seems to occur after
suspend/resume (immediately or several minutes later).
The panic occured in /home, which is a ffs on cgd on wd.
"fsck -f" does not report any error on it.

% uname -a
NetBSD mitana.nanohz.org 5.99.24 NetBSD 5.99.24 (MITANA) #202: Mon Mar 15 
13:54:47 CDT 2010  k...@mitana.nanohz.org:/usr/src/sys/arch/i386/compile/MITANA 
i386

% mount
/dev/wd0a on / type ffs (noatime, nodevmtime, local)
/dev/wd0h on /var type ffs (noatime, log, local)
/dev/wd0g on /usr type ffs (noatime, log, local)
/dev/cgd0a on /home type ffs (noatime, local)
tmpfs on /tmp type tmpfs (local)
procfs on /proc type procfs (local)
procfs on /usr/pkg/emul/linux/proc type procfs (local)
ptyfs on /dev/pts type ptyfs (local)

% find /home -inum 23052
/home/ken/.mozilla/firefox/default.07r/lock # which is a symlink.


(gdb) bt
#0  cpu_reboot (howto=260, bootstr=0x0)
at ../../../../arch/i386/i386/machdep.c:854
#1  0xc03a8751 in panic (fmt=0xc0561bf1 "ffs_valloc: dup alloc")
at ../../../../kern/subr_prf.c:302
#2  0xc01e7b9d in ffs_valloc (pvp=0x88a8, mode=33152, cred=0xcd086000, 
vpp=0xcd192c7c) at ../../../../ufs/ffs/ffs_alloc.c:599
#3  0xc03ee796 in ufs_makeinode (mode=33152, dvp=0x88a8, vpp=0xcd192c7c, 
cnp=0xcd192c90) at ../../../../ufs/ufs/ufs_vnops.c:2185
#4  0xc03eeb29 in ufs_create (v=0xcd192b54)
at ../../../../ufs/ufs/ufs_vnops.c:144
#5  0xc045cca5 in VOP_CREATE (dvp=0x88a8, vpp=0xcd192c7c, cnp=0xcd192c90, 
vap=0xcd192ba8) at ../../../../kern/vnode_if.c:163
#6  0xc045014c in vn_open (ndp=0xcd192c68, fmode=2563, cmode=384)
at ../../../../kern/vfs_vnops.c:178
#7  0xc044cc25 in sys_open (l=0xcd16fd20, uap=0xcd192d00, retval=0xcd192d28)
at ../../../../kern/vfs_syscalls.c:1320
#8  0xc03b5cc9 in syscall (frame=0xcd192d48) at ../../../../sys/syscallvar.h:61
#9  0xc0100525 in syscall1 ()


(gdb) frame 2
#2  0xc01e7b9d in ffs_valloc (pvp=0x88a8, mode=33152, cred=0xcd086000, 
vpp=0xcd192c7c) at ../../../../ufs/ffs/ffs_alloc.c:599
599             panic("ffs_valloc: dup alloc");
(gdb) p *(*vpp)->v_mount
$1 = {mnt_list = {cqe_next = 0xcb69e000, cqe_prev = 0xcb617000}, 
  mnt_vnodelist = {tqh_first = 0xcc91ec44, tqh_last = 0xcec3629c}, 
  mnt_op = 0xc05b1b80, mnt_vnodecovered = 0xcc4987f4, mnt_syncer = 0xcc91ec44, 
  mnt_transinfo = 0xcb11c354, mnt_data = 0xc2180b00, mnt_unmounting = {
rw_owner = 0}, mnt_renamelock = {u = {mtxa_owner = 0}}, 
  mnt_refcnt = 17050, mnt_recursecnt = 0, mnt_flag = 67112960, 
  mnt_iflag = 448, mnt_fs_bshift = 14, mnt_dev_bshift = 9, mnt_stat = {
f_flag = 0, f_bsize = 16384, f_frsize = 2048, f_iosize = 16384, 
f_blocks = 3096999, f_bfree = 1611921, f_bavail = 1457072, 
f_bresvd = 154849, f_files = 774654, f_ffree = 674307, f_favail = 674307, 
f_fresvd = 0, f_syncreads = 111436, f_syncwrites = 1300, f_asyncreads = 7, 
f_asyncwrites = 488, f_fsidx = {__fsid_val = {5376, 1931}}, f_fsid = 5376, 
f_namemax = 255, f_owner = 0, f_spare = {0, 0, 0, 0}, 
f_fstypename = "ffs", '\0' , 
f_mntonname = "/home", '\0' , 
f_mntfromname = "/dev/cgd0a", '\0' }, 
  mnt_specdataref = {specdataref_container = 0x0, specdataref_lock = {u = {
mtxa_owner = 0}}}, mnt_updating = {u = {mtxa_owner = 0}}, 
  mnt_wapbl_op = 0x0, mnt_wapbl = 0x0, mnt_wapbl_replay = 0x0, mnt_gen = 3}
(gdb) p *(struct inode *)(*vpp)->v_data
$2 = {i_gnode = {g_op = 0xc04f7374, g_glock = {rw_owner = 0}, g_dirtygen = 0}, 
  i_hash = {le_next = 0x0, le_prev = 0xcc52bc30}, i_nextsnap = {
tqe_next = 0x0, tqe_prev = 0x0}, i_vnode = 0xcec36228, i_ump = 0xc2180b00, 
  i_devvp = 0xcc498964, i_flag = 0, i_dev = 5376, i_number = 23052, inode_u = {
fs = 0xc2188800, lfs = 0xc2188800, e2fs = 0xc2188800}, i_unused1 = 0x0, 
  i_dquot = {0x0, 0x0}, i_modrev = 15425831166720, i_lockf = 0x0, i_count = 0, 
  i_endoff = 0, i_diroff = 0, i_offset = 0, i_reclen = 0, i_unused = 0, 
  inode_ext = {ffs = {ffs_snapblklist = 0x0, ffs_first_data_blk = 0, 
  ffs_first_indir_blk = 0}, e2fs = {ext2fs_last_lblk = 0, 
  ext2fs_last_blk = 0}, lfs = 0x0}, i_mode = 41453, i_nlink = 1, 
  i_size = 14, i_flags = 0, i_gen = 704332479, i_uid = 10001, i_gid = 10001, 
  i_dirhash = 0x0, i_din = {ffs1_din = 0xcdc17f38, ffs2_din = 0xcdc17f38, 
e2fs_din = 0xcdc17f38}}


(gdb) frame 7
#7  0xc044cc25 in sys_open (l=0xcd16fd20, uap=0xcd192d00, retval=0xcd192d28)
at ../../../../kern/vfs_syscalls.c:1320
1320if ((error = vn_open(&nd, flags, cmode)) != 0) {
(gdb) p nd
$3 = {ni_dirp = 0xcccd0800 "/home/ken/.history.00999a", 
  ni_segflg = UIO_SYSSPACE, ni_startdir = 0x0, ni_rootdir = 0xcc3e6ac8, 
  ni_erootdir = 0x0, ni_vp = 0xcec36228, ni_dvp = 0x88a8, ni_pathlen = 1, 
  ni_next =