SPLError: 3043:0:(list.h:126:list_remove()) ASSERTION(!list_is_empty(list)) failed

[gunnarbeutner]

In the (unlikely) event that zfs_rmnode() fails zfs_inode_destroy() is called for a znode that is already in the process of being torn down. This leads to a double-free error. The exact chain of events (as tested with kernel 2.6.38) is:

1. Last reference on an inode is being released via iput() -> iput_final()
2. iput_final() -> evict() -> zpl_evict_inode() -> zfs_inactive() -> zfs_zinactive() -> zfs_rmnode() -> zfs_inode_destroy()
3. iput_final -> destroy_inode() -> zpl_inode_destroy() -> zfs_inode_destroy()

At that point an assertion in list_remove() fails (in my case anyway, as this happened while cleaning up deleted inodes at mount time and there are no other znodes in zsb->z_all_znodes). Looks like those zfs_inode_destroy() calls are left-overs from the Solaris code (e.g. zfs_zinactive has a zfs_znode_free call in Solaris where the Linux version does not).

[   56.956792] removing znode: 13
[   56.956795] Pid: 1652, comm: mount.zfs Tainted: P            2.6.38-8-server #42-Ubuntu
[   56.956797] Call Trace:
[   56.956829]  [<ffffffffa03ac69f>] ? zfs_inode_destroy+0x5f/0x130 [zfs]
[   56.956855]  [<ffffffffa038b002>] ? zfs_rmnode+0x242/0x460 [zfs]
[   56.956880]  [<ffffffffa03afbc2>] ? zfs_zinactive+0xb2/0x160 [zfs]
[   56.956906]  [<ffffffffa03a8cee>] ? zfs_inactive+0x6e/0x360 [zfs]
[   56.957008]  [<ffffffffa03c55ef>] ? zpl_evict_inode+0x2f/0x40 [zfs]
[   56.957017]  [<ffffffff8117deb4>] ? evict+0x24/0xc0
[   56.957021]  [<ffffffff8117eae7>] ? iput_final+0x187/0x270
[   56.957023]  [<ffffffff8117ec0b>] ? iput+0x3b/0x50
[   56.957049]  [<ffffffffa038ad3a>] ? zfs_unlinked_drain+0xba/0x140 [zfs]
[   56.957052]  [<ffffffff815d779e>] ? _raw_spin_lock+0xe/0x20
[   56.957055]  [<ffffffff815d0064>] ? fam10h_check_enable_mmcfg+0x5/0xc3
[   56.957059]  [<ffffffff81038c79>] ? default_spin_lock_flags+0x9/0x10
[   56.957061]  [<ffffffff81038c79>] ? default_spin_lock_flags+0x9/0x10
[   56.957064]  [<ffffffff81087ae7>] ? finish_wait+0x67/0x80
[   56.957072]  [<ffffffffa023f9c1>] ? __taskq_create+0x341/0x6f0 [spl]
[   56.957087]  [<ffffffffa02f4650>] ? dmu_buf_rele+0x30/0x40 [zfs]
[   56.957090]  [<ffffffff81087940>] ? autoremove_wake_function+0x0/0x40
[   56.957115]  [<ffffffffa03a0148>] ? zfs_sb_setup+0xe8/0x120 [zfs]
[   56.957141]  [<ffffffffa03a17e0>] ? zfs_domount+0x1e0/0x220 [zfs]
[   56.957165]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957190]  [<ffffffffa03c52e3>] ? zpl_fill_super+0x13/0x80 [zfs]
[   56.957214]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957238]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957242]  [<ffffffff81167edf>] ? mount_nodev+0x5f/0xd0
[   56.957244]  [<ffffffff81167f66>] ? get_sb_nodev+0x16/0x40
[   56.957269]  [<ffffffffa03c52c9>] ? zpl_get_sb+0x29/0x30 [zfs]
[   56.957273]  [<ffffffff81278926>] ? security_sb_copy_data+0x16/0x20
[   56.957276]  [<ffffffff81167a59>] ? vfs_kern_mount+0x1d9/0x280
[   56.957278]  [<ffffffff81167b74>] ? do_kern_mount+0x54/0x110
[   56.957281]  [<ffffffff81184eda>] ? do_mount+0x1ea/0x230
[   56.957284]  [<ffffffff81185300>] ? sys_mount+0x90/0xe0
[   56.957287]  [<ffffffff8100bfc2>] ? system_call_fastpath+0x16/0x1b

