sc->sc_dk.dk_copenmask == 1 after /etc/rc.d/fsck_root

[David Young]

fsck_ffs opens the root filesystem on /dev/sd0a during boot.  Before
it does so, sd0's sc->sc_dk.dk_copenmask member is 0.  After fsck_ffs
has finished, dk_copenmask is 1.  I can stop the kernel when it opens
/dev/sd0a with breakpoints at cdev_open, sdopen, VOP_OPEN, vn_open,
and spec_open.  I cannot stop the kernel at a corresponding VOP_CLOSE,
vn_close, spec_close, cdev_close, or sdclose call during a fsck_ffs
system call.  It is a mystery to me how fsck_ffs can open the device and
(seemingly) never close it, not even implicitly.  Any ideas what's going
on?

dk_copenmask never returns to 0, not even during shutdown.

As a consequence of this dk_copenmask I am running 5.99.15.  The problem
seems to be relatively new.

Dave

--
David Young             OJC Technologies
dyoung@...      Urbana, IL * [phone]

[David Young]

On Wed, Jul 08, 2009 at 07:43:09PM -0500, David Young wrote:
> dk_copenmask never returns to 0, not even during shutdown.
>
> As a consequence of this dk_copenmask I am running 5.99.15.  The problem
> seems to be relatively new.

Oops, that was supposed to say,

> As a consequence of this, dk_copenmask never returns to 0, not even
> during shutdown.
>
> I am running 5.99.15.  The problem seems to be relatively new.

I modified /etc/rc.d/fsck_root to run 'ktruss -i fsck'. fsck execs
fsck_ffs. fsck_ffs does open /dev/sd0a and /dev/rsd0a, but it does not
close them before calling exit(0).

Perhaps the kernel is not cleaning up processes' file descriptor tables
like it used to?

Dave

--
David Young             OJC Technologies
dyoung@...      Urbana, IL * [phone]

[David Young]

On Thu, Jul 09, 2009 at 01:25:37PM -0500, David Young wrote:

> On Wed, Jul 08, 2009 at 07:43:09PM -0500, David Young wrote:
> > dk_copenmask never returns to 0, not even during shutdown.
> >
> > As a consequence of this dk_copenmask I am running 5.99.15.  The problem
> > seems to be relatively new.
>
> Oops, that was supposed to say,
>
> > As a consequence of this, dk_copenmask never returns to 0, not even
> > during shutdown.
> >
> > I am running 5.99.15.  The problem seems to be relatively new.
>
> I modified /etc/rc.d/fsck_root to run 'ktruss -i fsck'. fsck execs
> fsck_ffs. fsck_ffs does open /dev/sd0a and /dev/rsd0a, but it does not
> close them before calling exit(0).
>
> Perhaps the kernel is not cleaning up processes' file descriptor tables
> like it used to?

Below is the ktruss output, bracketed by the rc-script messages.  I had
to hit ^C to break out of ktruss, which hangs after fsck exits.

Starting root file system check:
    10      1 ktruss   emul(netbsd)
    10      1 ktruss   fktrace                     = 0
    10      1 ktruss   fcntl(0x4, 0x3, 0)          = 1
    10      1 ktruss   fcntl(0x4, 0x4, 0x1)        = 0
    10      1 fsck     emul(netbsd)
    10      1 fsck     execve("/sbin/fsck", 0xbfbfeee4, 0xbfbfeef4) JUSTRETURN
    10      1 fsck     mmap(0, 0x8000, 0x3, 0x1002, 0xffffffff, 0, 0, 0) = 0xbbbe9000
    10      1 fsck     open("/etc/ld.so.conf", 0, 0) = 3
    10      1 fsck     read(0x3, 0xbfbfede8, 0x80) = 55
       "libm.so.0\tmachdep.fpu_present\t1:libm387.so.0,libm.so.0\n"
    10      1 fsck     close(0x3)                  = 0
    10      1 fsck     open("/lib/libutil.so.7", 0, 0) = 3
    10      1 fsck     __fstat50(0x3, 0xbfbfe6ec)  = 0
    10      1 fsck     mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0, 0) = 0xbbbe8000
    10      1 fsck     munmap(0xbbbe8000, 0x1000)  = 0
    10      1 fsck     mmap(0, 0x15000, 0x5, 0x2, 0x3, 0, 0, 0) = 0xbbbd4000
    10      1 fsck     mmap(0xbbbe6000, 0x2000, 0x3, 0x12, 0x3, 0, 0x12000, 0) = 0xbb/dev/rsd0a: file system is clean; not checking
