Description of problem: After rebooting from 4.10.14-100.fc24 to 4.10.16-100.fc24 and starting to use an always-mounted remote nfs export my system (the nfs client) quickly has the nfs connection hang. It never does nfs recovery and my hard mount hangs all programs using it. Rebooting the nfs server doesn't help. Rebooting the client (the computer in question) fixes the problem, but on next reboot it rapidly hangs again once nfs gets used. I'm tainted, sorry, but my new video card isn't supported by nouveau yet. I'll try to reproduce on another box without taint. My nfs setup is pretty standard except a) I'm using NFSv4 over TCP and I specify the nfs ports strictly/manually for firewall purposes. I'm not positive it's nfs triggering this, but it sure seems like it. Certainly the symptom shows up in nfs (many of my apps hang). May 24 02:24:34 pog kernel: [ 4203.119574] page:ffffedb5c4aad000 count:0 mapcount:-127 mapping: (null) index:0x0 May 24 02:24:34 pog kernel: [ 4203.119581] flags: 0x17ffffc0000000() May 24 02:24:34 pog kernel: [ 4203.119586] raw: 0017ffffc0000000 0000000000000000 0000000000000000 00000000ffffff80 May 24 02:24:34 pog kernel: [ 4203.119590] raw: ffffedb5c7b9ca20 ffff9131effd1ef8 0000000000000003 0000000000000000 May 24 02:24:34 pog kernel: [ 4203.119592] page dumped because: VM_BUG_ON_PAGE(page_ref_count(page) == 0) May 24 02:24:34 pog kernel: [ 4203.119646] ------------[ cut here ]------------ May 24 02:24:34 pog kernel: [ 4203.119649] kernel BUG at ./include/linux/mm.h:432! May 24 02:24:34 pog kernel: [ 4203.119652] invalid opcode: 0000 [#1] SMP May 24 02:24:34 pog kernel: [ 4203.119654] Modules linked in: xfrm4_tunnel tunnel4 rpcsec_gss_krb5 ipcomp xfrm_ipcomp nfsv4 esp4 ah4 dns_resolver af_key nfs fscache 8021q garp mrp stp llc cfg80211 rfkill nf_nat_pptp nf_nat_proto_gre nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netbios_ns nf_conntrack_broadcast xt_mac nf_log_ipv4 nf_log_common xt_LOG xt_limit xt_conntrack xt_nat ipt_MASQUERADE nf_nat_masquerade_ipv4 xt_REDIRECT nf_nat_redirect asc7621 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c xt_TCPMSS ip6t_REJECT nf_reject_ipv6 iptable_mangle ip6table_filter iptable_raw ip6_tables iptable_security nvidia_drm(POE) nvidia_modeset(POE) gpio_ich iTCO_wdt iTCO_vendor_support ppdev nvidia(POE) joydev coretemp snd_hda_codec_hdmi drm_kms_helper drm kvm_intel snd_hda_codec_idt snd_hda_codec_generic May 24 02:24:34 pog kernel: [ 4203.119709] kvm snd_hda_intel irqbypass snd_hda_codec snd_hda_core snd_hwdep snd_seq snd_seq_device snd_pcm i2c_i801 snd_timer snd soundcore lpc_ich i82975x_edac edac_core shpchp parport_pc parport acpi_cpufreq tpm_tis tpm_tis_core tpm nfsd auth_rpcgss nfs_acl lockd grace sunrpc raid1 raid0 serio_raw ata_generic aic7xxx pata_acpi firewire_ohci e1000 firewire_core scsi_transport_spi crc_itu_t e1000e ptp pps_core pata_marvell fjes floppy May 24 02:24:34 pog kernel: [ 4203.119748] CPU: 1 PID: 394 Comm: kworker/1:1H Tainted: P OE 4.10.16-100.fc24.x86_64 #1 May 24 02:24:34 pog kernel: [ 4203.119750] Hardware name: /D975XBX2, BIOS BX97520J.86A.2838.2008.0903.1859 09/03/2008 May 24 02:24:34 pog kernel: [ 4203.119778] Workqueue: xprtiod xs_tcp_data_receive_workfn [sunrpc] May 24 02:24:34 pog kernel: [ 4203.119782] task: ffff9131e1d2c880 task.stack: ffff9f9bc1204000 May 24 02:24:34 pog kernel: [ 4203.119788] RIP: 0010:page_frag_free+0x6d/0x80 May 24 02:24:34 pog kernel: [ 4203.119791] RSP: 0018:ffff9f9bc1207d10 EFLAGS: 00010286 May 24 02:24:34 pog kernel: [ 4203.119794] RAX: 000000000000003e RBX: ffffedb5c5413dc0 RCX: 0000000000000006 May 24 02:24:34 pog kernel: [ 4203.119796] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff9131efc8e0e0 May 24 02:24:34 pog kernel: [ 4203.119799] RBP: ffff9f9bc1207d10 R08: 000000000001d328 R09: 0000000000000775 May 24 02:24:34 pog kernel: [ 4203.119801] R10: 000000000000000f R11: ffffffff89224d0d R12: ffff9130e18fe600 May 24 02:24:34 pog kernel: [ 4203.119803] R13: 0000000000000005 R14: ffff9130eab40440 R15: 0000000000001a60 May 24 02:24:34 pog kernel: [ 4203.119807] FS: 0000000000000000(0000) GS:ffff9131efc80000(0000) knlGS:0000000000000000 May 24 02:24:34 pog kernel: [ 4203.119809] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 May 24 02:24:34 pog kernel: [ 4203.119812] CR2: 000056528cbe44b4 CR3: 000000019aa9d000 CR4: 00000000000006e0 May 24 02:24:34 pog kernel: [ 4203.119814] Call Trace: May 24 02:24:34 pog kernel: [ 4203.119820] skb_free_head+0x28/0x30 May 24 02:24:34 pog kernel: [ 4203.119823] skb_release_data+0xf5/0x130 May 24 02:24:34 pog kernel: [ 4203.119827] skb_release_all+0x24/0x30 May 24 02:24:34 pog kernel: [ 4203.119830] __kfree_skb+0x12/0x20 May 24 02:24:34 pog kernel: [ 4203.119833] tcp_read_sock+0x11a/0x1e0 May 24 02:24:34 pog kernel: [ 4203.119850] ? xs_tcp_setup_socket+0x4e0/0x4e0 [sunrpc] May 24 02:24:34 pog kernel: [ 4203.119867] ? xs_tcp_setup_socket+0x4e0/0x4e0 [sunrpc] May 24 02:24:34 pog kernel: [ 4203.119883] xs_tcp_data_receive_workfn+0xbb/0x160 [sunrpc] May 24 02:24:34 pog kernel: [ 4203.119888] process_one_work+0x197/0x450 May 24 02:24:34 pog kernel: [ 4203.119891] worker_thread+0x4e/0x4a0 May 24 02:24:34 pog kernel: [ 4203.119894] kthread+0x109/0x140 May 24 02:24:34 pog kernel: [ 4203.119897] ? process_one_work+0x450/0x450 May 24 02:24:34 pog kernel: [ 4203.119900] ? kthread_park+0x90/0x90 May 24 02:24:34 pog kernel: [ 4203.119904] ? do_syscall_64+0x67/0x180 May 24 02:24:34 pog kernel: [ 4203.119907] ret_from_fork+0x2c/0x40 May 24 02:24:34 pog kernel: [ 4203.119909] Code: 47 1c 85 c0 74 19 f0 ff 4f 1c 74 02 5d c3 48 8b 07 31 f6 f6 c4 80 75 15 e8 41 fb ff ff 5d c3 48 c7 c6 58 7e c3 88 e8 33 e9 02 00 <0f> 0b 8b 77 6c eb e6 48 8b 05 65 31 c4 00 eb a4 0f 1f 0$ May 24 02:24:34 pog kernel: [ 4203.119953] RIP: page_frag_free+0x6d/0x80 RSP: ffff9f9bc1207d10 May 24 02:24:34 pog kernel: [ 4203.120037] ---[ end trace c7282584245dbe6e ]--- May 24 02:24:38 pog kernel: [ 4207.647037] nfs: server 192.168.100.2 not responding, still trying May 24 02:24:38 pog kernel: [ 4207.647047] nfs: server 192.168.100.2 not responding, still trying May 24 02:24:38 pog kernel: [ 4207.647051] nfs: server 192.168.100.2 not responding, still trying May 24 02:24:38 pog kernel: [ 4207.647054] nfs: server 192.168.100.2 not responding, still trying May 24 02:24:38 pog kernel: [ 4207.647057] nfs: server 192.168.100.2 not responding, still trying Second occurrence stack trace slightly different (more dumps available on request): May 24 03:04:10 pog kernel: [ 173.097660] skb_free_head+0x28/0x30 May 24 03:04:10 pog kernel: [ 173.097663] skb_release_data+0xf5/0x130 May 24 03:04:10 pog kernel: [ 173.097667] skb_release_all+0x24/0x30 May 24 03:04:10 pog kernel: [ 173.097669] __kfree_skb+0x12/0x20 May 24 03:04:10 pog kernel: [ 173.097673] tcp_recvmsg+0x2e9/0xb40 May 24 03:04:10 pog kernel: [ 173.097677] inet_recvmsg+0x4b/0xc0 May 24 03:04:10 pog kernel: [ 173.097681] sock_recvmsg+0x3d/0x50 May 24 03:04:10 pog kernel: [ 173.097684] sock_read_iter+0x90/0xe0 May 24 03:04:10 pog kernel: [ 173.097688] __vfs_read+0xe2/0x150 May 24 03:04:10 pog kernel: [ 173.097691] vfs_read+0x96/0x130 May 24 03:04:10 pog kernel: [ 173.097695] SyS_read+0x55/0xc0 May 24 03:04:10 pog kernel: [ 173.097698] do_syscall_64+0x67/0x180 May 24 03:04:10 pog kernel: [ 173.097702] entry_SYSCALL64_slow_path+0x25/0x25 Version-Release number of selected component (if applicable): kernel-4.10.16-100.fc24.x86_64 How reproducible: always Steps to Reproduce: 1. boot into 4.10.16 2. have fstab (or whatever systemd expects these days) mount the remote nfs export (mounted "hard") 3. do some reads over nfs (play a music file, watch some video) (takes under 10 minutes to trigger) Actual results: nfs hangs; kernel bug trace in messages Expected results: no hang Additional info: kernel-4.10.14-100.fc24.x86_64 does not have this problem, and I am using that for now. I never tried 4.10.15.
Bug is still there, tested 4.11.5-100.fc24; bug output slightly different: kernel BUG at ./include/linux/mm.h:462! I can make it freeze the mount within 5s just by playing a video off of the exported fs.
Tried 4.11.10-100.fc24 and bug persists. Took about 5 mins to crash this time playing video... I think it crashes faster when I seek all around the video rather than just watching it linearly. I'm going to try to start a bisect.
FYI, my mount options in fstab (in case I'm doing something weird triggering this bug): 192.168.100.2:/data /mnt/data nfs4 rw,bg,async,hard,intr,noatime,nodiratime,nosuid,proto=tcp,timeo=15,rsize=8192,wsize=8192 0 0 from mount: 192.168.100.2:/data on /mnt/data type nfs4 (rw,nosuid,noatime,nodiratime,vers=4.2,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,port=0,timeo=15,retrans=2,sec=sys,clientaddr=192.168.100.1,local_lock=none,addr=192.168.100.2)
I have bisected this bug to: c21b48cc1bbf2f5af3ef54ada559f7fadf8b508b is the first bad commit commit c21b48cc1bbf2f5af3ef54ada559f7fadf8b508b Author: Eric Dumazet <edumazet> Date: Wed Apr 26 09:07:46 2017 -0700 net: adjust skb->truesize in ___pskb_trim() Andrey found a way to trigger the WARN_ON_ONCE(delta < len) in skb_try_coalesce() using syzkaller and a filter attached to a TCP socket. As we did recently in commit 158f323b9868 ("net: adjust skb->truesize in pskb_expand_head()") we can adjust skb->truesize from ___pskb_trim(), via a call to skb_condense(). If all frags were freed, then skb->truesize can be recomputed. This call can be done if skb is not yet owned, or destructor is sock_edemux(). I am currently rpmbuilding a custom test kernel of 4.11.10 with the following patch to undo that commit: diff -uNr a/net/core/skbuff.c b/net/core/skbuff.c --- a/net/core/skbuff.c 2017-07-23 06:48:50.714654762 -0500 +++ b/net/core/skbuff.c 2017-07-23 06:53:31.441060810 -0500 @@ -1576,8 +1576,6 @@ skb_set_tail_pointer(skb, len); } - if (!skb->sk || skb->destructor == sock_edemux) - skb_condense(skb); return 0; } EXPORT_SYMBOL(___pskb_trim); It will take all day to rebuild so I will get back later, but the bisect was pretty easy & clean (can make it crash in about 10s every time) so I'm pretty sure that will be the bug. I'm not sure why I'm the only one in the world with this bug, or why heavy NFS access triggers it. I'll report back when my custom 4.11.10 is booted and doesn't have the bug!
I have confirmed the patch in comment #4 fixes the bug. My bug is definitely caused by commit c21b48cc1bbf2f5af3ef54ada559f7fadf8b508b. My patched stock Fedora 24 4.11.10 works perfectly fine. I'm trying to get some attention to this on LKML, we'll see how that goes.
Eric Dumazet <edumazet> on the netdev mailing list has notified me of a potential "proper" patch to fix my bug: e44699d2c28067f69698ccb68dd3ddeacfebc434 ("net: handle NAPI_GRO_FREE_STOLEN_HEAD case also in napi_frags_finish()") Indeed that patch also fixes my problem (after I took out my kludge c21b48 back-out patch), when applied to stock F24 4.11.10 src rpm. I hadn't tested e44699 as it isn't in any Fedora 24 kernel yet. I'm not sure what vanilla version it is in but the patch is only 1 month old. Is it possible to find out if/when/what F24 kernel version will get this patch? Thanks!
Thanks for tracking it down. F24 is going to go EOL very soon so it's going to be getting very sparse updates. e44699d2c28067f69698ccb68dd3ddeacfebc434 is in 4.12 though so F26 and eventually F25 will be getting that patch.
Thanks! This might be a dumb question, but how can I tell what version of (a) vanilla kernel and/or (b) Fedora's kernel a specific commit is in? I'll be switching to F25 soon and will look forward to that commit.
This message is a reminder that Fedora 24 is nearing its end of life. Approximately 2 (two) weeks from now Fedora will stop maintaining and issuing updates for Fedora 24. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '24'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 24 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
(In reply to Trevor Cordes from comment #8) > Thanks! This might be a dumb question, but how can I tell what version of > (a) vanilla kernel and/or (b) Fedora's kernel a specific commit is in? > > I'll be switching to F25 soon and will look forward to that commit. It's not a dumb question. For vanilla kernels, if you have a git checkout of the tree you can do: git describe --contains <commit sha1sum> For a Fedora kernel, it's somewhat harder depending on things. We have an exploded tree, but if it's a backport the upstream sha1sum can't be used. So for specific patches or bugs, it's probably best just to ask. Also, I would recommend moving to Fedora 26.
I upgraded to F26 and got kernel-4.12.5-300.fc26.x86_64 from koji and my bug appears gone, so that commit must be in there. Note: current non-testing F26 kernel 4.11.11 still has the bug, that's why I had to grab koji. I guess I close this bug as UPSTREAM(?) or wait until 4.12 gets out of testing and into updates proper? P.S. These updates seem to also fix a similar bug (unreported) where my cifs mounts would hang in the exact same way... perhaps they were related. Thanks!
Fedora 24 changed to end-of-life (EOL) status on 2017-08-08. Fedora 24 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.