Bug 206820
| Summary: | [ext2fs] Panic when writing to ext3fs mounted as ext2fs | ||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | Base System | Reporter: | Arrigo Marchiori <ardovm> | ||||||||
| Component: | kern | Assignee: | Pedro F. Giffuni <pfg> | ||||||||
| Status: | Closed FIXED | ||||||||||
| Severity: | Affects Only Me | CC: | pfg | ||||||||
| Priority: | --- | Flags: | pfg:
mfc-stable10+
pfg: mfc-stable9+ |
||||||||
| Version: | 9.3-STABLE | ||||||||||
| Hardware: | Any | ||||||||||
| OS: | Any | ||||||||||
| Attachments: |
|
||||||||||
Created attachment 166396 [details]
/var/crash/core.txt from the first panic
Created attachment 166397 [details]
/var/crash/core.txt from the second panic
The panic is also reproducible when writing to a md(4) instead of a USB drive.
The stack trace is analogous.
(kgdb) bt
#0 doadump (textdump=1) at pcpu.h:250
#1 0xc0aed3ae in kern_reboot (howto=260)
at /usr/src/sys/kern/kern_shutdown.c:454
#2 0xc0aed6a5 in panic (fmt=<value optimized out>)
at /usr/src/sys/kern/kern_shutdown.c:642
#3 0xc0d70ede in vm_fault_hold (map=0xc1b8d000, vaddr=3799322624,
fault_type=2 '\002', fault_flags=0, m_hold=0x0)
at /usr/src/sys/vm/vm_fault.c:289
#4 0xc0d7355b in vm_fault (map=0xc1b8d000, vaddr=3799322624,
fault_type=<value optimized out>, fault_flags=0)
at /usr/src/sys/vm/vm_fault.c:229
#5 0xc0fb619f in trap_pfault (frame=0xf0a8c964, usermode=0, eva=3799322628)
at /usr/src/sys/i386/i386/trap.c:932
#6 0xc0fb744b in trap (frame=0xf0a8c964) at /usr/src/sys/i386/i386/trap.c:553
#7 0xc0f9fee7 in calltrap () at /usr/src/sys/i386/i386/exception.s:173
#8 0xcc966759 in ext2_i2ei (ip=0xc7ba8300, ei=0xe2750f80)
at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode_cnv.c:152
#9 0xcc965a56 in ext2_update (vp=0xc99c5470, waitfor=1)
at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode.c:91
#10 0xcc96bd12 in ext2_makeinode (mode=8, dvp=0xc99c46a8, vpp=0xf0a8cb88,
cnp=0xf0a8cb9c)
at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_vnops.c:1586
#11 0xc0fdd612 in VOP_CREATE_APV (vop=0xcc96f3a0, a=0xf0a8cae8)
at vnode_if.c:260
#12 0xc0b9d989 in vn_open_cred (ndp=0xf0a8cb5c, flagp=0xf0a8cc24,
cmode=<value optimized out>, vn_open_flags=0, cred=0xc8bcf600,
fp=0xc940bdc8) at vnode_if.h:109
#13 0xc0b9de6b in vn_open (ndp=0xf0a8cb5c, flagp=0xf0a8cc24, cmode=493,
fp=0xc940bdc8) at /usr/src/sys/kern/vfs_vnops.c:113
#14 0xc0b99460 in kern_openat (td=0xca383900, fd=-100,
path=0x284a61a0 <Address 0x284a61a0 out of bounds>, pathseg=UIO_USERSPACE,
flags=2562, mode=493) at /usr/src/sys/kern/vfs_syscalls.c:1128
#15 0xc0b998b5 in kern_open (td=0xca383900,
path=0x284a61a0 <Address 0x284a61a0 out of bounds>, pathseg=UIO_USERSPACE,
flags=2561, mode=493) at /usr/src/sys/kern/vfs_syscalls.c:1079
#16 0xc0b998f0 in sys_open (td=0xca383900, uap=0xf0a8cccc)
at /usr/src/sys/kern/vfs_syscalls.c:1055
#17 0xc0fb6869 in syscall (frame=0xf0a8cd08) at subr_syscall.c:142
#18 0xc0f9ff8c in Xint0x80_syscall () at /usr/src/sys/i386/i386/exception.s:279
(kgdb) frame 8
#8 0xcc966759 in ext2_i2ei (ip=0xc7ba8300, ei=0xe2750f80)
at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode_cnv.c:152
152 ei->e2di_ctime_extra = NSEC_TO_XTIME(ip->i_ctimensec);
(kgdb) print *ip
$1 = {i_vnode = 0xc99c5470, i_ump = 0xc7b92380, i_flag = 0, i_number = 49160,
i_e2fs = 0xc7858c00, i_modrev = 18475684767084, i_count = 0, i_endoff = 0,
i_diroff = 0, i_offset = 0, i_block_group = 24, i_next_alloc_block = 0,
i_next_alloc_goal = 0, i_mode = 33261, i_nlink = 1, i_uid = 0, i_gid = 0,
i_size = 0, i_blocks = 0, i_atime = 1454338085, i_mtime = 1454338085,
i_ctime = 1454338085, i_birthtime = 1454338085, i_mtimensec = 522810000,
i_atimensec = 522810000, i_ctimensec = 522810000, i_birthnsec = 522809000,
i_gen = 679956546, i_flags = 0, i_db = {0 <repeats 12 times>}, i_ib = {0, 0,
0}, i_ext_cache = {ec_start = 0, ec_blk = 0, ec_len = 0, ec_type = 0}}
(kgdb) print *ei
Cannot access memory at address 0xe2750f80
(kgdb) frame 9
#9 0xcc965a56 in ext2_update (vp=0xc99c5470, waitfor=1)
at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode.c:91
91 ext2_i2ei(ip, (struct ext2fs_dinode *)((char *)bp->b_data +
(kgdb) print *vp
$2 = {v_type = VREG, v_tag = 0xcc96e830 "ext2fs", v_op = 0xcc96f3a0,
v_data = 0xc7ba8300, v_mount = 0xc7dc77ec, v_nmntvnodes = {tqe_next = 0x0,
tqe_prev = 0xc99c56bc}, v_un = {vu_mount = 0x0, vu_socket = 0x0,
vu_cdev = 0x0, vu_fifoinfo = 0x0}, v_hashlist = {le_next = 0x0,
le_prev = 0xc793f988}, v_hash = 49160, v_cache_src = {lh_first = 0x0},
v_cache_dst = {tqh_first = 0x0, tqh_last = 0xc99c54a0}, v_cache_dd = 0x0,
v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = {
lo_name = 0xcc96e830 "ext2fs", lo_flags = 108199944, lo_data = 0,
lo_witness = 0x0}, lk_lock = 3392682240, lk_exslpfail = 0, lk_timo = 51,
lk_pri = 96}, v_interlock = {lock_object = {
lo_name = 0xc11003e9 "vnode interlock", lo_flags = 16973824,
lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, v_vnlock = 0xc99c54c8,
v_holdcnt = 1, v_usecount = 1, v_iflag = 512, v_vflag = 0, v_writecount = 0,
v_actfreelist = {tqe_next = 0xc99c56a8, tqe_prev = 0xc7dc782c}, v_bufobj = {
bo_mtx = {lock_object = {lo_name = 0xc11003f9 "bufobj interlock",
lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4},
bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0xc99c5530},
bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0,
tqh_last = 0xc99c5540}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0,
bo_flag = 0, bo_ops = 0xc1371e80, bo_bsize = 1024, bo_object = 0x0,
bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0xc99c5470,
__bo_vnode = 0xc99c5470}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0,
v_rl = {rl_waiters = {tqh_first = 0x0, tqh_last = 0xc99c5580},
rl_currdep = 0x0}}
Running e2fsck on the md(4)-backed file, after reboot: # e2fsck /dev/md0s1 e2fsck 1.42.13 (17-May-2015) /dev/md0s1 was not cleanly unmounted, check forced. Pass 1: Checking inodes, blocks, and sizes Inode 30721, i_size is 24, should be 1024. Fix<y>? yes Inode 49154 is in use, but has dtime set. Fix<y>? yes Inode 110593, i_size is 24, should be 1024. Fix<y>? yes Inode 126977, i_size is 24, should be 1024. Fix<y>? yes Pass 2: Checking directory structure Pass 3: Checking directory connectivity Pass 4: Checking reference counts Pass 5: Checking group summary information Block bitmap differences: +123139 +(196867--196880) +197137 +(197426--197445) +197702 +(197876--197888) +442627 +508163 Fix<y>? yes Free blocks count wrong for group #15 (7934, counted=7933). Fix<y>? yes Free blocks count wrong for group #24 (7934, counted=7885). Fix<y>? yes Free blocks count wrong for group #54 (7934, counted=7933). Fix<y>? yes Free blocks count wrong for group #62 (7934, counted=7933). Fix<y>? yes Free blocks count wrong (497201, counted=497149). Fix<y>? yes Inode bitmap differences: +30721 +(49153--49159) +110593 +126977 Fix<y>? yes Free inodes count wrong for group #15 (2048, counted=2047). Fix<y>? yes Directories count wrong for group #15 (0, counted=1). Fix<y>? yes Free inodes count wrong for group #24 (2048, counted=2041). Fix<y>? yes Directories count wrong for group #24 (0, counted=1). Fix<y>? yes Free inodes count wrong for group #54 (2048, counted=2047). Fix<y>? yes Directories count wrong for group #54 (0, counted=1). Fix<y>? yes Free inodes count wrong for group #62 (2048, counted=2047). Fix<y>? yes Directories count wrong for group #62 (0, counted=1). Fix<y>? yes Free inodes count wrong (131061, counted=131051). Fix<y>? yes /dev/md0s1: ***** FILE SYSTEM WAS MODIFIED ***** /dev/md0s1: 21/131072 files (9.5% non-contiguous), 27135/524284 blocks FWIW, the problem is _not_ reproducible on my 10-RELEASE x86-64 machine: # uname -a FreeBSD myhost 10.1-RELEASE-p26 FreeBSD 10.1-RELEASE-p26 #0: Wed Jan 13 20:59:29 UTC 2016 root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC amd64 Hello Arrigo; Thank you so much for testing! Please try this: - On 9-stable revert r294971. - Try to reproduce on 10-stable. Both 9-stable and 10-stable have a chenge to use the extra timestamps. These are supposed to be unused in ext3. Pedro. (In reply to Pedro F. Giffuni from comment #6) Hello Pedro, thank you for taking care of this. [...] > Please try this: > > - On 9-stable revert r294971. 9-STABLE r294970 does not show this problem. That change may be the culprit? > - Try to reproduce on 10-stable. I don't have any 10-stable machines. I am sorry. Hi again; (In reply to Arrigo Marchiori from comment #7) The change is pretty much the main suspect. It did pass some basic tests before being committed but there may be special cases. I appreciate the report. One more question what is the inode size of the filesystem? A commit references this bug: Author: pfg Date: Wed Feb 3 14:31:24 UTC 2016 New revision: 295209 URL: https://svnweb.freebsd.org/changeset/base/295209 Log: Revert r294695: ext2fs: passthrough any extra timestamps to the dinode struct. While it passed the classic testing, the change appears to have caused some regression and still requires some more precautions. PR: 206820 MFC after: 3 days Changes: head/sys/fs/ext2fs/ext2_inode_cnv.c Created attachment 166499 [details]
Output of dumpe2fs on an ext2 filesystem correctly populated by stable r294970
This filesystem was created into a 512 megabyte md(4), with the mkfs.ext3 and tune2fs invocations from the bug decription.
Inode count: 131072
Block count: 524280
Block size: 1024
Fragment size: 1024
Inode size: 128
(In reply to Arrigo Marchiori from comment #10) Thank you Arrigo! That is the root cause: The inode is too small and our implementation is not being careful about the inode size. I didn't notice in my testing because I ran my tests in a USB mem with the default ext3 settings. Reverting is a workaround ... for now. A commit references this bug: Author: pfg Date: Sat Feb 6 16:58:56 UTC 2016 New revision: 295353 URL: https://svnweb.freebsd.org/changeset/base/295353 Log: MFC r295209; Revert r294695; passthrough any extra timestamps to the dinode struct. The original ext2fs change worked fine on disks formated with default values, but it was the cause of a regression when inodes are small. Revert it for now, while we figure out safer ways pass such values, PR: 206820 Approved by: re Changes: _U stable/10/ stable/10/sys/fs/ext2fs/ext2_inode_cnv.c A commit references this bug: Author: pfg Date: Sat Feb 6 17:10:47 UTC 2016 New revision: 295354 URL: https://svnweb.freebsd.org/changeset/base/295354 Log: MFC r295209; Revert r294695; passthrough any extra timestamps to the dinode struct. The original ext2fs change worked fine on disks formated with default values, but it was the cause of a regression when inodes are small. Revert it for now, while we figure out safer ways pass such values, PR: 206820 Changes: _U stable/9/sys/ _U stable/9/sys/fs/ stable/9/sys/fs/ext2fs/ext2_inode_cnv.c Fixed on all supported versions. After 10.3 Release I will be considering a better enhancement. Huge thanks for all the testing!! (In reply to Pedro F. Giffuni from comment #14) > Fixed on all supported versions. > After 10.3 Release I will be considering a better enhancement. > > Huge thanks for all the testing!! Thank you for the quick fix! |
I encountered two panics on the very same operation: writing files to a ext3fs formatted USB drive that is mounted as ext2fs. The filesystem is created by a shell script, issuing the following commands: # mkfs.ext3 /dev/da0s1 # tune2fs -O ^dir_index /dev/da0s1 # mount -t ext2fs /dev/da0s1 /mnt And files are extracted from a tar archive (produced by gnu tar): # ssh linuxhost 'cat filesystem.tar.bz2' | tar -C /mnt -xjf -' My system is a 9-STABLE updated this morning. # uname -a FreeBSD myhost 9.3-STABLE FreeBSD 9.3-STABLE #144 r295117M: Mon Feb 1 09:31:54 CET 2016 root@myhost:/usr/obj/usr/src/sys/GENERIC i386 Both panics are triggered by function ext2_i2ei at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode_cnv.c:152 Here is an excerpt of the backtrace: [...] #7 0xc0f9fee7 in calltrap () at /usr/src/sys/i386/i386/exception.s:173 #8 0xd00f5759 in ext2_i2ei (ip=0xcab8f100, ei=0xe17e0f80) at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode_cnv.c:152 #9 0xd00f4a56 in ext2_update (vp=0xce0f38e0, waitfor=1) at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode.c:91 #10 0xd00fad12 in ext2_makeinode (mode=8, dvp=0xcc69f11c, vpp=0xeffeab88, cnp=0xeffeab9c) at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_vnops.c:1586 #11 0xc0fdd612 in VOP_CREATE_APV (vop=0xd00fe3a0, a=0xeffeaae8) at vnode_if.c:260 #12 0xc0b9d989 in vn_open_cred (ndp=0xeffeab5c, flagp=0xeffeac24, cmode=<value optimized out>, vn_open_flags=0, cred=0xc9ee7100, fp=0xcafea508) at vnode_if.h:109 #13 0xc0b9de6b in vn_open (ndp=0xeffeab5c, flagp=0xeffeac24, cmode=493, fp=0xcafea508) at /usr/src/sys/kern/vfs_vnops.c:113 #14 0xc0b99460 in kern_openat (td=0xc8420900, fd=-100, path=0x284a61a0 <Address 0x284a61a0 out of bounds>, pathseg=UIO_USERSPACE, flags=2562, mode=493) at /usr/src/sys/kern/vfs_syscalls.c:1128 #15 0xc0b998b5 in kern_open (td=0xc8420900, path=0x284a61a0 <Address 0x284a61a0 out of bounds>, pathseg=UIO_USERSPACE, flags=2561, mode=493) at /usr/src/sys/kern/vfs_syscalls.c:1079 #16 0xc0b998f0 in sys_open (td=0xc8420900, uap=0xeffeaccc) at /usr/src/sys/kern/vfs_syscalls.c:1055 #17 0xc0fb6869 in syscall (frame=0xeffead08) at subr_syscall.c:142 #18 0xc0f9ff8c in Xint0x80_syscall () at /usr/src/sys/i386/i386/exception.s:279 When kgdb'ing into frame 8, the pointer to ei seems not to be valid: (kgdb) frame 8 #8 0xd00f5759 in ext2_i2ei (ip=0xcab8f100, ei=0xe17e0f80) at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode_cnv.c:152 152 ei->e2di_ctime_extra = NSEC_TO_XTIME(ip->i_ctimensec); (kgdb) print *ip $1 = {i_vnode = 0xce0f38e0, i_ump = 0xccadc240, i_flag = 0, i_number = 122888, i_e2fs = 0xc7798c00, i_modrev = 62488400780442, i_count = 0, i_endoff = 0, i_diroff = 0, i_offset = 0, i_block_group = 60, i_next_alloc_block = 0, i_next_alloc_goal = 0, i_mode = 33261, i_nlink = 1, i_uid = 0, i_gid = 0, i_size = 0, i_blocks = 0, i_atime = 1454332232, i_mtime = 1454332232, i_ctime = 1454332232, i_birthtime = 1454332232, i_mtimensec = 700120000, i_atimensec = 700120000, i_ctimensec = 700120000, i_birthnsec = 700118000, i_gen = 1784569991, i_flags = 0, i_db = {0 <repeats 12 times>}, i_ib = {0, 0, 0}, i_ext_cache = {ec_start = 0, ec_blk = 0, ec_len = 0, ec_type = 0}} (kgdb) print *ei Cannot access memory at address 0xe17e0f80 Some information from the previous frame: (kgdb) frame 9 #9 0xd00f4a56 in ext2_update (vp=0xce0f38e0, waitfor=1) at /usr/src/sys/modules/ext2fs/../../fs/ext2fs/ext2_inode.c:91 91 ext2_i2ei(ip, (struct ext2fs_dinode *)((char *)bp->b_data + (kgdb) print bp $2 = (struct buf *) 0xe112a8a8 (kgdb) print *bp $3 = {b_bufobj = 0xcbe062e4, b_bcount = 1024, b_caller1 = 0x0, b_data = 0xe17e0c00 "íA", b_error = 0, b_iocmd = 2 '\002', b_ioflags = 2 '\002', b_iooffset = 503319552, b_resid = 0, b_iodone = 0, b_blkno = 983046, b_offset = 503319552, b_bobufs = {tqe_next = 0x0, tqe_prev = 0xe1231828}, b_left = 0xe12317f0, b_right = 0x0, b_vflags = 0, b_freelist = {tqe_next = 0x0, tqe_prev = 0xe123183c}, b_qindex = 2, b_flags = 2684354720, b_xflags = 1 '\001', b_lock = {lock_object = { lo_name = 0xc10fe54f "bufwait", lo_flags = 108199936, lo_data = 0, lo_witness = 0x0}, lk_lock = 3359770880, lk_exslpfail = 0, lk_timo = 0, lk_pri = 96}, b_bufsize = 1024, b_runningbufspace = 0, b_kvabase = 0xe17e0000 "#", b_kvaalloc = 0x0, b_kvasize = 16384, b_lblkno = 983046, b_vp = 0xcbe06238, b_dirtyoff = 0, b_dirtyend = 0, b_rcred = 0x0, b_wcred = 0x0, b_saveaddr = 0xe17e0000, b_pager = { pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0x0, tqh_last = 0xe11ad6f0}, cluster_entry = {tqe_next = 0x0, tqe_prev = 0xe11ad6f0}}, b_pages = {0xc51334b0, 0x0 <repeats 31 times>}, b_npages = 1, b_dep = {lh_first = 0x0}, b_fsprivate1 = 0x0, b_fsprivate2 = 0x0, b_fsprivate3 = 0x0, b_pin_count = 0} Please tell me what information I can provide, to help tracking this problem down.