NetBSD Problem Report #30094

From carton@Ivy.NET  Fri Apr 29 15:58:09 2005
Return-Path: <carton@Ivy.NET>
Received: from smtp-relay.dca.net (smtp-relay.dca.net [216.158.48.66])
	by narn.netbsd.org (Postfix) with ESMTP id BE0C963B116
	for <gnats-bugs@gnats.NetBSD.org>; Fri, 29 Apr 2005 15:58:08 +0000 (UTC)
Message-Id: <20050429155704.0D47B12FB43@castrovalva.Ivy.NET>
Date: Fri, 29 Apr 2005 11:57:04 -0400 (EDT)
From: root@castrovalva.Ivy.NET
Reply-To: root@castrovalva.Ivy.NET
To: gnats-bugs@netbsd.org
Subject: lfs panic: lfs_vget: dinode not found
X-Send-Pr-Version: 3.95

>Number:         30094
>Category:       kern
>Synopsis:       lfs panic: lfs_vget: dinode not found
>Confidential:   no
>Severity:       serious
>Priority:       low
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Fri Apr 29 15:59:00 +0000 2005
>Closed-Date:    
>Last-Modified:  Thu Apr 10 04:55:57 +0000 2008
>Originator:     Miles Nordin
>Release:        NetBSD 3.99.3 (-current from 2005-04-27)
>Organization:
>Environment:
System: NetBSD sohryu 3.99.3 NetBSD 3.99.3 (SOHRYU-$Revision: 1.1.1.7 $) #2: Thu Apr 28 05:02:46 EDT 2005 carton@castrovalva:/scratch/src-current/sys/arch/macppc/compile/SOHRYU macppc
Architecture: powerpc
Machine: macppc
>Description:
I get this panic while copying a root filesystem from one directory on this 
180GB LFS to another with 'pax -rwpe'.

Script started on Thu Apr 28 21:46:50 2005
ezln:~$ sudo cu -l ttyC1 -s 38400
Password:
^GConnected.
db> dmesg 0t4000
rs, LBA48 addressing
wd0: 186 GB, 387621 cyl, 16 head, 63 sec, 512 bytes/sect x 390721968 sectors
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 5 (Ultra/100)
wd0(pdcide0:1:0): using PIO mode 4, Ultra-DMA mode 5 (Ultra/100) (using DMA)
wd0: transfer error, downgrading to Ultra-DMA mode 4
wd0(pdcide0:1:0): using PIO mode 4, Ultra-DMA mode 4 (Ultra/66) (using DMA)
wd0c: error reading fsbn 0 (wd0 bn 0; cn 0 tn 0 sn 0), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
boot device: mc0
root device (default mc0): tlp0
dump device:
file system (default generic):
root on tlp0
nfs_boot: trying DHCP/BOOTP
tlp0: transmit underrun; new threshold: 96/256 bytes
nfs_boot: DHCP next-server: 192.168.1.1
nfs_boot: my_name=sohryu
nfs_boot: my_domain=nat
nfs_boot: my_addr=192.168.1.123
nfs_boot: my_mask=255.255.255.0
nfs_boot: gateway=192.168.1.1
root on 216.158.24.196:/export/nbnfs/sohryu
root file system type: nfs
init path (default /sbin/init):
init: trying /sbin/init
tlp0: transmit underrun; new threshold: 128/512 bytes
tlp0: transmit underrun; new threshold: 160/1024 bytes
lfs_mountfs: inode part of ifile of length 119472128 cannot fit in 672 buffers
lfs_mountfs: please consider increasing NBUF to at least 58376
lfs_mountfs: inode part of ifile of length 119472128 cannot fit in 221184 bytes
lfs_mountfs: please consider increasing BUFPAGES to at least 116712
wd0d: error reading fsbn 344035834 of 344035834-344035849 (wd0 bn 344560122; cn 1
68242 tn 15 sn 26), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 344092322 of 344092322-344092337 (wd0 bn 344616610; cn 1
68269 tn 53 sn 2), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 359392566 of 359392566-359392581 (wd0 bn 359916854; cn 1
75740 tn 41 sn 22), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 364475430 of 364475430-364475445 (wd0 bn 364999718; cn 1
78222 tn 33 sn 6), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 9214866 of 9214866-9214881 (wd0 bn 9739154; cn 4755 tn 2
8 sn 18), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 8628440 of 8628440-8628455 (wd0 bn 9152728; cn 4469 tn 6
 sn 24), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
