Date: Fri, 15 May 2009 13:49:47 +0300 From: Andriy Gapon <avg@icyb.net.ua> To: freebsd-fs@freebsd.org Cc: Pawel Jakub Dawidek <pjd@freebsd.org> Subject: stable/7: shutdown stuck in zfs_umount (z_op_cnt > 0) Message-ID: <4A0D48CB.7030707@icyb.net.ua>
next in thread | raw e-mail | index | archive | help
Quite frequently when rebooting or shutting down after long uptime my amd64 stable/7 system gets stuck in shutdown after printing "All buffers synced". Below is some kgdb examination after breaking to ddb and inducing panic. I also see lots of threads with zfs-related names (also below). Any ideas/suggestions on cause/fix/workaround? Thanks! (kgdb) i thr ... 3 Thread 100002 (PID=1: init) sched_switch (td=0xffffff0001411a50, newtd=Variable "newtd" is not available. ) at /usr/src/sys/kern/sched_ule.c:1944 ... (kgdb) thr 3 [Switching to thread 3 (Thread 100002)]#0 sched_switch (td=0xffffff0001411a50, newtd=Variable "newtd" is not available. ) at /usr/src/sys/kern/sched_ule.c:1944 1944 cpuid = PCPU_GET(cpuid); (kgdb) bt #0 sched_switch (td=0xffffff0001411a50, newtd=Variable "newtd" is not available. ) at /usr/src/sys/kern/sched_ule.c:1944 #1 0xffffffff802b35d9 in mi_switch (flags=1, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:444 #2 0xffffffff802e0085 in sleepq_switch (wchan=Variable "wchan" is not available. ) at /usr/src/sys/kern/subr_sleepqueue.c:497 #3 0xffffffff802e0c0f in sleepq_timedwait (wchan=0xffffffff80660be8) at /usr/src/sys/kern/subr_sleepqueue.c:615 #4 0xffffffff802b3a27 in _sleep (ident=0xffffffff80660be8, lock=0x0, priority=0, wmesg=0xffffffff807e3ce3 "soldelay", timo=1) at /usr/src/sys/kern/kern_synch.c:226 #5 0xffffffff802b3b1c in pause (wmesg=Variable "wmesg" is not available. ) at /usr/src/sys/kern/kern_synch.c:334 #6 0xffffffff807cf8ce in zfs_umount (vfsp=0xffffff00076b7000, fflag=524288, td=0xffffff0001411a50) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c:738 #7 0xffffffff80326bbb in dounmount (mp=0xffffff00076b7000, flags=524288, td=0xffffff0001411a50) at /usr/src/sys/kern/vfs_mount.c:1298 #8 0xffffffff80329e91 in vfs_unmountall () at /usr/src/sys/kern/vfs_subr.c:3099 #9 0xffffffff802abcdd in boot (howto=0) at /usr/src/sys/kern/kern_shutdown.c:400 #10 0xffffffff802ac3f4 in reboot (td=Variable "td" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:172 #11 0xffffffff8044827d in syscall (frame=0xfffffffe8001ec80) at /usr/src/sys/amd64/amd64/trap.c:900 #12 0xffffffff8042d37b in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:330 #13 0x0000000000407e7c in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) fr 6 #6 0xffffffff807cf8ce in zfs_umount (vfsp=0xffffff00076b7000, fflag=524288, td=0xffffff0001411a50) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c:738 738 delay(1); (kgdb) list 733 * mutex in order to cv_signal 734 * - only occurs on forced unmount in the rare case when 735 * there are outstanding threads within the file system. 736 */ 737 while (zfsvfs->z_op_cnt) { 738 delay(1); 739 } 740 } 741 742 zfs_objset_close(zfsvfs); (kgdb) p zfsvfs->z_op_cnt $11 = 2 (kgdb) p *zfsvfs $12 = {z_vfs = 0xffffff00076b7000, z_parent = 0xffffff00076a7000, z_os = 0xffffff000768aa60, z_root = 3, z_unlinkedobj = 2, z_max_blksz = 131072, z_assign = 2, z_log = 0xffffff00076d1a00, z_acl_mode = 2, z_acl_inherit = 4, z_atime = 0, z_unmounted1 = 1, z_unmounted2 = 0, z_op_cnt = 2, z_um_lock = {lock_object = {lo_name = 0xffffffff807e3d2a "zfsvfs->z_um_lock", lo_type = 0xffffffff807e3d2a "zfsvfs->z_um_lock", lo_flags = 41484288, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, sx_lock = 1, sx_recurse = 0}, z_all_znodes = { list_size = 432, list_offset = 400, list_head = {list_next = 0xffffff00076a7098, list_prev = 0xffffff00076a7098}}, z_znodes_lock = {lock_object = {lo_name = 0xffffffff807e3d13 "zfsvfs->z_znodes_lock", lo_type = 0xffffffff807e3d13 "zfsvfs->z_znodes_lock", lo_flags = 41484288, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, sx_lock = 1, sx_recurse = 0}, z_ctldir = 0x0, z_show_ctldir = 0, z_issnap = 0, z_hold_mtx = {{lock_object = {lo_name = 0xffffffff807e3554 "zfsvfs->z_hold_mtx[i]", lo_type = 0xffffffff807e3554 "zfsvfs->z_hold_mtx[i]", lo_flags = 41484288, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, sx_lock = 1, sx_recurse = 0} <repeats 64 times>}} (kgdb) p *zfsvfs->z_vfs $13 = {mnt_lock = {lk_object = {lo_name = 0xffffffff804bb9b5 "vfslock", lo_type = 0xffffffff804bb9b5 "vfslock", lo_flags = 70844416, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, lk_interlock = 0xffffffff8065ff30, lk_flags = 1310720, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 80, lk_timo = 0, lk_lockholder = 0xffffff0001411a50, lk_newlock = 0x0}, mnt_mtx = {lock_object = {lo_name = 0xffffffff804bb9a4 "struct mount mtx", lo_type = 0xffffffff804bb9a4 "struct mount mtx", lo_flags = 16973824, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, mtx_lock = 4, mtx_recurse = 0}, mnt_gen = 1, mnt_list = {tqe_next = 0x0, tqe_prev = 0xffffff00076b7408}, mnt_op = 0xffffffff807e6460, mnt_vfc = 0xffffffff807e6400, mnt_vnodecovered = 0xffffff00076cd1f8, mnt_syncer = 0x0, mnt_ref = 1, mnt_nvnodelist = {tqh_first = 0x0, tqh_last = 0xffffff00076b70c0}, mnt_nvnodelistsize = 0, mnt_writeopcount = 1, mnt_kern_flag = 1627389961, mnt_flag = 268439552, mnt_noasync = 0, mnt_opt = 0xffffff00076cb060, mnt_optnew = 0x0, mnt_maxsymlinklen = 0, mnt_stat = {f_version = 537068824, f_type = 1, f_flags = 268439552, f_bsize = 131072, f_iosize = 131072, f_blocks = 460060, f_bfree = 458184, f_bavail = 458184, f_files = 487824, f_ffree = 458184, f_syncwrites = 0, f_asyncwrites = 0, f_syncreads = 0, f_asyncreads = 0, f_spare = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0}, f_namemax = 255, f_owner = 0, f_fsid = {val = {-673697102, -1110623743}}, f_charspare = '\0' <repeats 79 times>, f_fstypename = "zfs", '\0' <repeats 12 times>, f_mntfromname = "tank/var/db", '\0' <repeats 76 times>, f_mntonname = "/var/db", '\0' <repeats 80 times>}, mnt_cred = 0xffffff00076bd000, mnt_data = 0xffffff00076a7000, mnt_time = 0, mnt_iosize_max = 65536, mnt_export = 0x0, mnt_label = 0x0, mnt_hashseed = 192489048, mnt_markercnt = 0, mnt_holdcnt = 0, mnt_holdcntwaiters = 0, mnt_secondary_writes = 0, mnt_secondary_accwrites = 0, mnt_susp_owner = 0x0, mnt_gjprovider = 0x0, mnt_explock = {lk_object = {lo_name = 0xffffffff804bb9bd "explock", lo_type = 0xffffffff804bb9bd "explock", lo_flags = 70844416, lo_witness_data = {lod_list = {stqe_next = 0x0}, lod_witness = 0x0}}, lk_interlock = 0xffffffff8065ff60, lk_flags = 0, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 0, lk_prio = 80, lk_timo = 0, lk_lockholder = 0xffffffffffffffff, lk_newlock = 0x0}} 131 Thread 100341 (PID=4039: zvol:worker zvol/ta) sched_switch (td=0xffffff00a87a5000, newtd=Variable "newtd" is not available. 130 Thread 100257 (PID=4038: zil_clean) sched_switch (td=0xffffff0011b1a000, newtd=Variable "newtd" is not available. 125 Thread 100127 (PID=210: zil_clean) sched_switch (td=0xffffff00076946e0, newtd=Variable "newtd" is not available. 124 Thread 100126 (PID=209: zil_clean) sched_switch (td=0xffffff0004f84370, newtd=Variable "newtd" is not available. 123 Thread 100125 (PID=208: zil_clean) sched_switch (td=0xffffff0004f846e0, newtd=Variable "newtd" is not available. 122 Thread 100124 (PID=207: zil_clean) sched_switch (td=0xffffff0007694a50, newtd=Variable "newtd" is not available. 121 Thread 100123 (PID=206: zil_clean) sched_switch (td=0xffffff0004f84a50, newtd=Variable "newtd" is not available. 120 Thread 100122 (PID=205: zil_clean) sched_switch (td=0xffffff0007695000, newtd=Variable "newtd" is not available. 119 Thread 100060 (PID=204: zil_clean) sched_switch (td=0xffffff0004d2e000, newtd=Variable "newtd" is not available. 118 Thread 100121 (PID=203: zil_clean) sched_switch (td=0xffffff0007695370, newtd=Variable "newtd" is not available. 117 Thread 100059 (PID=202: zil_clean) sched_switch (td=0xffffff0004d2e370, newtd=Variable "newtd" is not available. 116 Thread 100057 (PID=201: zil_clean) sched_switch (td=0xffffff0004d2ea50, newtd=Variable "newtd" is not available. 115 Thread 100120 (PID=200: zil_clean) sched_switch (td=0xffffff0004d43370, newtd=Variable "newtd" is not available. 114 Thread 100070 (PID=199: zil_clean) sched_switch (td=0xffffff0004d41a50, newtd=Variable "newtd" is not available. 113 Thread 100058 (PID=198: zil_clean) sched_switch (td=0xffffff0004d2e6e0, newtd=Variable "newtd" is not available. 112 Thread 100055 (PID=197: zil_clean) sched_switch (td=0xffffff0004d2f370, newtd=Variable "newtd" is not available. 111 Thread 100076 (PID=196: zil_clean) sched_switch (td=0xffffff0004d40370, newtd=Variable "newtd" is not available. 110 Thread 100056 (PID=195: zil_clean) sched_switch (td=0xffffff0004d2f000, newtd=Variable "newtd" is not available. 109 Thread 100069 (PID=194: zil_clean) sched_switch (td=0xffffff0004d42000, newtd=Variable "newtd" is not available. 108 Thread 100053 (PID=193: zil_clean) sched_switch (td=0xffffff0004d2fa50, newtd=Variable "newtd" is not available. 107 Thread 100117 (PID=192: zil_clean) sched_switch (td=0xffffff0004d65000, newtd=Variable "newtd" is not available. 106 Thread 100054 (PID=191: zil_clean) sched_switch (td=0xffffff0004d2f6e0, newtd=Variable "newtd" is not available. 105 Thread 100078 (PID=190: zil_clean) sched_switch (td=0xffffff0004d686e0, newtd=Variable "newtd" is not available. 104 Thread 100111 (PID=189: zil_clean) sched_switch (td=0xffffff0004d676e0, newtd=Variable "newtd" is not available. 103 Thread 100077 (PID=188: zil_clean) sched_switch (td=0xffffff0004d40000, newtd=Variable "newtd" is not available. 102 Thread 100067 (PID=187: zil_clean) sched_switch (td=0xffffff0004d426e0, newtd=Variable "newtd" is not available. 101 Thread 100068 (PID=186: zil_clean) sched_switch (td=0xffffff0004d42370, newtd=Variable "newtd" is not available. 100 Thread 100112 (PID=185: zil_clean) sched_switch (td=0xffffff0004d67370, newtd=Variable "newtd" is not available. 99 Thread 100075 (PID=184: zil_clean) sched_switch (td=0xffffff0004d406e0, newtd=Variable "newtd" is not available. 98 Thread 100119 (PID=183: zil_clean) sched_switch (td=0xffffff0004d436e0, newtd=Variable "newtd" is not available. 97 Thread 100114 (PID=182: zil_clean) sched_switch (td=0xffffff0004d65a50, newtd=Variable "newtd" is not available. 96 Thread 100118 (PID=181: zil_clean) sched_switch (td=0xffffff0004d43a50, newtd=Variable "newtd" is not available. 95 Thread 100115 (PID=180: zil_clean) sched_switch (td=0xffffff0004d656e0, newtd=Variable "newtd" is not available. 94 Thread 100113 (PID=179: zil_clean) sched_switch (td=0xffffff0004d67000, newtd=Variable "newtd" is not available. 93 Thread 100073 (PID=178: zil_clean) sched_switch (td=0xffffff0004d41000, newtd=Variable "newtd" is not available. 92 Thread 100074 (PID=177: zil_clean) sched_switch (td=0xffffff0004d40a50, newtd=Variable "newtd" is not available. 91 Thread 100071 (PID=176: zil_clean) sched_switch (td=0xffffff0004d416e0, newtd=Variable "newtd" is not available. 90 Thread 100072 (PID=175: zil_clean) sched_switch (td=0xffffff0004d41370, newtd=Variable "newtd" is not available. 89 Thread 100116 (PID=174: zil_clean) sched_switch (td=0xffffff0004d65370, newtd=Variable "newtd" is not available. 88 Thread 100066 (PID=173: zil_clean) sched_switch (td=0xffffff0004d42a50, newtd=Variable "newtd" is not available. 87 Thread 100063 (PID=172: zil_clean) sched_switch (td=0xffffff0004d2b370, newtd=Variable "newtd" is not available. 86 Thread 100064 (PID=171: zil_clean) sched_switch (td=0xffffff0004d2b000, newtd=Variable "newtd" is not available. 85 Thread 100065 (PID=170: zil_clean) sched_switch (td=0xffffff0004d43000, newtd=Variable "newtd" is not available. 84 Thread 100109 (PID=109: zil_clean) sched_switch (td=0xffffff0004d67a50, newtd=Variable "newtd" is not available. 80 Thread 100105 (PID=105: vdev:worker ad16s1d) sched_switch (td=0xffffff0004d68000, newtd=Variable "newtd" is not available. 79 Thread 100104 (PID=104: vdev:worker ad10s2d) sched_switch (td=0xffffff0004f87000, newtd=Variable "newtd" is not available. 78 Thread 100103 (PID=103: vdev:worker ad6s2d) sched_switch (td=0xffffff0004d68370, newtd=Variable "newtd" is not available. 77 Thread 100102 (PID=102: spa_zio_intr_5) sched_switch (td=0xffffff0004f87370, newtd=Variable "newtd" is not available. 76 Thread 100101 (PID=101: spa_zio_intr_5) sched_switch (td=0xffffff0004f876e0, newtd=Variable "newtd" is not available. 75 Thread 100100 (PID=100: spa_zio_issue_5) sched_switch (td=0xffffff0004f87a50, newtd=Variable "newtd" is not available. 74 Thread 100099 (PID=99: spa_zio_issue_5) sched_switch (td=0xffffff0004f88000, newtd=Variable "newtd" is not available. 73 Thread 100098 (PID=98: spa_zio_intr_4) sched_switch (td=0xffffff0004f88370, newtd=Variable "newtd" is not available. 72 Thread 100097 (PID=97: spa_zio_intr_4) sched_switch (td=0xffffff0004d68a50, newtd=Variable "newtd" is not available. 71 Thread 100096 (PID=96: spa_zio_issue_4) sched_switch (td=0xffffff0004f67000, newtd=Variable "newtd" is not available. 70 Thread 100095 (PID=95: spa_zio_issue_4) sched_switch (td=0xffffff0004f67370, newtd=Variable "newtd" is not available. 69 Thread 100094 (PID=94: spa_zio_intr_3) sched_switch (td=0xffffff0004f676e0, newtd=Variable "newtd" is not available. 68 Thread 100093 (PID=93: spa_zio_intr_3) sched_switch (td=0xffffff0004f67a50, newtd=Variable "newtd" is not available. 67 Thread 100092 (PID=92: spa_zio_issue_3) sched_switch (td=0xffffff0004f69000, newtd=Variable "newtd" is not available. 66 Thread 100091 (PID=91: spa_zio_issue_3) sched_switch (td=0xffffff0004f69370, newtd=Variable "newtd" is not available. 65 Thread 100090 (PID=90: spa_zio_intr_2) sched_switch (td=0xffffff0004f696e0, newtd=Variable "newtd" is not available. 64 Thread 100089 (PID=89: spa_zio_intr_2) sched_switch (td=0xffffff0004f69a50, newtd=Variable "newtd" is not available. 63 Thread 100088 (PID=88: spa_zio_issue_2) sched_switch (td=0xffffff0004f6a000, newtd=Variable "newtd" is not available. 62 Thread 100087 (PID=87: spa_zio_issue_2) sched_switch (td=0xffffff0004f6a370, newtd=Variable "newtd" is not available. 61 Thread 100086 (PID=86: spa_zio_intr_1) sched_switch (td=0xffffff0004f6a6e0, newtd=Variable "newtd" is not available. 60 Thread 100085 (PID=85: spa_zio_intr_1) sched_switch (td=0xffffff0004f6aa50, newtd=Variable "newtd" is not available. 59 Thread 100084 (PID=84: spa_zio_issue_1) sched_switch (td=0xffffff0004f6b000, newtd=Variable "newtd" is not available. 58 Thread 100083 (PID=83: spa_zio_issue_1) sched_switch (td=0xffffff0004f6b370, newtd=Variable "newtd" is not available. 57 Thread 100082 (PID=82: spa_zio_intr_0) sched_switch (td=0xffffff0003310370, newtd=Variable "newtd" is not available. 56 Thread 100081 (PID=81: spa_zio_intr_0) sched_switch (td=0xffffff00033106e0, newtd=Variable "newtd" is not available. 55 Thread 100080 (PID=80: spa_zio_issue_0) sched_switch (td=0xffffff0003310a50, newtd=Variable "newtd" is not available. 54 Thread 100079 (PID=79: spa_zio_issue_0) sched_switch (td=0xffffff0004cd4000, newtd=Variable "newtd" is not available. -- Andriy Gapon
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?4A0D48CB.7030707>