Hello Daniel,

I have another reference count issue, and have a patch for it.  Although
they have differenct panic stack, I think they have same root cause.
https://www.redhat.com/archives/linux-cachefs/2018-February/msg00000.html

I did try the patch of
https://www.redhat.com/archives/linux-cachefs/2017-June/msg00002.html,
but it looks like doesn't work on my environment.

Thanks,
-Lei


在 06/04/2018 7:16 PM, Daniel Axtens 写道:
> Hi,
>
> We have a user reporting BUG splats and FSCache assertion failures with
> FSCache and NFS. The full stack traces are below.
>
> We are consistently seeing the following FSCache assertion:
>
> [81738.886634] FS-Cache: 
> [81738.888281] FS-Cache: Assertion failed
> [81738.889461] FS-Cache: 6 == 5 is false
> [81738.890625] ------------[ cut here ]------------
> [81738.891706] kernel BUG at 
> /build/linux-hVVhWi/linux-4.4.0/fs/fscache/operation.c:494!
>
> which references the following:
>
>       ASSERTIFCMP(op->state != FSCACHE_OP_ST_INITIALISED &&
>                   op->state != FSCACHE_OP_ST_COMPLETE,
>                   op->state, ==, FSCACHE_OP_ST_CANCELLED);
>
> So the operation has become DEAD when it was expected to be CANCELLED.
>
> fscache_put_operation() is the only thing I can find that will mark an
> operation as DEAD, and then only when atomic_dec_and_test(&op->usage)
> goes to 0 twice.
>
> This looks supsiciously like this bug reported in June 2017:
> https://www.redhat.com/archives/linux-cachefs/2017-June/msg00002.html
> "Re: [Linux-cachefs] Problem: Race in fscache operation enqueuing for
> reading and copying multiple pages from cachefiles to netfs causes
> kernel oops or at worst memory scribbling."
>
> Indeed, immediatlely prior to the assertion failure, we sometimes see a
> WARN in the workqueue code from trying to insert a work that is not
> pending, and the stack trace includes cachefiles_read_waiter calling
> fscache_enqueue_operation.
>
> Was there ever any progress on that bug? Or is there anything else I
> should be looking at?
>
> Thanks in advance!
>
> Regards,
> Daniel
>
>
> Full stack traces:
>
> [81738.885081] ------------[ cut here ]------------
> [81738.885165] WARNING: CPU: 67 PID: 70869 at 
> /build/linux-hVVhWi/linux-4.4.0/kernel/workqueue.c:623 insert_work+0xac/0xc0()
> [81738.885175] Modules linked in: binfmt_misc veth ipt_MASQUERADE 
> nf_nat_masquerade_ipv4 nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo 
> iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype 
> xt_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay 
> xt_multiport iptable_filter ip_tables x_tables nfsv3 nfs_acl rpcsec_gss_krb5 
> auth_rpcgss nfsv4 nfs lockd grace nv_peer_mem(OE) cachefiles fscache msr 
> rdma_ucm(OE) ib_ucm(OE) rdma_cm(OE) iw_cm(OE) configfs ib_ipoib(OE) ib_cm(OE) 
> ib_uverbs(OE) ib_umad(OE) mlx5_ib(OE) mlx4_ib(OE) ib_core(OE) mlx4_en(OE) 
> mlx4_core(OE) bonding ipmi_ssif intel_rapl x86_pkg_temp_thermal 
> intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul 
> crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul 
> glue_helper ablk_helper cryptd joydev input_leds mxm_wmi sb_edac edac_core 
> lpc_ich mei_me mei nvidia_uvm(POE) shpchp 8250_fintek ipmi_si wmi 
> acpi_power_meter mac_hid sunrpc ipmi_devintf ipmi_msghandler knem(OE) autofs4
>   nvidia_drm(POE) nvidia_modeset(POE) ast i2c_algo_bit nvidia(POE) ttm ixgbe 
> drm_kms_helper syscopyarea ses dca sysfillrect mlx5_core(OE) enclosure 
> sysimgblt fb_sys_fops vxlan hid_generic ip6_udp_tunnel usbhid udp_tunnel 
> mlx_compat(OE) hid ahci ptp megaraid_sas drm libahci pps_core mdio fjes
> [81738.885422] CPU: 67 PID: 70869 Comm: xxxxxx Tainted: P           OE   
> 4.4.0-92-generic #115-Ubuntu
> [81738.885428] Hardware name: xxxxx
> [81738.885431]  0000000000000086 6bb3b89857e8c7df ffff887f7f2c3b60 
> ffffffff813f9c83
> [81738.885436]  0000000000000000 ffffffff81cbb498 ffff887f7f2c3b98 
> ffffffff81081312
> [81738.885439]  ffff887f22fdd200 ffff887f626bc540 ffff887f656e8000 
> 0000000000000005
> [81738.885446] Call Trace:
> [81738.885452]  <IRQ>  [<ffffffff813f9c83>] dump_stack+0x63/0x90
> [81738.885512]  [<ffffffff81081312>] warn_slowpath_common+0x82/0xc0
> [81738.885535]  [<ffffffff8108145a>] warn_slowpath_null+0x1a/0x20
> [81738.885558]  [<ffffffff8109869c>] insert_work+0xac/0xc0
> [81738.885571]  [<ffffffff810987e9>] __queue_work+0x139/0x3b0
> [81738.885579]  [<ffffffff81098c77>] queue_work_on+0x27/0x40
> [81738.885625]  [<ffffffffc054b064>] fscache_enqueue_operation+0x94/0x150 
> [fscache]
> [81738.885640]  [<ffffffffc03b68ec>] cachefiles_read_waiter+0xbc/0x100 
> [cachefiles]
> [81738.885666]  [<ffffffff810c3d12>] __wake_up_common+0x52/0x90
> [81738.885694]  [<ffffffff810c3d89>] __wake_up+0x39/0x50
> [81738.885715]  [<ffffffff810c4040>] __wake_up_bit+0x50/0x70
> [81738.885726]  [<ffffffff8118f739>] unlock_page+0x69/0x70
> [81738.885746]  [<ffffffff812e8073>] mpage_end_io+0x33/0xc0
> [81738.885770]  [<ffffffff813c28af>] bio_endio+0x3f/0x60
> [81738.885782]  [<ffffffff813ca257>] blk_update_request+0x87/0x310
> [81738.885801]  [<ffffffff815c40b3>] scsi_end_request+0x33/0x1d0
> [81738.885815]  [<ffffffff815c77e6>] scsi_io_completion+0x1b6/0x690
> [81738.885841]  [<ffffffff815be40f>] scsi_finish_command+0xcf/0x120
> [81738.885858]  [<ffffffff815c6f74>] scsi_softirq_done+0x124/0x150
> [81738.885897]  [<ffffffff813d2147>] blk_done_softirq+0x87/0xb0
> [81738.885916]  [<ffffffff81085df1>] __do_softirq+0x101/0x290
> [81738.885933]  [<ffffffff810860f3>] irq_exit+0xa3/0xb0
> [81738.885950]  [<ffffffff818449e4>] do_IRQ+0x54/0xd0
> [81738.885975]  [<ffffffff81842ac2>] common_interrupt+0x82/0x82
> [81738.885982]  <EOI>  [<ffffffff811fe87c>] ? try_charge+0x3c/0x660
> [81738.886035]  [<ffffffff810c4125>] ? wake_up_bit+0x25/0x30
> [81738.886057]  [<ffffffff81202ceb>] mem_cgroup_try_charge+0x6b/0x1e0
> [81738.886074]  [<ffffffff8118fc40>] __add_to_page_cache_locked+0x60/0x1f0
> [81738.886194]  [<ffffffffc141cd83>] ? nfs_pageio_add_request+0xa3/0x1b0 [nfs]
> [81738.886284]  [<ffffffffc141d760>] ? nfs_read_completion+0x210/0x210 [nfs]
> [81738.886299]  [<ffffffff8118fe27>] add_to_page_cache_lru+0x37/0x90
> [81738.886316]  [<ffffffff8119df5b>] read_cache_pages+0x7b/0x120
> [81738.886401]  [<ffffffffc141de79>] nfs_readpages+0x129/0x200 [nfs]
> [81738.886429]  [<ffffffff8119e1e6>] __do_page_cache_readahead+0x196/0x230
> [81738.886454]  [<ffffffff8119e3bd>] ondemand_readahead+0x13d/0x250
> [81738.886469]  [<ffffffff8119e53b>] page_cache_async_readahead+0x6b/0x70
> [81738.886478]  [<ffffffff81190dd8>] generic_file_read_iter+0x458/0x670
> [81738.886529]  [<ffffffffc1415292>] ? __nfs_revalidate_mapping+0xc2/0x280 
> [nfs]
> [81738.886564]  [<ffffffffc1410c72>] nfs_file_read+0x52/0xa0 [nfs]
> [81738.886577]  [<ffffffff8120eec4>] new_sync_read+0x94/0xd0
> [81738.886584]  [<ffffffff8120ef26>] __vfs_read+0x26/0x40
> [81738.886589]  [<ffffffff8120f4e6>] vfs_read+0x86/0x130
> [81738.886595]  [<ffffffff81210235>] SyS_read+0x55/0xc0
> [81738.886606]  [<ffffffff81841ff2>] entry_SYSCALL_64_fastpath+0x16/0x71
> [81738.886612] ---[ end trace dbbc7c60b0e5f2a3 ]---
>
> [81738.886634] FS-Cache: 
> [81738.888281] FS-Cache: Assertion failed
> [81738.889461] FS-Cache: 6 == 5 is false
> [81738.890625] ------------[ cut here ]------------
> [81738.891706] kernel BUG at 
> /build/linux-hVVhWi/linux-4.4.0/fs/fscache/operation.c:494!
> [81738.892821] invalid opcode: 0000 [#1] SMP 
> [81738.893930] Modules linked in: binfmt_misc veth ipt_MASQUERADE 
> nf_nat_masquerade_ipv4 nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo 
> iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype 
> xt_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay 
> xt_multiport iptable_filter ip_tables x_tables nfsv3 nfs_acl rpcsec_gss_krb5 
> auth_rpcgss nfsv4 nfs lockd grace nv_peer_mem(OE) cachefiles fscache msr 
> rdma_ucm(OE) ib_ucm(OE) rdma_cm(OE) iw_cm(OE) configfs ib_ipoib(OE) ib_cm(OE) 
> ib_uverbs(OE) ib_umad(OE) mlx5_ib(OE) mlx4_ib(OE) ib_core(OE) mlx4_en(OE) 
> mlx4_core(OE) bonding ipmi_ssif intel_rapl x86_pkg_temp_thermal 
> intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul 
> crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul 
> glue_helper ablk_helper cryptd joydev input_leds mxm_wmi sb_edac edac_core 
> lpc_ich mei_me mei nvidia_uvm(POE) shpchp 8250_fintek ipmi_si wmi 
> acpi_power_meter mac_hid sunrpc ipmi_devintf ipmi_msghandler knem(OE) autofs4
>   nvidia_drm(POE) nvidia_modeset(POE) ast i2c_algo_bit nvidia(POE) ttm ixgbe 
> drm_kms_helper syscopyarea ses dca sysfillrect mlx5_core(OE) enclosure 
> sysimgblt fb_sys_fops vxlan hid_generic ip6_udp_tunnel usbhid udp_tunnel 
> mlx_compat(OE) hid ahci ptp megaraid_sas drm libahci pps_core mdio fjes
> [81738.908228] CPU: 23 PID: 36247 Comm: kworker/u162:0 Tainted: P        W  
> OE   4.4.0-92-generic #115-Ubuntu
> [81738.910190] Hardware name: xxxxx
> [81738.912691] Workqueue: fscache_operation fscache_op_work_func [fscache]
> [81738.914032] task: ffff8846c0f23800 ti: ffff886cf2f0c000 task.ti: 
> ffff886cf2f0c000
> [81738.914880] RIP: 0010:[<ffffffffc054af96>]  [<ffffffffc054af96>] 
> fscache_put_operation+0x1d6/0x210 [fscache]
> [81738.915788] RSP: 0000:ffff886cf2f0fde0  EFLAGS: 00010282
> [81738.916700] RAX: 0000000000000019 RBX: ffff887f626bc540 RCX: 
> 0000000000000006
> [81738.917635] RDX: 0000000000000000 RSI: 0000000000000246 RDI: 
> ffff887f7eccdd50
> [81738.918571] RBP: ffff886cf2f0fdf8 R08: 0000000000000000 R09: 
> 000000000000079e
> [81738.919539] R10: 0000000000000002 R11: 000000000000079e R12: 
> ffff887f656e8000
> [81738.920454] R13: ffff887f22fdd200 R14: 0000000000001440 R15: 
> ffff887f626bc540
> [81738.921275] FS:  0000000000000000(0000) GS:ffff887f7ecc0000(0000) 
> knlGS:0000000000000000
> [81738.922089] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [81738.922922] CR2: 00007ff2cce7e880 CR3: 0000000002e0a000 CR4: 
> 00000000003406e0
> [81738.923765] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 
> 0000000000000000
> [81738.924650] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 
> 0000000000000400
> [81738.925517] Stack:
> [81738.926320]  ffff887f626bc540 ffff887f656e8000 ffff887f22fdd200 
> ffff886cf2f0fe10
> [81738.927155]  ffffffffc054b1ca ffff887f608c3ec0 ffff886cf2f0fe50 
> ffffffff8109a625
> [81738.928059]  0000000000000000 ffff887f608c3ef0 ffff887f656e8000 
> 0000000000000088
> [81738.928961] Call Trace:
> [81738.929825]  [<ffffffffc054b1ca>] fscache_op_work_func+0x2a/0x50 [fscache]
> [81738.930680]  [<ffffffff8109a625>] process_one_work+0x165/0x480
> [81738.931547]  [<ffffffff8109a98b>] worker_thread+0x4b/0x4c0
> [81738.932427]  [<ffffffff8109a940>] ? process_one_work+0x480/0x480
> [81738.933506]  [<ffffffff810a0cc5>] kthread+0xe5/0x100
> [81738.934498]  [<ffffffff810a0be0>] ? kthread_create_on_node+0x1e0/0x1e0
> [81738.935551]  [<ffffffff8184238f>] ret_from_fork+0x3f/0x70
> [81738.936519]  [<ffffffff810a0be0>] ? kthread_create_on_node+0x1e0/0x1e0
> [81738.937372] Code: c7 c7 fb 02 55 c0 e8 e1 2b c4 c0 48 c7 c7 09 03 55 c0 e8 
> d5 2b c4 c0 8b 73 40 ba 05 00 00 00 48 c7 c7 b0 ee 54 c0 e8 c1 2b c4 c0 <0f> 
> 0b 48 c7 c7 fb 02 55 c0 e8 b3 2b c4 c0 48 c7 c7 09 03 55 c0 
> [81738.939258] RIP  [<ffffffffc054af96>] fscache_put_operation+0x1d6/0x210 
> [fscache]
> [81738.940185]  RSP <ffff886cf2f0fde0>
> [81738.944238] ---[ end trace dbbc7c60b0e5f2a4 ]---
>
> (this usually follows, it just looks like a cascading failure from
> messing with the work queue data structures)
>
> [81738.946803] BUG: unable to handle kernel paging request at ffffffffffffffd8
> [81738.947768] IP: [<ffffffff810a1370>] kthread_data+0x10/0x20
> [81738.948624] PGD 2e0d067 PUD 2e0f067 PMD 0 
> [81738.949445] Oops: 0000 [#2] SMP 
> [81738.950237] Modules linked in: binfmt_misc veth ipt_MASQUERADE 
> nf_nat_masquerade_ipv4 nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo 
> iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype 
> xt_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay 
> xt_multiport iptable_filter ip_tables x_tables nfsv3 nfs_acl rpcsec_gss_krb5 
> auth_rpcgss nfsv4 nfs lockd grace nv_peer_mem(OE) cachefiles fscache msr 
> rdma_ucm(OE) ib_ucm(OE) rdma_cm(OE) iw_cm(OE) configfs ib_ipoib(OE) ib_cm(OE) 
> ib_uverbs(OE) ib_umad(OE) mlx5_ib(OE) mlx4_ib(OE) ib_core(OE) mlx4_en(OE) 
> mlx4_core(OE) bonding ipmi_ssif intel_rapl x86_pkg_temp_thermal 
> intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul 
> crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul 
> glue_helper ablk_helper cryptd joydev input_leds mxm_wmi sb_edac edac_core 
> lpc_ich mei_me mei nvidia_uvm(POE) shpchp 8250_fintek ipmi_si wmi 
> acpi_power_meter mac_hid sunrpc ipmi_devintf ipmi_msghandler knem(OE) autofs4
>   nvidia_drm(POE) nvidia_modeset(POE) ast i2c_algo_bit nvidia(POE) ttm ixgbe 
> drm_kms_helper syscopyarea ses dca sysfillrect mlx5_core(OE) enclosure 
> sysimgblt fb_sys_fops vxlan hid_generic ip6_udp_tunnel usbhid udp_tunnel 
> mlx_compat(OE) hid ahci ptp megaraid_sas drm libahci pps_core mdio fjes
> [81738.959336] CPU: 23 PID: 36247 Comm: kworker/u162:0 Tainted: P      D W  
> OE   4.4.0-92-generic #115-Ubuntu
> [81738.960164] Hardware name: xxxxx
> [81738.960993] task: ffff8846c0f23800 ti: ffff886cf2f0c000 task.ti: 
> ffff886cf2f0c000
> [81738.961808] RIP: 0010:[<ffffffff810a1370>]  [<ffffffff810a1370>] 
> kthread_data+0x10/0x20
> [81738.962644] RSP: 0000:ffff886cf2f0fab8  EFLAGS: 00010002
> [81738.963475] RAX: 0000000000000000 RBX: 0000000000000017 RCX: 
> ffffffff82109e80
> [81738.964312] RDX: 0000000000000017 RSI: 0000000000000017 RDI: 
> ffff8846c0f23800
> [81738.965142] RBP: ffff886cf2f0fab8 R08: 00000000ffffffff R09: 
> 0000000000000000
> [81738.965996] R10: ffff8846c0f23860 R11: 0000000000009800 R12: 
> 0000000000000000
> [81738.966825] R13: 0000000000016dc0 R14: ffff8846c0f23800 R15: 
> ffff887f7ecd6dc0
> [81738.967676] FS:  0000000000000000(0000) GS:ffff887f7ecc0000(0000) 
> knlGS:0000000000000000
> [81738.968534] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [81738.969369] CR2: 0000000000000028 CR3: 0000000002e0a000 CR4: 
> 00000000003406e0
> [81738.970202] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 
> 0000000000000000
> [81738.971053] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 
> 0000000000000400
> [81738.971893] Stack:
> [81738.972728]  ffff886cf2f0fad0 ffffffff8109b9c1 ffff887f7ecd6dc0 
> ffff886cf2f0fb20
> [81738.973583]  ffffffff8183dab0 ffff887f5f808aa0 ffff886c00000017 
> ffff8846c0f23800
> [81738.974448]  ffff886cf2f10000 ffff8846c0f23ed0 ffff886cf2f0f6d0 
> 0000000000000000
> [81738.975289] Call Trace:
> [81738.976164]  [<ffffffff8109b9c1>] wq_worker_sleeping+0x11/0x90
> [81738.977019]  [<ffffffff8183dab0>] __schedule+0x650/0xa30
> [81738.977844]  [<ffffffff8183dec5>] schedule+0x35/0x80
> [81738.978668]  [<ffffffff81084465>] do_exit+0x775/0xb00
> [81738.979484]  [<ffffffff81031c41>] oops_end+0xa1/0xd0
> [81738.980294]  [<ffffffff810320fb>] die+0x4b/0x70
> [81738.981091]  [<ffffffff8102f121>] do_trap+0xb1/0x140
> [81738.981882]  [<ffffffff8102f4a9>] do_error_trap+0x89/0x110
> [81738.982656]  [<ffffffffc054af96>] ? fscache_put_operation+0x1d6/0x210 
> [fscache]
> [81738.983428]  [<ffffffff810ca782>] ? up+0x32/0x50
> [81738.984189]  [<ffffffff810d8656>] ? console_unlock+0x216/0x550
> [81738.984934]  [<ffffffff8102fa10>] do_invalid_op+0x20/0x30
> [81738.985677]  [<ffffffff81843b0e>] invalid_op+0x1e/0x30
> [81738.986416]  [<ffffffffc054af96>] ? fscache_put_operation+0x1d6/0x210 
> [fscache]
> [81738.987155]  [<ffffffffc054b1ca>] fscache_op_work_func+0x2a/0x50 [fscache]
> [81738.987890]  [<ffffffff8109a625>] process_one_work+0x165/0x480
> [81738.988631]  [<ffffffff8109a98b>] worker_thread+0x4b/0x4c0
> [81738.989349]  [<ffffffff8109a940>] ? process_one_work+0x480/0x480
> [81738.990049]  [<ffffffff810a0cc5>] kthread+0xe5/0x100
> [81738.990724]  [<ffffffff810a0be0>] ? kthread_create_on_node+0x1e0/0x1e0
> [81738.991390]  [<ffffffff8184238f>] ret_from_fork+0x3f/0x70
> [81738.992042]  [<ffffffff810a0be0>] ? kthread_create_on_node+0x1e0/0x1e0
> [81738.992671] Code: ff ff ff be 49 02 00 00 48 c7 c7 98 b9 cb 81 e8 e7 00 fe 
> ff e9 a6 fe ff ff 66 90 0f 1f 44 00 00 48 8b 87 18 05 00 00 55 48 89 e5 <48> 
> 8b 40 d8 5d c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 
> [81738.994013] RIP  [<ffffffff810a1370>] kthread_data+0x10/0x20
> [81738.994627]  RSP <ffff886cf2f0fab8>
> [81738.995216] CR2: ffffffffffffffd8
> [81738.995785] ---[ end trace dbbc7c60b0e5f2a5 ]---
> [81738.997887] Fixing recursive fault but reboot is needed!
>
> (hardlockups seem to follow)
>
> --
> Linux-cachefs mailing list
> Linux-cachefs@redhat.com
> https://www.redhat.com/mailman/listinfo/linux-cachefs



--
Linux-cachefs mailing list
Linux-cachefs@redhat.com
https://www.redhat.com/mailman/listinfo/linux-cachefs

Reply via email to