wd0d: error reading fsbn 363604140 of 363604140-363604155 (wd0 bn 364128428; cn 1
77797 tn 5 sn 12), retrying
wd0: (aborted command, interface CRC error)
wd0: soft error (corrected)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
searched 8 entries
offset is 0x49c2c8 (seg 703)
block is 0x49c2c7 (seg 703)
panic: lfs_vget: dinode not found
db> t
0xd4973c80: at panic+0x19c
0xd4973d10: at lfs_vget+0x454
0xd4973d60: at lfs_mknod+0x234
0xd4973da0: at VOP_MKNOD+0x44
0xd4973dd0: at sys_mknod+0x21c
0xd4973ed0: at syscall_plain+0xe0
0xd4973f40: user SC trap #14 by 0xeff07c9c: srr1=0xd032
            r1=0xffffcb60 cr=0x84004084 xer=0x20000000 ctr=0xeff07c94
db> ps
 PID           PPID     PGRP        UID S   FLAGS LWPS          COMMAND    WAIT
 441            432      441          0 2  0x4002    1              top    poll
>465            432      465          0 2  0x4002    1              pax
 469            432      469          0 2  0x4002    1               rm lfs_sdi
 447            429      429          0 2       0    1     lfs_cleanerd segment
 429              1      429          0 2       0    1     lfs_cleanerd    wait
 44               0        0          0 2 0x20200    1       lfs_writer lfswrit
 432            412      432          0 2  0x4002    1              ksh   pause
 412            410      412        405 2  0x4002    1            ksh93    wait
 410            399      399        405 2   0x100    1             sshd  select
 399            318      399          0 2   0x101    1             sshd   netio
 407              1      407          0 2  0x4002    1            getty   ttyin
 411              1        1          0 2  0x4000    1            getty nanosle
 376              1      376          0 2       0    1             cron nanosle
 374              1      374          0 2 0x80000    1            inetd  kqread
 318              1      318          0 2       0    1             sshd  select
 211              1      211          0 2       0    1        mount_mfs  mfsidl
 110              1      110          0 2       0    1          syslogd  genput
 11               0        0          0 2 0x20200    1         aiodoned aiodone
 10               0        0          0 2 0x20200    1          ioflush
 9                0        0          0 2 0x20200    1       pagedaemon pgdaemo
 8                0        0          0 2 0x20200    1            nfsio  nfsidl
 7                0        0          0 2 0x20200    1            nfsio  nfsidl
 6                0        0          0 2 0x20200    1            nfsio  nfsidl
 5                0        0          0 2 0x20200    1            nfsio
 4                0        0          0 2 0x20200    1         scsibus0  sccomp
 3                0        0          0 2 0x20200    1          atabus1   atath
 2                0        0          0 2 0x20200    1          atabus0   atath
 1                0        1          0 2  0x4000    1             init    wait
 0               -1        0          0 2 0x20200    1          swapper schedul
db> ps/w
 PID          COMMAND     EMUL  PRI UTIME STIME WAIT-MSG    WAIT-CHANNEL
 441              top   netbsd   24   1.4   1.0 poll        netbsd:selwait
>465              pax   netbsd   17   0.9  68.5
 469               rm   netbsd   17   2.2  44.4 lfs_sdirop  0xd0158a18
 447       lfs_cleanerd   netbsd   80   0.1 250.5 segment     0xd0158840
 429       lfs_cleanerd   netbsd   32   0.0   0.0 wait        0xd63b7e0
 44        lfs_writer   netbsd    4   0.0   0.3 lfswriter   netbsd:lfs_writer_da
emon
 432              ksh   netbsd   40   0.0   0.3 pause       0xd46b058
 412            ksh93   netbsd   32   0.0   0.3 wait        0xd63b010
 410             sshd   netbsd   24   0.4   0.5 select      netbsd:selwait
 399             sshd   netbsd   24   0.3   0.0 netio       netbsd:ADBDevTable+0
