On 09/15/2015 09:43 AM, Holger Hoffstätte wrote:
On 09/15/15 14:58, Filipe Manana wrote:
On Tue, Sep 15, 2015 at 12:49 PM, Holger Hoffstätte
<holger.hoffstae...@googlemail.com> wrote:
Hello Filipe,
your mail comes just in time as I was typing a mail about this patch:
On 09/15/15 04:22, fdman...@kernel.org wrote:
Btrfs: remove unnecessary locking of cleaner_mutex to avoid deadlock
While it might seem to fix this particular problem, it seems there is either a
new one or a bad interaction with either both or one of these from Josef, which
came through around the same time:
Btrfs: use btrfs_get_fs_root in resolve_indirect_ref
Btrfs: keep dropped roots in cache until transaciton commit
With all three patches I have now seen something like this when deleting
snapshots that contain enough data to also kick off the cleaner:
[34851.791035] BTRFS info (device sdc1): leaf 865062912000 total ptrs 104 free
space 1151
(..lots of stuff that was supposed to be deleted..)
[34851.791210] BTRFS critical (device sdc1): unable to update root key 1328 132
5341
[34851.791795] ------------[ cut here ]------------
[34851.792343] kernel BUG at fs/btrfs/root-tree.c:160!
[34851.792889] invalid opcode: 0000 [#1] SMP
[34851.793442] Modules linked in: nfsd auth_rpcgss oid_registry lockd grace
sunrpc sch_fq_codel btrfs xor snd_hda_codec_hdmi snd_hda_codec_realtek
snd_hda_codec_generic x86_pkg_temp_thermal coretemp crc32_pclmul crc32c_intel
aesni_intel i915 raid6_pq aes_x86_64 glue_helper snd_hda_intel lrw gf128mul
snd_hda_controller ablk_helper cryptd snd_hda_codec intel_gtt snd_hda_core
i2c_algo_bit drm_kms_helper snd_pcm i2c_i801 usbhid drm snd_timer r8169 snd
soundcore i2c_core mii video
[34851.795328] CPU: 0 PID: 8807 Comm: sync Not tainted 4.1.7 #1
[34851.795942] Hardware name: System manufacturer System Product Name/P8Z68-V
LX, BIOS 4105 07/01/2013
[34851.796571] task: ffff88040cc91760 ti: ffff880352454000 task.ti:
ffff880352454000
[34851.797204] RIP: 0010:[<ffffffffa0435496>] [<ffffffffa0435496>]
btrfs_update_root+0x1e6/0x330 [btrfs]
[34851.797869] RSP: 0018:ffff880352457cf8 EFLAGS: 00010292
[34851.798521] RAX: 0000000000000045 RBX: ffff8802f0e59120 RCX: 0000000000000006
[34851.799188] RDX: 0000000000000007 RSI: 0000000000000246 RDI: ffff88041f20d520
[34851.799858] RBP: ffff880352457d58 R08: 0000000000000000 R09: 0000000000000410
[34851.800534] R10: 00000000ffffffff R11: 0000000000000410 R12: 0000000000000001
[34851.801208] R13: ffff8803fdf191df R14: ffff8803fdf19028 R15: ffff8800c96f4800
[34851.801879] FS: 00007fa61e9bd700(0000) GS:ffff88041f200000(0000)
knlGS:0000000000000000
[34851.802566] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[34851.803257] CR2: 00007fadc28e4000 CR3: 000000035247f000 CR4: 00000000000406f0
[34851.803962] Stack:
[34851.804661] 00003a6552457d88 00000000000000b0 ffff8803fdf191df
ffff88030c3a8f18
[34851.805389] 000000000000053a 0000000000000000 ffff880352457d58
ffff88030c3a8f18
[34851.806107] ffff88040cba6000 ffff88040cba6070 0000000000000002
ffff8803fdf19000
[34851.806825] Call Trace:
[34851.807536] [<ffffffffa04bd900>] commit_fs_roots.isra.7+0x11b/0x14d [btrfs]
[34851.808261] [<ffffffffa0444325>] btrfs_commit_transaction+0x6b5/0xc10
[btrfs]
[34851.808992] [<ffffffff8107aec0>] ? wake_atomic_t_function+0x60/0x60
[34851.809714] [<ffffffffa04125b9>] btrfs_sync_fs+0x59/0x110 [btrfs]
[34851.810438] [<ffffffff811a3d70>] ? do_fsync+0x70/0x70
[34851.811170] [<ffffffff811a3d90>] sync_fs_one_sb+0x20/0x30
[34851.811904] [<ffffffff81176a56>] iterate_supers+0xb6/0x120
[34851.812636] [<ffffffff811a3eb5>] sys_sync+0x55/0x90
[34851.813371] [<ffffffff81573b97>] system_call_fastpath+0x12/0x6a
[34851.814106] Code: 89 ff e8 de f9 ff ff 48 8b 45 b0 48 c7 c6 88 78 4c a0 49 8b bf
f0 01 00 00 0f b6 48 08 4c 8b 40 09 48 8b 10 31 c0 e8 5a e8 fd ff <0f> 0b 49 8b
87 f0 01 00 00 f0 0f ba a8 78 0d 00 00 02 72 1d 48
[34851.815868] RIP [<ffffffffa0435496>] btrfs_update_root+0x1e6/0x330 [btrfs]
[34851.816713] RSP <ffff880352457cf8>
[34851.817575] ---[ end trace cc3e428ae50170a3 ]---
While this happened when issuing sync after a delayed snapshot delete, I've
seen it also happen in the background. It's however not easily repeatable.
Until now I've not been able to pinpoint whether the problem is only in the
lock removal patch or an interaction with Josef's patches (or only there), but
so far I have never seen this with only those two.
Just thought you wanted to know - maybe you have an idea. Maybe there is a bad
interaction (larger race window?) with keeping the snapshots pinned longer and
the cleaner lock removal.
Hi Holger,
So at a first glance I don't think the patch that removes the locking
of cleaner mutex is the cause here. First it removed the locking in
the unmount and remount paths only (before attempts to delete unused
block groups), second the cleaner mutex is used only to serialize
snapshot removal and block group relocation/balance. Deleting unused
block groups is safe without the cleaner mutex and safe against a
transaction commit too, since before deleting any block group it will
start/join the transaction and block until the current transaction
ends its commit (if it's currently committing, such as in your trace).
OK, thanks for the explanation.
I haven't tried Josef's patches, but I'll leave them running here and
see if I can reproduce that.
Thanks.
When you get such error, are you doing an unmount or remount? If not,
no, just snapshot delete & manual sync.
I really don't see how the patch introduces any problems, either with
or without Josef's changes.
The interesting thing is that I ran with only your patch for a while
without problems, but saw this error after merging Josef's patches
and trying a quick snapshot delete *right away* (I remember that I also
issued a sync then, so..). I chalked it up to stale module info - despite
clean unmounting/rmmod/depmod/reload, which usually works fine for simple
patches - and since it worked fine for several days in casual use after
a clean reboot I let it slide. However it just happened again out of
the blue while deleting a snapshot. I don't know whether issuing the
sync was a deciding factor; I was more interested in seeing reclaimed
space immediately.
I've now reverted Josef's patches and have been running with only yours
for a good hour, creating/deleting multiple/nested/chained snapshots
with lots of blocks changed between them, with and without issuing sync
as hard as I can - nothing. Also verified that the cleaner still does
its thing (even deleting the very last data chunk) - no problems.
Let me know what you think and how/when I can help or test.
This is my bug, sorry about that, I'll send something out to fix it
right away. Thanks,
Josef
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
