From owner-freebsd-fs@FreeBSD.ORG Mon Oct 27 15:16:12 2014 Return-Path: Delivered-To: freebsd-fs@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 2858EFE3 for ; Mon, 27 Oct 2014 15:16:12 +0000 (UTC) Received: from mail1.sandvine.com (Mail1.sandvine.com [64.7.137.134]) by mx1.freebsd.org (Postfix) with ESMTP id BEFD1382 for ; Mon, 27 Oct 2014 15:16:11 +0000 (UTC) Received: from WTL-EXCHP-1.sandvine.com ([fe80::ac6b:cc1e:f2ff:93aa]) by wtl-exchp-2.sandvine.com ([fe80::68ac:f071:19ff:3455%19]) with mapi id 14.03.0195.001; Mon, 27 Oct 2014 11:15:01 -0400 From: Adam Parco To: "freebsd-fs@freebsd.org" Subject: panic: devfs_fsync: vop_stdfsync failed. Thread-Topic: panic: devfs_fsync: vop_stdfsync failed. Thread-Index: Ac/x88uhWWQKkD58QMu09zdrpmOZwQ== Date: Mon, 27 Oct 2014 15:15:00 +0000 Message-ID: Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-originating-ip: [192.168.200.58] MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable X-Content-Filtered-By: Mailman/MimeDel 2.1.18-1 X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 27 Oct 2014 15:16:12 -0000 Hello, I am investigating making FreeBSD 8.2 more resilient to removing a USB duri= ng a write. In my short testing I have gotten 3 different failures. I wou= ld like to discuss potential solutions for the first failure. I looked at = head source and there doesn't appear to be any fixes for this particular is= sue. >From what I have gathered, it looks like: - the filesystem synchronizer daemon wakes up - tries to sync vnodes - devfs_fsync realizes the device went away with dirty set, warns = of data loss: o "Device da0s1 went missing before all of the data could be written to i= t; expect data loss." - vop_stdfync loops a couple times trying to handle the dirty item= s - eventual gives up o "fsync: giving up on dirty" - Dirty count will still be >0 and errno should be EAGAIN (not 0) - Panic o "devfs_fsync: vop_stdfsync failed." When we give up on dirty, should we be clearing the dirty count? Otherwise= we will always panic after this. Thoughts? Other suggestions? Thanks, Adam. bt: #0 doadump () at pcpu.h:224 #1 0xffffffff8045fbe9 in boot (howto=3D260) at /usr/src/sys/kern/kern_shut= down.c:508 #2 0xffffffff8046011d in panic (fmt=3D0x1
) at = /usr/src/sys/kern/kern_shutdown.c:775 #3 0xffffffff803ec3db in devfs_fsync (ap=3D0xffffff862b3edb20) at /usr/src= /sys/fs/devfs/devfs_vnops.c:569 #4 0xffffffff8069c8ca in VOP_FSYNC_APV (vop=3D0xffffffff80892fa0, a=3D0xff= ffff862b3edb20) at vnode_if.c:1267 #5 0xffffffff804e3e27 in sync_vnode (slp=3D0xffffff0006136af0, bo=3D0xffff= ff862b3edbc0, td=3D0xffffff0006005480) at vnode_if.h:549 #6 0xffffffff804e406d in sched_sync () at /usr/src/sys/kern/vfs_subr.c:184= 1 #7 0xffffffff80438ed2 in fork_exit (callout=3D0xffffffff804e3ec0 , arg=3D0x0, frame=3D0xffffff862b3edc50) at /usr/src/sys/kern/kern_fork.= c:847 #8 0xffffffff80633dbe in fork_trampoline () at /usr/src/sys/amd64/amd64/ex= ception.S:599 console: da0 at umass-sim0 bus 0 scbus0 target 0 lun 0 da0: Removable Direct Access SCSI-0 device da0: 40.000MB/s transfers da0: 7441MB (15240576 512 byte sectors: 255H 63S/T 948C) [-- MARK -- Fri Oct 24 13:39:00 2014] ugen1.3: at usbus1 (disconnected) umass0: at uhub3, port 1, addr 3 (disconnected) (da0:umass-sim0:0:0:0): AutoSense failed g_vfs_done():da0s1[WRITE(offset=3D50139136, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50204672, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50270208, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50335744, length=3D65536)](da0:umass-sim0= :0:0:0): lost device error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50401280, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50466816, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50532352, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50597888, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50663424, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50728960, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50794496, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50860032, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50925568, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50991104, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D50073600, length=3D65536)]error =3D 5 g_vfs_done():da0s1[WRITE(offset=3D51056640, length=3D65536)]error =3D 6 g_vfs_done():da0s1[WRITE(offset=3D51122176, length=3D65536)]error =3D 6 (da0:umass-sim0:0:0:0): Synchronize cache failed, status =3D=3D 0xa, scsi s= tatus =3D=3D 0x0 (da0:umass-sim0:0:0:0): removing device entry g_vfs_done():[unknown][WRITE(offset=3D51187712, length=3D65536)]error =3D 6 g_vfs_done():[unknown][WRITE(offset=3D51253248, length=3D65536)]error =3D 6 g_vfs_done():[unknown][WRITE(offset=3D51318784, length=3D65536)]error =3D 6 Device da0s1 went missing before all of the data could be written to it; ex= pect data loss. fsync: giving up on dirty 0xffffff08c7eec1d8: tag devfs, type VCHR usecount 1, writecount 0, refcount 4 mountedhere 0xffffff0109ddf400 flags (VI_DOOMED) v_object 0xffffff08c7ec7438 ref 0 pages 2169 lock type devfs: EXCL by thread 0xffffff0adf0b6900 (pid 64960) dev da0s1 panic: devfs_fsync: vop_stdfsync failed. pci: 1752 correctable, 0 uncorrectable, 0 fatal cpu: 2 correctable, 0 uncorrectable, 0 fatal cpuid =3D 4 curthread =3D getty/getty (64960/100629) cpu_ticks =3D 19048675905756 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801e51ca =3D db_trace_self_wrapper+0x2= a panic() at 0xffffffff80460148 =3D panic+0x228 devfs_fsync() at 0xffffffff803ec3db =3D devfs_fsync+0x8b VOP_FSYNC_APV() at 0xffffffff8069c8ca =3D VOP_FSYNC_APV+0x4a bufsync() at 0xffffffff804cbcd8 =3D bufsync+0x38 bufobj_invalbuf() at 0xffffffff804e1997 =3D bufobj_invalbuf+0x87 vgonel() at 0xffffffff804e1c56 =3D vgonel+0xb6 vgone() at 0xffffffff804e1e89 =3D vgone+0x39 devfs_delete() at 0xffffffff803eab89 =3D devfs_delete+0x189 devfs_populate_loop() at 0xffffffff803eb37d =3D devfs_populate_loop+0x3ad devfs_populate() at 0xffffffff803eb461 =3D devfs_populate+0x21 devfs_lookup() at 0xffffffff803eeb94 =3D devfs_lookup+0x2d4 VOP_LOOKUP_APV() at 0xffffffff8069e9bc =3D VOP_LOOKUP_APV+0x4c lookup() at 0xffffffff804d7eea =3D lookup+0x37a namei() at 0xffffffff804d8cff =3D namei+0x3bf vn_open_cred() at 0xffffffff804ed583 =3D vn_open_cred+0x1e3 kern_openat() at 0xffffffff804eaab9 =3D kern_openat+0x149 syscallenter() at 0xffffffff8049bad4 =3D syscallenter+0x104 syscall() at 0xffffffff8064a15c =3D syscall+0x4c Xfast_syscall() at 0xffffffff80633b52 =3D Xfast_syscall+0xe2 --- syscall (5, FreeBSD ELF64, open), rip =3D 0x300845cfc, rsp =3D 0x7fffff= ffecd8, rbp =3D 0x5086a0 --- Uptime: 2h26m42s Physical memory: 49040 MB Dumping 1934 MB: 1919 1903 1887 1871 1855 1839 1823 1807 1791 1775 1759 174= 3 1727 1711 1695 1679 1663 1647 1631 1615 1599 1583 1567 1551 1535 1519 150= 3 1487 1471 1455 1439 1423 1407 1391 1375 1359 1343 1327 1311 1295 1279 126= 3 1247 1231 1215 1199 1183 1167 1151 1135 1119 1103 1087 1071[-- MARK -- Fr= i Oct 24 13:40:00 2014] 1055 1039 1023 1007 991 975 959 943 927 911 895 879 863 847 831 815 799 783= 767 751 735 719 703 687 671 655 639 623 607 591 575 559 543 527 511 495 47= 9 463 447 431 415 399 383 367 351 335 319 303 287 271 255 239 223 207 191 1= 75 159 143 127 111 95 79 63 47 31 15 Dump complete