xa33ac
 407            getty   netbsd   25   0.0   0.0 ttyin       0x74400c
 411            getty   netbsd   32   0.0   0.0 nanosleep   netbsd:nanowait.0
 376             cron   netbsd   32   0.0   0.0 nanosleep   netbsd:nanowait.0
 374            inetd   netbsd   24   0.0   0.0 kqread      0xd6a1000
 318             sshd   netbsd   24   1.3   0.0 select      netbsd:selwait
 211        mount_mfs   netbsd   32   0.0   0.0 mfsidl      0xdf9cd28
 110          syslogd   netbsd    4   0.0   0.4 genput      0x1180800
 11          aiodoned   netbsd    4   0.0   1.6 aiodoned    netbsd:uvm+0x70
 10           ioflush   netbsd   17   0.0   1.3
 9         pagedaemon   netbsd    4   0.0   0.0 pgdaemon    netbsd:uvm+0x64
 8              nfsio   netbsd   32   0.0   0.1 nfsidl      netbsd:nfs_asyncdaem
on+0x38
 7              nfsio   netbsd   32   0.0   0.1 nfsidl      netbsd:nfs_asyncdaem
on+0x28
 6              nfsio   netbsd   32   0.0   0.3 nfsidl      netbsd:nfs_asyncdaem
on+0x18
 5              nfsio   netbsd   24   0.0   0.5
 4           scsibus0   netbsd   16   0.0   0.0 sccomp      0xd0031b08
 3            atabus1   netbsd   16   0.0   0.0 atath       0xd00b1b98
 2            atabus0   netbsd   16   0.0   0.0 atath       0xd00b1a2c
 1               init   netbsd   32   0.9   0.9 wait        netbsd:ADBDevTable+0
xc0e0c
 0            swapper   netbsd    4   0.0   0.0 scheduler   netbsd:proc0
[...]

Then, after rebooting, 'fsck_lfs -p /dev/rwd0d' segfaults:

/dev/rwd0d: total inode list traversal length 4x list length, optimizing

Program received signal SIGSEGV, Segmentation fault.
0x0181251c in vnode_destroy (tossvp=0xf7cb1c0) at vnode.c:136
warning: Source file is more recent than executable.

136             LIST_REMOVE(tossvp, v_getvnodes);
(gdb) t
[Current thread is 0 (process 1362)]
(gdb) bt
#0  0x0181251c in vnode_destroy (tossvp=0xf7cb1c0) at vnode.c:136
#1  0x0180baf0 in remove_ino (vp=0xf7cb1c0, ino=1195755) at pass6.c:223
#2  0x0180dfcc in pass6 () at pass6.c:570
#3  0x0180777c in checkfilesys (
    filesys=0x1820000 <Error reading address 0x1820000: Invalid argument>,
    mntpt=0xdfb0 <Error reading address 0xdfb0: Invalid argument>, auxdata=64,
    child=8) at main.c:246
#4  0x0180755c in main (argc=0, argv=0xffffdd08) at main.c:135
(gdb)

>How-To-Repeat:
unknown
>Fix:
unknown

>Release-Note:

>Audit-Trail:

State-Changed-From-To: open->feedback
State-Changed-By: xtraeme@netbsd.org
State-Changed-When: Sat, 29 Apr 2006 08:06:40 +0000
State-Changed-Why:
Do you still see this panic with a recent -current system?


