On Tue, 18 Dec 2012, [email protected] wrote:
> >Synopsis: find(1) in ntfs results in panic
> >Category: kernel
> >Environment:
>
> System : OpenBSD 5.2
> Details : OpenBSD 5.2-current (GENERIC.MP) #5: Wed Dec 12 23:22:46
> MST
> 2012 [email protected]:/usr/src/sys/arch/amd64/compile/GENERIC.MP
>
> Architecture: OpenBSD.amd64
> Machine : amd64
>
> >Description:
>
> find in read-only mounted ntfs results in kernel panic. ddb data is
> appended. The panic occurs in less than a minute after find cmd invoked
> and seems repeatable. I have the resultant crash dump.
>
> >How-To-Repeat:
>
> sudo mount -r /dev/sd0i /dos
> sudo mount -r /dev/sd0j /dos2
> $TIME find /dos /dos2 | wc
>
> >Fix:
>
> ### ddb ###
> x4:build/packages 1>sudo mount -r /dev/sd0i /dos
> x4:build/packages 2>sudo mount -r /dev/sd0j /dos2
> x4:build/packages 3>$TIME find /dos /dos2 | wc
> panic: malloc: out of space in kmem_map
> Stopped at Debugger+0x5: leave
> RUN AT LEAST 'trace' AND 'ps' AND INCLUDE OUTPUT WHEN REPORTING THIS PANIC!
> IF RUNNING SMP, USE 'mach ddbcpu <#>' AND 'trace' ON OTHER PROCESSORS, TOO.
> DO NOT EVEN BOTHER REPORTING THIS WITHOUT INCLUDING THAT INFORMATION!
> ddb{3}> trace
> Debugger() at Debugger+0x5
> panic() at panic+0xe4
> malloc() at malloc+0x496
> ntfs_ntlookupfile() at ntfs_ntlookupfile+0x131
> ntfs_vgetex() at ntfs_vgetex+0xe18
> VOP_LOOKUP() at VOP_LOOKUP+0x2c
> vfs_lookup() at vfs_lookup+0x271
> namei() at namei+0x21c
> vn_open() at vn_open+0x91
> doopenat() at doopenat+0x125
> syscall() at syscall+0x249
> --- syscall (number 5) ---
> end trace frame: 0x0, count: -11
> 0x128645a2467a:
> ddb{3}> ps
> PID PPID PGRP UID S FLAGS WAIT COMMAND
> *22131 13812 13812 1000 7 0 find
> 13779 25230 13812 1000 3 0x80 piperd wc
> 13812 25230 13812 1000 3 0x80 wait time
> 7028 1 7028 0 3 0x80 select sendmail
> 25230 1 25230 1000 3 0x80 wait bash
> 13933 1 13933 0 3 0x80 ttyin getty
> 23108 1 23108 0 3 0x80 ttyin getty
> 21122 1 21122 0 3 0x80 ttyin getty
> 19864 1 19864 0 3 0x80 ttyin getty
> 28106 1 28106 0 3 0x80 ttyin getty
> 10008 12930 12930 0 3 0x80 nanosleep perl
> 5219 1 5219 0 3 0x80 poll wsmoused
> 12930 4988 12930 0 3 0x88 pause sh
> 4988 31274 31274 0 3 0x80 piperd cron
> 31274 1 31274 0 3 0x80 select cron
> 30043 1 30043 0 3 0x80 kqread apmd
> 22482 1 22482 99 3 0x80 poll sndiod
> 2664 6577 6577 67 3 0x80 netcon httpd
> 4093 6577 6577 67 3 0x80 netcon httpd
> 26228 6577 6577 67 3 0x80 netcon httpd
> 29349 6577 6577 67 3 0x80 netcon httpd
> 25501 6577 6577 67 3 0x80 netcon httpd
> 2138 1 2138 0 3 0x80 select inetd
> 6577 1 6577 67 3 0x80 select httpd
> 11029 1 11029 0 3 0x80 select lpd
> 26174 1 26174 0 3 0x80 select sshd
> 17408 1 17408 0 3 0x80 poll rpc.statd
> 21617 1 21617 0 3 0x80 poll rpc.lockd
> 4535 3282 3282 0 3 0x80 nfsd nfsd
> 15591 3282 3282 0 3 0x80 nfsd nfsd
> 16691 3282 3282 0 3 0x80 nfsd nfsd
> 17815 3282 3282 0 3 0x80 nfsd nfsd
> 3282 1 3282 0 3 0x80 netcon nfsd
> 27784 1 27784 0 3 0x80 select mountd
> 31453 1 31453 28 3 0x80 poll portmap
> 24628 1 24628 0 3 0x80 poll ntpd
> 27188 25821 27188 83 3 0x80 poll ntpd
> 25821 1 25821 83 3 0x80 poll ntpd
> 445 10615 10615 70 3 0x80 select named
> 10615 1 10615 0 3 0x80 netio named
> 485 7566 7566 74 3 0x80 bpf pflogd
> 7566 1 7566 0 3 0x80 netio pflogd
> 18023 13564 13564 73 3 0x80 poll syslogd
> 13564 1 13564 0 3 0x80 netio syslogd
> 2325 1 2325 77 3 0x80 poll dhclient
> 13370 1 13370 0 3 0x80 poll dhclient
> 11965 0 0 0 3 0x100280 nfsidl nfsio
> 27156 0 0 0 3 0x100280 nfsidl nfsio
> 29818 0 0 0 3 0x100280 nfsidl nfsio
> 11644 0 0 0 3 0x100280 nfsidl nfsio
> 20008 1 20008 0 3 0x80 mfsidl mount_mfs
> 16 0 0 0 3 0x100200 aiodoned aiodoned
> 15 0 0 0 3 0x100200 syncer update
> 14 0 0 0 3 0x100200 cleaner cleaner
> 13 0 0 0 3 0x100200 reaper reaper
> 12 0 0 0 3 0x100200 pgdaemon pagedaemon
> 11 0 0 0 3 0x100200 bored crypto
> 10 0 0 0 3 0x100200 pftm pfpurge
> 9 0 0 0 3 0x100200 usbtsk usbtask
> 8 0 0 0 3 0x100200 usbatsk usbatsk
> 7 0 0 0 3 0x100200 acpi0 acpi0
> 6 0 0 0 3 0x40100200 idle3
> 5 0 0 0 7 0x40100200 idle2
> 4 0 0 0 7 0x40100200 idle1
> 3 0 0 0 3 0x100200 bored syswq
> 2 0 0 0 7 0x40100200 idle0
> 1 0 1 0 3 0x80 wait init
> 0 -1 0 0 3 0x200 scheduler swapper
> ddb{3}> show registers
> ds 0x3cf5 mp_pdirpa+0x1c0e
> es 0xd
> fs 0xa760 acpi_pdirpa+0x6348
> gs 0x4898 acpi_pdirpa+0x480
> rdi 0x1
> rsi 0x296
> rbp 0xffff800014d4a750
> rbx 0xffffffff80804898 seltrue_filtops+0x9b8
> rdx 0xa
> rcx 0xffff80000019e000
> rax 0x1
> r8 0xffff800014d4a670
> r9 0xffffffff80804898 seltrue_filtops+0x9b8
> r10 0xffff800014d4a628
> r11 0x8
> r12 0x100
> r13 0xffff800014d4a760
> r14 0xc
> r15 0
> rip 0xffffffff80459605 Debugger+0x5
> cs 0x8
> rflags 0x202
> rsp 0xffff800014d4a750
> ss 0x10
> Debugger+0x5: leave
> ddb{3}> show malloc
> Type InUse MemUse HighUse Limit Requests Type Lim Kern Lim
> devbuf 1695 1456K 1456K 78643K 2472 0 0
> pcb 46 12K 12K 78643K 84 0 0
> routetbl 81 8K 8K 78643K 174 0 0
> ifaddr 61 15K 15K 78643K 61 0 0
> sysctl 2 1K 1K 78643K 2 0 0
> ioctlops 0 0K 4K 78643K 1483 0 0
> mount 15 15K 15K 78643K 16 0 0
> NFS mount 4 2K 2K 78643K 4 0 0
> vnodes 28 1K 98K 78643K 1584 0 0
> UFS quota 1 32K 32K 78643K 1 0 0
> UFS mount 36 85K 85K 78643K 36 0 0
> shm 2 1K 1K 78643K 2 0 0
> VM map 2 0K 0K 78643K 2 0 0
> sem 3 2K 2K 78643K 5 0 0
> dirhash 51 12K 12K 78643K 51 0 0
> ACPI 4858 565K 633K 78643K 23997 0 0
> file desc 6 21K 25K 78643K 38 0 0
> proc 13 9K 9K 78643K 13 0 0
> VFS cluster 0 0K 0K 78643K 8 0 0
> MFS node 1 0K 0K 78643K 1 0 0
> Export Host 5 1K 1K 78643K 8 0 0
> NFS srvsock 1 0K 0K 78643K 1 0 0
> NFS daemon 5 0K 0K 78643K 5 0 0
> in_multi 25 1K 1K 78643K 25 0 0
> ether_multi 4 0K 0K 78643K 4 0 0
> ISOFS mount 1 32K 32K 78643K 1 0 0
> MSDOSFS mount 1 16K 16K 78643K 1 0 0
> ttys 786 514K 514K 78643K 786 0 0
> exec 0 0K 2K 78643K 710 0 0
> pfkey data 1 0K 0K 78643K 2 0 0
> pagedep 1 8K 8K 78643K 1 0 0
> inodedep 1 32K 36K 78643K 36 0 0
> newblk 1 0K 0K 78643K 1 0 0
> indirdep 0 0K 16K 78643K 2 0 0
> VM swap 7 874K 874K 78643K 7 0 0
> UVM amap 3360 361K 389K 78643K 31768 0 0
> UVM aobj 2 2K 2K 78643K 2 0 0
> USB 94 29K 29K 78643K 94 0 0
> USB device 23 1K 1K 78643K 23 0 0
> memdesc 1 4K 4K 78643K 1 0 0
> crypto data 1 1K 1K 78643K 1 0 0
> packet tags 0 0K 0K 78643K 1 0 0
> ip6_options 2 0K 0K 78643K 2 0 0
> NDP 8 0K 0K 78643K 9 0 0
> temp 55 10K 3762K 78643K 206452 0 0
> NTFS mount 4 6K 6K 78643K 6 0 0
> NTFS node 20957 2619K 2619K 78643K 27318 0 0
> NTFS fnode 20957 5239K 5239K 78643K 27318 0 0
> NTFS dir 16756 67024K 67024K 78643K 23098 0 0
> NTFS hash 1 32K 32K 78643K 1 0 0
> NTFS attr 71861 35930K 35930K 78643K 97323 0 0
> NTFS data 68848 14774K 14774K 78643K 92348 0 0
> NTFS vrun 6028 94K 103K 78643K 9954 0 0
> DRM 4 4K 4K 78643K 4 0 0
So you've got NTFS eating 122MB of kernel memory via 205,411 allocations. The
NTFS code is a memory hog and the only time it releases any of the
allocations is when the vnodes are released or the file system is unmounted.
The following diff should address the 'NTFS dir' memory usage, which prevents
NTFS from keeping a read buffer around just in case we want to read the
directory again (basically the opendir case). We may be able to reduce the
other memory usage, but it is not going to be overly simple...
Index: ntfs_vnops.c
===================================================================
RCS file: /cvs/src/sys/ntfs/ntfs_vnops.c,v
retrieving revision 1.26
diff -u -p -r1.26 ntfs_vnops.c
--- ntfs_vnops.c 20 Jun 2012 17:30:22 -0000 1.26
+++ ntfs_vnops.c 31 Dec 2012 03:53:10 -0000
@@ -589,7 +589,11 @@ ntfs_readdir(void *v)
if (ap->a_eofflag)
*ap->a_eofflag = VTONT(ap->a_vp)->i_size <= uio->uio_offset;
*/
- out:
+out:
+ if (fp->f_dirblbuf != NULL) {
+ free(fp->f_dirblbuf, M_NTFSDIR);
+ fp->f_dirblbuf = NULL;
+ }
free(cde, M_TEMP);
return (error);
}
> ddb{3}> show all pools
> Name Size Requests Fail Releases Pgreq Pgrel Npage Hiwat Minpg Maxpg
> Idle inpcbpl 360 176 0 114 6 0 6 6 0
> 8 0 plimitpl 152 33 0 5 2 0 2 2 0
> 8 0 tcpcbpl 560 32 0 5 4 0 4 4
> 0 8 0 rtentpl 200 37 0 1 2 0 2 2
> 0 8 0 pfosfp 40 840 0 420 5 0 5
> 5 0 8 0 pfosfpen 112 1420 0 710 34 13 21
> 21 0 8 0 pfstateitempl 24 51 0 38 1 0
> 1 1 0 8 0 pfstatekeypl 104 51 0 38 2 0
> 2 2 0 8 0 pfstatepl 304 51 0 38 4
> 0 4 4 0 8 2 pfrulepl 1328 12 0 11 4
> 0 4 4 0 8 3 semupl 112 2 0 2
> 1 0 1 1 0 8 1 semapl 104 1 0 0
> 1 0 1 1 0 8 0 nfsnodepl 464 4 0
> 4 1 0 1 1 0 8 1 dirhash 1024 194 0
> 0 49 0 49 49 0 8 0 dirrempl 64 40 0
> 40 1 0 1 1 0 8 1 mkdirpl 56 2
> 0 2 1 0 1 1 0 8 1 diraddpl 56
> 50 0 50 1 0 1 1 0 8 1 freefilepl 48
> 38 0 38 1 0 1 1 0 8 1 freeblkspl 192
> 47 0 47 2 0 2 2 0 8 2 freefragpl
> 64 3 0 3 1 0 1 1 0 8 1
> allocindirpl 104 2 0 2 1 0 1 1 0 8
> 1 indirdeppl 56 2 0 2 1 0 1 1 0
> 8 1 allocdirectpl 128 65 0 65 2 0 2 2 0
> 8 2 bmsafemappl 64 11 0 11 1 0 1 1
> 0 8 1 newblkpl 64 67 0 67 1 0 1 1
> 0 8 1 inodedeppl 152 96 0 96 4 0 4
> 4 0 8 4 pagedeppl 128 13 0 13 1 0 1
> 1 0 8 1 dino2pl 256 7 0 2 1 0
> 1 1 0 8 0 dino1pl 128 2072 0 1624 67 35
> 32 67 0 8 8 ffsino 232 2079 0 1626 122
> 78 44 122 0 8 8 nchpl 144 36133 0 31924 156
> 0 156 156 0 8 0 vnodes 264 21422 0 0
> 1429 0 1429 1429 0 8 0 namei 1024 82177 0
> 82176 2 0 2 2 0 8 1 nfsreqpl 96 8 0
> 8 1 0 1 1 0 8 1 scxspl 200 32784
> 0 32784 2 0 2 2 0 8 2 ifaddritempl 64
> 13 0 0 1 0 1 1 0 8 0 wqtasks 40
> 68 0 68 1 0 1 1 0 8 1 sigapl 432
> 583 0 535 6 0 6 6 0 8 0 knotepl
> 104 2 0 0 1 0 1 1 0 8 0
> kqueuepl 256 1 0 0 1 0 1 1 0 8
> 0 pipepl 120 646 0 641 1 0 1 1 0
> 8 0 fdescpl 440 584 0 535 6 0 6 6 0
> 8 0 filepl 120 49838 0 49678 5 0 5 5
> 0 8 0 lockfpl 88 15 0 10 1 0 1 1
> 0 8 0 pcredpl 24 602 0 535 1 0 1
> 1 0 8 0 sessionpl 64 35 0 4 1 0 1
> 1 0 8 0 pgrppl 40 47 0 15 1 0
> 1 1 0 8 0 ucredpl 80 421 0 384 1 0
> 1 1 0 8 0 zombiepl 144 535 0 535 1
> 0 1 1 0 8 1 processpl 640 602 0 535 12
> 0 12 12 0 8 0 procpl 616 602 0 535
> 12 0 12 12 0 8 0 sockpl 472 247 0 152
> 13 0 13 13 0 8 1 mcl2k 2048 235 0
> 228 9 0 9 9 4 3072 5 mbpl 256 1786 0
> 1765 4 0 4 4 1 384 2 bufpl 304 32390
> 0 368 2464 0 2464 2464 0 242 0 anonpl 24 45063
> 0 30364 100 0 100 100 0 94 0 amappl 72
> 31417 0 28087 95 0 95 95 0 75 12 dma4096
> 4096 4 0 4 1 0 1 1 0 8 1 dma512
> 512 27 0 22 1 0 1 1 0 8 0
> dma256 256 33 0 33 1 0 1 1 0 8
> 1 dma128 128 1 0 1 1 0 1 1 0
> 8 1 dma64 64 10 0 10 1 0 1 1 0
> 8 1 dma32 32 29 0 29 1 0 1 1
> 0 8 1 dma16 24 7 0 7 1 0 1 1
> 0 8 1 aobjpl 64 1 0 0 1 0 1
> 1 0 8 0 uaddrrnd 40 584 0 535 1 0 1
> 1 0 8 0 uaddrbestfit 32 2 0 0 1 0
> 1 1 0 8 0 uaddr 24 584 0 535 1 0
> 1 1 0 8 0 vmmpekpl 168 2133 0 2126 1
> 0 1 1 0 8 0 vmmpepl 168 69281 0 61459 421
> 0 421 421 0 357 48 vmsppl 224 583 0 535
> 3 0 3 3 0 8 0 pdppl 4096 583 0 535
> 51 0 51 51 0 8 3 pvpl 32 138251 0
> 124215 128 0 128 128 0 263 1 pmappl 152 583
> 0 535 2 0 2 2 0 8 0 extentpl 40 111
> 0 52 1 0 1 1 0 8 0 phpool 96
> 4129 0 0 101 0 101 101 0 8 0 ddb{3}> show
> extents
> extent `swap0x0000' (0x0 - 0x3003ea), flags=0
> 0x0 - 0x0
> extent `swapmap' (0x1 - 0x7fffffff), flags=0
> 0x1 - 0x3003eb
> extent `ppb3 pcipmem' (0x0 - 0xffffffffffffffff), flags=0
> 0x0 - 0xfaefffff
> 0xfaff0000 - 0xffffffffffffffff
> extent `ppb3 pcimem' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xfbefffff
> 0xfbfff000 - 0xffffffff
> extent `ppb3 pciio' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xdfff
> 0xe800 - 0xe8ff
> 0xf000 - 0xffffffff
> extent `ppb2 pcimem' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xfbdfffff
> 0xfbefec00 - 0xfbefec7f
> 0xfbeff000 - 0xfbeff07f
> 0xfbeff400 - 0xfbeff47f
> 0xfbeff800 - 0xffffffff
> extent `ppb1 pcimem' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xfbcfffff
> 0xfbdfc000 - 0xffffffff
> extent `ppb1 pciio' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xcfff
> 0xd800 - 0xd8ff
> 0xe000 - 0xffffffff
> extent `drmext' (0x40000000 - 0x7fffffffffffffff), flags=2<NOCOALESCE>
> extent `ppb0 pcipmem' (0x0 - 0xffffffffffffffff), flags=0
> 0x0 - 0xffffffffffffffff
> extent `ppb0 pcimem' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xfbbfffff
> 0xfbce8000 - 0xfbcebfff
> 0xfbcf0000 - 0xffffffff
> extent `ppb0 pciio' (0x0 - 0xffffffff), flags=0
> 0x0 - 0xc0ff
> 0xd000 - 0xffffffff
> extent `pcibus' (0x0 - 0xff), flags=0
> 0x0 - 0x5
> extent `pcimem' (0x0 - 0xffffffffffffffff), flags=0
> 0x0 - 0x3fffffff
> 0xcff80000 - 0xdfffffff
> 0xfaf00000 - 0xfaffffff
> 0xfbaf4000 - 0xfbaf7fff
> 0xfbaf9000 - 0xfbaf9fff
> 0xfbafa800 - 0xfbafa8ff
> 0xfbafb000 - 0xfbaff0ff
> 0xfbaff800 - 0xfbaffbff
> 0xfbb00000 - 0xfbffffff
> 0xff700000 - 0xffffffff
> 0x1000000000 - 0xffffffffffffffff
> extent `pciio' (0x0 - 0xffffffff), flags=0
> 0x7000 - 0x700f
> 0x8000 - 0x8003
> 0x9000 - 0x9007
> 0xa000 - 0xa003
> 0xb000 - 0xb007
> 0xc000 - 0xefff
> 0xff00 - 0xff0f
> 0x10000 - 0xffffffff
> extent `iomem' (0x0 - 0xffffffffffff), flags=3<NOCOALESCE,FIXED>
> 0x5000 - 0x9dfff
> 0xa0000 - 0xbffff
> 0x100000 - 0xffffff
> 0x1000000 - 0x3fffffff
> 0xfbaf4000 - 0xfbaf7fff
> 0xfbaf9000 - 0xfbaf9fff
> 0xfbafa800 - 0xfbafa8ff
> 0xfbafb000 - 0xfbafbfff
> 0xfbafc000 - 0xfbafcfff
> 0xfbafd000 - 0xfbafdfff
> 0xfbafe000 - 0xfbafefff
> 0xfbaff000 - 0xfbaff0ff
> 0xfbaff800 - 0xfbaffbff
> 0xfbcf0000 - 0xfbcfffff
> 0xfbdfc000 - 0xfbdfffff
> 0xfed00000 - 0xfed003ff
> extent `ioport' (0x0 - 0xffff), flags=3<NOCOALESCE,FIXED>
> 0x0 - 0xb
> 0x2e - 0x2f
> 0x40 - 0x43
> 0x60 - 0x60
> 0x61 - 0x61
> 0x64 - 0x64
> 0x80 - 0x8e
> 0xb0 - 0xb0
> 0xc0 - 0xd7
> 0x170 - 0x177
> 0x1f0 - 0x1f7
> 0x290 - 0x297
> 0x376 - 0x376
> 0x378 - 0x37b
> 0x3c0 - 0x3cf
> 0x3d0 - 0x3df
> 0x3f0 - 0x3f5
> 0x3f6 - 0x3f6
> 0x3f7 - 0x3f7
> 0x3f8 - 0x3ff
> 0x800 - 0x801
> 0x802 - 0x803
> 0x804 - 0x805
> 0x808 - 0x80b
> 0x820 - 0x823
> 0x824 - 0x827
> 0x8ff - 0x8ff
> 0xb00 - 0xb0f
> 0xe800 - 0xe8ff
> 0xff00 - 0xff0f
> ddb{3}> show uvmexp
> Current UVM status:
> pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
> 251508 VM pages: 17598 active, 841 inactive, 3 wired, 152828 free
> min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
> pages 0 anon, 0 vnode, 0 vtext
> freemin=8383, free-target=11177, inactive-target=0, wired-max=83836
> faults=111945, traps=110328, intrs=33382, ctxswitch=73358 fpuswitch=31
> softint=16767, syscalls=1218330, swapins=0, swapouts=0, kmapent=18
> fault counts:
> noram=0, noanon=0, pgwait=0, pgrele=0
> ok relocks(total)=3739(3739), anget(retries)=59308(0), amapcopy=44354
> neighbor anon/obj pg=6043/56410, gets(lock/unlock)=22923/3739
> cases: anon=46711, anoncow=12597, obj=20171, prcopy=2752, przero=29714
> daemon and swap counts:
> woke=0, revs=0, scans=0, obscans=0, anscans=0
> busy=0, freed=0, reactivate=0, deactivate=0
> pageouts=0, pending=0, nswget=0
> nswapdev=1, nanon=0, nanonneeded=0 nfreeanon=0
> swpages=3146730, swpginuse=0, swpgonly=0 paging=0
> kernel pointers:
> objs(kern)=0xffffffff80d28ba0
--
"Reason is not automatic. Those who deny it cannot be conquered by it.
Do not count on them. Leave them alone." -- Ayn Rand