be6000
    10      1 fsck     mmap(0xbbbe8000, 0x1000, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbe8000
    10      1 fsck     close(0x3)                  = 0
    10      1 fsck     open("/lib/libprop.so.1", 0, 0xbfbfe6ec) = 3
    10      1 fsck     __fstat50(0x3, 0xbfbfe6ec)  = 0
    10      1 fsck     mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0, 0) = 0xbbbd3000
    10      1 fsck     munmap(0xbbbd3000, 0x1000)  = 0
    10      1 fsck     mmap(0, 0xf000, 0x5, 0x2, 0x3, 0, 0, 0) = 0xbbbc5000
    10      1 fsck     mmap(0xbbbd3000, 0x1000, 0x3, 0x12, 0x3, 0, 0xe000, 0) = 0xbbbd3000
    10      1 fsck     mmap(0xbbbd4000, 0, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbd4000
    10      1 fsck     close(0x3)                  = 0
    10      1 fsck     open("/lib/libc.so.12", 0, 0xbfbfe6ec) = 3
    10      1 fsck     __fstat50(0x3, 0xbfbfe6ec)  = 0
    10      1 fsck     mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0, 0) = 0xbbbc4000
    10      1 fsck     munmap(0xbbbc4000, 0x1000)  = 0
    10      1 fsck     mmap(0, 0x108000, 0x5, 0x2, 0x3, 0, 0, 0) = 0xbbabd000
    10      1 fsck     mmap(0xbbbad000, 0x8000, 0x3, 0x12, 0x3, 0, 0xf0000, 0) = 0xbbbad000
    10      1 fsck     mmap(0xbbbb5000, 0x10000, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbb5000
    10      1 fsck     close(0x3)                  = 0
    10      1 fsck     __sysctl(0xbfbfee2c, 0x2, 0xbbbc00a0, 0xbfbfee34, 0, 0) = 0
    10      1 fsck     __sysctl(0xbfbfe3e8, 0x2, 0xbbbb9fd4, 0xbfbfe3f0, 0, 0) = 0
    10      1 fsck     __sysctl(0xbfbfe328, 0x2, 0xbbbc3aa0, 0xbfbfe330, 0, 0) = 0
    10      1 fsck     readlink("/etc/malloc.conf", 0xbfbfe3f5, 0x400) Err#2 ENOENT
    10      1 fsck     break(0x8100000)            = 0
    10      1 fsck     mmap(0, 0x100000, 0x3, 0x14001002, 0xffffffff, 0, 0, 0) = 0xbb900000
    10      1 fsck     open("/etc/fstab", 0, 0x1b6) = 3
    10      1 fsck     __fstat50(0x3, 0xbfbfe2f0)  = 0
    10      1 fsck     read(0x3, 0xbb902000, 0x4000) = 286
       "# NetBSD /etc/fstab\n# See /usr/share/examples/fstab/ for more exampl"
    10      1 fsck     __stat50("/", 0xbfbfe820)   = 0
    10      1 fsck     __stat50("/dev/sd0a", 0xbfbfe7a4) = 0
    10      1 fsck     __stat50("/dev/rsd0a", 0xbfbfe728) = 0
    11      1 fsck     emul(netbsd)
    11      1 fsck     fork                        = 0
    11      1 fsck     statvfs1("/", 0xbfbfd7bc, 0x1) = 0
    11      1 fsck_ffs emul(netbsd)
    11      1 fsck_ffs execve("/sbin/fsck_ffs", 0xbb906100, 0xbfbfef00) JUSTRETURN
    11      1 fsck_ffs mmap(0, 0x8000, 0x3, 0x1002, 0xffffffff, 0, 0, 0) = 0xbbbe9000
    10      1 fsck     __vfork14                   = 11
    11      1 fsck_ffs open("/etc/ld.so.conf", 0, 0) = 5
    11      1 fsck_ffs read(0x5, 0xbfbfeddc, 0x80) = 55
       "libm.so.0\tmachdep.fpu_present\t1:libm387.so.0,libm.so.0\n"
    11      1 fsck_ffs close(0x5)                  = 0
    11      1 fsck_ffs open("/lib/libutil.so.7", 0, 0) = 5
    11      1 fsck_ffs __fstat50(0x5, 0xbfbfe6e0)  = 0
    11      1 fsck_ffs mmap(0, 0x1000, 0x1, 0x1, 0x5, 0, 0, 0) = 0xbbbe8000
    11      1 fsck_ffs munmap(0xbbbe8000, 0x1000)  = 0
    11      1 fsck_ffs mmap(0, 0x15000, 0x5, 0x2, 0x5, 0, 0, 0) = 0xbbbd4000
    11      1 fsck_ffs mmap(0xbbbe6000, 0x2000, 0x3, 0x12, 0x5, 0, 0x12000, 0) = 0xbbbe6000
    11      1 fsck_ffs mmap(0xbbbe8000, 0x1000, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbe8000
    11      1 fsck_ffs close(0x5)                  = 0
    11      1 fsck_ffs open("/lib/libprop.so.1", 0, 0xbfbfe6e0) = 5
    11      1 fsck_ffs __fstat50(0x5, 0xbfbfe6e0)  = 0
    11      1 fsck_ffs mmap(0, 0x1000, 0x1, 0x1, 0x5, 0, 0, 0) = 0xbbbd3000
    11      1 fsck_ffs munmap(0xbbbd3000, 0x1000)  = 0
    11      1 fsck_ffs mmap(0, 0xf000, 0x5, 0x2, 0x5, 0, 0, 0) = 0xbbbc5000
    11      1 fsck_ffs mmap(0xbbbd3000, 0x1000, 0x3, 0x12, 0x5, 0, 0xe000, 0) = 0xbbbd3000
    11      1 fsck_ffs mmap(0xbbbd4000, 0, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbd4000
    11      1 fsck_ffs close(0x5)                  = 0
    11      1 fsck_ffs open("/lib/libc.so.12", 0, 0xbfbfe6e0) = 5
    11      1 fsck_ffs __fstat50(0x5, 0xbfbfe6e0)  = 0
    11      1 fsck_ffs mmap(0, 0x1000, 0x1, 0x1, 0x5, 0, 0, 0) = 0xbbbc4000
    11      1 fsck_ffs munmap(0xbbbc4000, 0x1000)  = 0
    11      1 fsck_ffs mmap(0, 0x108000, 0x5, 0x2, 0x5, 0, 0, 0) = 0xbbabd000
    11      1 fsck_ffs mmap(0xbbbad000, 0x8000, 0x3, 0x12, 0x5, 0, 0xf0000, 0) = 0xbbbad000
    11      1 fsck_ffs mmap(0xbbbb5000, 0x10000, 0x3, 0x1012, 0xffffffff, 0, 0, 0) = 0xbbbb5000
    11      1 fsck_ffs close(0x5)                  = 0
    11      1 fsck_ffs __sysctl(0xbfbfee20, 0x2, 0xbbbc00a0, 0xbfbfee28, 0, 0) = 0
    11      1 fsck_ffs getrlimit(0x2, 0xbfbfee60)  = 0
    11      1 fsck_ffs setrlimit(0x2, 0xbfbfee60)  = 0
    11      1 fsck_ffs sync()                      = 0
    11      1 fsck_ffs __sigaction_sigtramp(0x2, 0xbfbfe4b8, 0xbfbfe4a0, 0xbbb2fce0, 0x2) = 0
    11      1 fsck_ffs __sigaction_sigtramp(0x2, 0xbfbfe4b8, 0xbfbfe4a0, 0xbbb2fce0, 0x2) = 0
    11      1 fsck_ffs __sigaction_sigtramp(0x3, 0xbfbfe4b8, 0xbfbfe4a0, 0xbbb2fce0, 0x2) = 0
    11      1 fsck_ffs __sigaction_sigtramp(0x1d, 0xbfbfe4b8, 0xbfbfe4a0, 0xbbb2fce0, 0x2) = 0
    11      1 fsck_ffs __stat50("/", 0xbfbfe450)   = 0
    11      1 fsck_ffs __stat50("/dev/rsd0a", 0xbfbfe3d4) = 0
    11      1 fsck_ffs __stat50("/dev/rsd0a", 0xbfbfe2a4) = 0
    11      1 fsck_ffs __stat50("/dev/sd0a", 0xbfbfe3d4) = 0
    11      1 fsck_ffs __stat50("/dev/rsd0a", 0xbfbfe358) = 0
    11      1 fsck_ffs __sysctl(0xbfbfe058, 0x2, 0xbbbb9fd4, 0xbfbfe060, 0, 0) = 0
    11      1 fsck_ffs __sysctl(0xbfbfdf98, 0x2, 0xbbbc3aa0, 0xbfbfdfa0, 0, 0) = 0
    11      1 fsck_ffs readlink("/etc/malloc.conf", 0xbfbfe065, 0x400) Err#2 ENOENT
    11      1 fsck_ffs break(0x8100000)            = 0
    11      1 fsck_ffs mmap(0, 0x100000, 0x3, 0x14001002, 0xffffffff, 0, 0, 0) = 0xbb900000
    11      1 fsck_ffs __stat50("/dev/rsd0a", 0xbfbfdb04) = 0
    11      1 fsck_ffs open("/dev/rsd0a", 0, 0)    = 5
    11      1 fsck_ffs open("/dev/rsd0a", 0x1, 0)  = 6
    11      1 fsck_ffs ioctl(0x5, DIOCGDISKINFO, 0xbfbfd118) = 0
       "\0\M-@\M-+\M-;\^O\^B\0\0"
    11      1 fsck_ffs munmap(0xbbabc000, 0x20f)   = 0
    11      1 fsck_ffs ioctl(0x5, DIOCGWEDGEINFO, 0xbfbfda34) Err#25 ENOTTY
    11      1 fsck_ffs ioctl(0x5, DIOCGDINFO, 0xbfbfd158) = 0
       "WEV\M^B\0\0\0\0skyking\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
    11      1 fsck_ffs __stat50("/dev/rsd0a", 0xbfbfd2ec) = 0
    11      1 fsck_ffs pread(0x5, 0xbb902000, 0x2000, 0, 0x10000, 0) = 8192
       "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
    11      1 fsck_ffs pread(0x5, 0xbb902000, 0x2000, 0, 0x2000, 0) = 8192
       "\0\0\0\0\0\0\0\0\b\0\0\0\^P\0\0\0\^X\0\0\0\M-H\^E\0\0\0\0\0\0\M^?\M^?"
    11      1 fsck_ffs pread(0x5, 0xbb906000, 0x800, 0, 0x61e4c000, 0x39) = 2048
       "\0\0\0\0\0\0\0\0\b\0\0\0\^P\0\0\0\^X\0\0\0\M-H\^E\0\0\0\0\0\0\M^?\M^?"
    11      1 fsck_ffs __fstat50(0x1, 0xbfbfc8d0)  = 0
    11      1 fsck_ffs ioctl(0x1, TIOCGETA, 0xbfbfc920) = 0
       "\^B+\0\0\a\0\0\0\0\M^K\0\0\M-K\^E\0\0\^D\M^?\M^?\^?\^W\^U\^R\M^?\^C"
    11      1 fsck_ffs write(0x1, 0xbb911000, 0x2f) = 47
       "/dev/rsd0a: file system is clean; not checking\n"
    11      1 fsck_ffs exit(0)
    10      1 fsck     __wait450                   = 11
    10      1 fsck     exit(0)
^CUnknown error 130; help!
ERROR: ABORTING BOOT (sending SIGTERM to parent)!
1 2009-07-09T13:Enter pathname of shell or RETURN for /bin/sh:

Dave

--
David Young             OJC Technologies
dyoung@...      Urbana, IL * [phone]

[David Young]

On Thu, Jul 09, 2009 at 01:25:37PM -0500, David Young wrote:

> On Wed, Jul 08, 2009 at 07:43:09PM -0500, David Young wrote:
> > dk_copenmask never returns to 0, not even during shutdown.
> >
> > As a consequence of this dk_copenmask I am running 5.99.15.  The problem
> > seems to be relatively new.
>
> Oops, that was supposed to say,
>
> > As a consequence of this, dk_copenmask never returns to 0, not even
> > during shutdown.
> >
> > I am running 5.99.15.  The problem seems to be relatively new.
>
> I modified /etc/rc.d/fsck_root to run 'ktruss -i fsck'. fsck execs
> fsck_ffs. fsck_ffs does open /dev/sd0a and /dev/rsd0a, but it does not
> close them before calling exit(0).
>
> Perhaps the kernel is not cleaning up processes' file descriptor tables
> like it used to?

I set breakpoints with ddb at fd_free and at the 'dt = ' line:

        if (atomic_dec_uint_nv(&fdp->fd_refcnt) > 0)
                return;
       
        /*
         * Close any files that the process holds open.
         */
        dt = fdp->fd_dt;

In fsck_ffs, fd_free() exits before reaching the 'dt = ' line.  In
fsck_ffs's parent, fsck, fd_free() proceeds to the 'dt = ' line.
Perhaps fsck and fsck_ffs share their descriptor tables by some mistake?

Dave

--
David Young             OJC Technologies
dyoung@...      Urbana, IL * [phone]