From: Greg Oster <oster@cs.usask.ca>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/30094 (lfs panic: lfs_vget: dinode not found) 
Date: Sat, 29 Apr 2006 09:19:42 -0600

 xtraeme@netbsd.org writes:
 > Synopsis: lfs panic: lfs_vget: dinode not found
 > 
 > State-Changed-From-To: open->feedback
 > State-Changed-By: xtraeme@netbsd.org
 > State-Changed-When: Sat, 29 Apr 2006 08:06:40 +0000
 > State-Changed-Why:
 > Do you still see this panic with a recent -current system?

 I saw this one in testing just the other day:


 lfs_cleanerd[6780]: /mnt: wrote 2108160 dirty + 40960 supporting indirect + 73728 supporting Ifile = 2222848 bytes to clean 9 segs (77% recovery)
 lfs_cleanerd[6780]: /mnt: bfree = 517543, avail = -4144, clean = 362/14648
 lfs_cleanerd[6780]: /mnt: cleaning with goal 4194304 bytes (362 segs clean)
 lfs_cleanerd[6780]: /mnt: cleaning with goal 4194304 bytes (362 segs clean)
 lfs_cleanerd[6780]: /mnt: add seg 1676 prio 53115 containing 8192 bytes
 lfs_cleanerd[6780]: /mnt: add seg 8110 prio 52760 containing 408064 bytes
 lfs_cleanerd[6780]: /mnt: add seg 2334 prio 52650 containing 512896 bytes
 lfs_cleanerd[6780]: /mnt: add seg 1536 prio 52535 containing 16384 bytes
 lfs_cleanerd[6780]: /mnt: add seg 4237 prio 52526 containing 349696 bytes
 lfs_cleanerd[6780]: sending blocks 0-770
 lfs_cleanerd[6780]: /mnt: wrote 1295232 dirty + 8192 supporting indirect + 40960 supporting Ifile = 1344384 bytes to clean 5 segs (75% recovery)
 lfs_cleanerd[6780]: /mnt: bfree = 518311, avail = 913, clean = 367/14648
 lfs_cleanerd[6780]: /mnt: cleaning with goal 4194304 bytes (367 segs clean)
 lfs_cleanerd[6780]: /mnt: cleaning with goal 4194304 bytes (367 segs clean)
 lfs_cleanerd[6780]: /mnt: add seg 334 prio 52612 containing 65280 bytes
 lfs_cleanerd[6780]: /mnt: add seg 1740 prio 52602 containing 8192 bytes
 lfs_cleanerd[6780]: /mnt: add seg 9725 prio 52442 containing 90112 bytes
 lfs_cleanerd[6780]: /mnt: add seg 1778 prio 52405 containing 8192 bytes
 lfs_cleanerd[6780]: /mnt: add seg 4485 prio 52386 containing 762624 bytes
 lfs_cleanerd[6780]: /mnt: add seg 1642 prio 52378 containing 16384 bytes
 lfs_cleanerd[6780]: /mnt: add seg 14425 prio 52339 containing 406912 bytes
 lfs_cleanerd[6780]: /mnt: add seg 14534 prio 52274 containing 335744 bytes
 lfs_cleanerd[6780]: /mnt: add seg 4424 prio 52207 containing 268416 bytes
 lfs_cleanerd[6780]: /mnt: add seg 2062 prio 52112 containing 8192 bytes
 lfs_cleanerd[6780]: /mnt: add seg 665 prio 52077 containing 395520 bytes
 lfs_cleanerd[6780]: sending blocks 0-595
 *died*

 /dev/raid0f  13393849  12896273   -844653   107%    /mnt

 searched 8 entries
 offset is 0x57326e (seg 5580)
 block is 0x7ed4a3 (seg 8117)
 searched 8 entries
 offset is 0x57326e (seg 5580)
 block is 0x7ed4a3 (seg 8117)
 panic: lfs_vget: dinode not found
 Stopped in pid 18791.1 (rm) at  netbsd:cpu_Debugger+0x5:        leave
 db{3}> tr
 cpu_Debugger() at netbsd:cpu_Debugger+0x5
 panic() at netbsd:panic+0x1c9
 lfs_vget() at netbsd:lfs_vget+0x545
 ufs_lookup() at netbsd:ufs_lookup+0x954
 VOP_LOOKUP() at netbsd:VOP_LOOKUP+0x2e
 lookup() at netbsd:lookup+0x229
 namei() at netbsd:namei+0x12c
 sys_unlink() at netbsd:sys_unlink+0x63
 syscall_plain() at netbsd:syscall_plain+0xfb
 --- syscall (number 844424930852873) ---
 0x547500:
 db{3}>


 Later...

 Greg Oster


State-Changed-From-To: feedback->open
State-Changed-By: dholland@NetBSD.org
State-Changed-When: Thu, 10 Apr 2008 04:55:57 +0000
State-Changed-Why:
feedback received, in 2006.


>Unformatted:

NetBSD Home
NetBSD PR Database Search

(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-2007 The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.