Hello,
On Tue 05-09-17 11:51:44, Nikolay Borisov wrote:
> I've hit the following problems under memory-heavy workload conditions:
>
> First is a BUG_ON : J_ASSERT(journal_current_handle() == handle);
>
>
> [ 64.261793] kernel BUG at fs/jbd2/transaction.c:1644!
> [ 64.263894] invalid opcode: 0000 [#1] SMP
> [ 64.266187] Modules linked in:
> [ 64.267472] CPU: 1 PID: 542 Comm: kworker/u12:6 Not tainted 4.12.0-nbor
> #135
> [ 64.269941] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> Ubuntu-1.8.2-1ubuntu1 04/01/2014
> [ 64.272374] Workqueue: writeback wb_workfn (flush-254:0)
> [ 64.273862] task: ffff88001c37b880 task.stack: ffff880018ac8000
> [ 64.275580] RIP: 0010:jbd2_journal_stop+0x375/0x4d0
> [ 64.276704] RSP: 0000:ffff880018acb990 EFLAGS: 00010286
> [ 64.278708] RAX: ffff88001c37b880 RBX: ffff88001e83c000 RCX:
> ffff88001c4f8800
> [ 64.280499] RDX: ffff88001e83c000 RSI: 0000000000000b26 RDI:
> ffff88001e83c000
> [ 64.282262] RBP: ffff880018acba10 R08: ffff880019ec5888 R09:
> 0000000000000000
> [ 64.284111] R10: 0000000000000000 R11: ffffffff81283f8f R12:
> ffff880018a1a140
> [ 64.285553] R13: ffff88001c4f8800 R14: ffff88001c47d000 R15:
> ffff880018aa01f0
> [ 64.286337] FS: 0000000000000000(0000) GS:ffff88001fc40000(0000)
> knlGS:0000000000000000
> [ 64.287671] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 64.288568] CR2: 0000000000421ac0 CR3: 000000001ae83000 CR4:
> 00000000000006a0
> [ 64.289468] Call Trace:
> [ 64.289748] ? __ext4_journal_get_write_access+0x67/0xc0
> [ 64.290330] ? ext4_writepages+0xec6/0x1200
> [ 64.290786] __ext4_journal_stop+0x3c/0xa0
> [ 64.291233] ext4_writepages+0x8b2/0x1200
> [ 64.291682] ? writeback_sb_inodes+0x11f/0x5c0
> [ 64.292174] do_writepages+0x1c/0x80
> [ 64.292572] ? do_writepages+0x1c/0x80
> [ 64.292985] __writeback_single_inode+0x61/0x760
> [ 64.293575] writeback_sb_inodes+0x28d/0x5c0
> [ 64.294192] __writeback_inodes_wb+0x92/0xc0
> [ 64.294777] wb_writeback+0x3e9/0x560
> [ 64.295241] wb_workfn+0x9a/0x5d0
> [ 64.295977] ? wb_workfn+0x9a/0x5d0
> [ 64.296788] ? process_one_work+0x15c/0x620
> [ 64.297971] process_one_work+0x1d9/0x620
> [ 64.298969] worker_thread+0x4e/0x3b0
> [ 64.299684] kthread+0x113/0x150
> [ 64.300287] ? process_one_work+0x620/0x620
> [ 64.301145] ? kthread_create_on_node+0x40/0x40
> [ 64.301953] ret_from_fork+0x2a/0x40
> [ 64.302572] Code: dd ff 41 8b 45 60 85 c0 0f 84 29 fe ff ff 49 8d bd 00 01
> 00 00 31 c9 ba 01 00 00 00 be 03 00 00 00 e8 90 c1 dd ff e9 0c fe ff ff <0f>
> 0b 44 89 fe 4c 89 ef e8 ce 83 00 00 89 45 c4 e9 18 fe ff ff
> [ 64.305997] RIP: jbd2_journal_stop+0x375/0x4d0 RSP: ffff880018acb990
> [ 64.307037] ---[ end trace ec3f7cbd6e733faf ]---
>
> I consulted with Jan his opinion is that this is due to ->journal_info
> in workqueue threads gets modified while the work was running.
Sorry, this was a false alarm. Nikolai eventually hit also traces that were
not from workqueue code and eventually we've tracked down the problem to
his btrfs swapfile patches which were overwriting current->journal_info in
the swapout path...
Honza
--
Jan Kara <[email protected]>
SUSE Labs, CR