[   56.957291] removing znode: 13
[   56.957294] Pid: 1652, comm: mount.zfs Tainted: P            2.6.38-8-server #42-Ubuntu
[   56.957295] Call Trace:
[   56.957320]  [<ffffffffa03ac69f>] ? zfs_inode_destroy+0x5f/0x130 [zfs]
[   56.957345]  [<ffffffffa03c5623>] ? zpl_inode_destroy+0x23/0x70 [zfs]
[   56.957348]  [<ffffffff8117dd4a>] ? __destroy_inode+0x2a/0xa0
[   56.957351]  [<ffffffff8117ddf6>] ? destroy_inode+0x36/0x60
[   56.957353]  [<ffffffff8117eb0a>] ? iput_final+0x1aa/0x270
[   56.957355]  [<ffffffff8117ec0b>] ? iput+0x3b/0x50
[   56.957380]  [<ffffffffa038ad3a>] ? zfs_unlinked_drain+0xba/0x140 [zfs]
[   56.957383]  [<ffffffff815d779e>] ? _raw_spin_lock+0xe/0x20
[   56.957386]  [<ffffffff815d0064>] ? fam10h_check_enable_mmcfg+0x5/0xc3
[   56.957389]  [<ffffffff81038c79>] ? default_spin_lock_flags+0x9/0x10
[   56.957391]  [<ffffffff81038c79>] ? default_spin_lock_flags+0x9/0x10
[   56.957394]  [<ffffffff81087ae7>] ? finish_wait+0x67/0x80
[   56.957400]  [<ffffffffa023f9c1>] ? __taskq_create+0x341/0x6f0 [spl]
[   56.957414]  [<ffffffffa02f4650>] ? dmu_buf_rele+0x30/0x40 [zfs]
[   56.957417]  [<ffffffff81087940>] ? autoremove_wake_function+0x0/0x40
[   56.957442]  [<ffffffffa03a0148>] ? zfs_sb_setup+0xe8/0x120 [zfs]
[   56.957468]  [<ffffffffa03a17e0>] ? zfs_domount+0x1e0/0x220 [zfs]
[   56.957492]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957517]  [<ffffffffa03c52e3>] ? zpl_fill_super+0x13/0x80 [zfs]
[   56.957541]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957565]  [<ffffffffa03c52d0>] ? zpl_fill_super+0x0/0x80 [zfs]
[   56.957568]  [<ffffffff81167edf>] ? mount_nodev+0x5f/0xd0
[   56.957571]  [<ffffffff81167f66>] ? get_sb_nodev+0x16/0x40
[   56.957595]  [<ffffffffa03c52c9>] ? zpl_get_sb+0x29/0x30 [zfs]
[   56.957599]  [<ffffffff81278926>] ? security_sb_copy_data+0x16/0x20
[   56.957602]  [<ffffffff81167a59>] ? vfs_kern_mount+0x1d9/0x280
[   56.957604]  [<ffffffff81167b74>] ? do_kern_mount+0x54/0x110
[   56.957607]  [<ffffffff81184eda>] ? do_mount+0x1ea/0x230
[   56.957609]  [<ffffffff81185300>] ? sys_mount+0x90/0xe0
[   56.957612]  [<ffffffff8100bfc2>] ? system_call_fastpath+0x16/0x1b    

[behlendorf]

Nice job. This looks right to me on first inspection but let me chew on it a little more before merging it.

[behlendorf]

Issue #252 looks like a likely duplicate.

[behlendorf]

Reopening... for now. The commit comment closed it even though it wasn't committed to master. I'll need to keep that in mind in the future.

[devsk]

Is this closed in the master now or not? Just curious because its been almost 4 months...:)

[behlendorf]

Yes, the fix was actually committed to master way back in June.

Author: Gunnar Beutner [email protected]
AuthorDate: Thu Jun 16 20:59:56 2011 +0200
Commit: Brian Behlendorf [email protected]
CommitDate: Mon Jun 20 10:30:17 2011 -0700