From: "J. Bruce Fields" <bfields@fieldses.org>
To: Salvatore Bonaccorso <bonaccos@ee.ethz.ch>
Cc: linux-nfs@vger.kernel.org, Chuck Lever <chuck.lever@oracle.com>
Subject: Re: nfsd4_process_open2 failed to open newly-created file! status=10008 ; warning at fs/nfsd/nfs4proc.c for nfsd4_open
Date: Mon, 27 Sep 2021 11:53:38 -0400 [thread overview]
Message-ID: <20210927155338.GA30593@fieldses.org> (raw)
In-Reply-To: <20210927061025.GA20892@varda.ee.ethz.ch>
On Mon, Sep 27, 2021 at 08:10:31AM +0200, Salvatore Bonaccorso wrote:
> We recently got the following traces on a NFS server, but I'm not sure
> how to further debug this, any hints?
The server creates and opens a file in two steps, though it should
really be a single atomic operation.
That means there's a small possibility somebody could intervene and do
something like change the permissions:
>
> [5746893.904448] ------------[ cut here ]------------
> [5746893.910050] nfsd4_process_open2 failed to open newly-created file! status=10008
10008 is NFS4ERR_DELAY, so maybe somebody managed to get a delegation
before we finished opening?
We should be able to prevent that....
In your setup are there processes quickly opening new files created by
others?
--b.
> [5746893.918488] WARNING: CPU: 16 PID: 1316 at fs/nfsd/nfs4proc.c:456 nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5746893.927833] Modules linked in: tcp_diag udp_diag raw_diag inet_diag unix_diag binfmt_misc rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache bonding quota_v2 quota_tree intel_rapl ipmi_ssif skx_edac nfit libnvdimm x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel intel_cstate ttm drm_kms_helper drm intel_uncore pcspkr intel_rapl_perf mei_me ioatdma iTCO_wdt evdev joydev pcc_cpufreq sg i2c_algo_bit iTCO_vendor_support mei dca ipmi_si wmi ipmi_devintf ipmi_msghandler acpi_power_meter acpi_pad button nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto ecb dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c crc32c_generic raid1
> [5746894.000592] raid0 multipath linear md_mod hid_generic usbhid hid sd_mod crc32c_intel xhci_pci ahci xhci_hcd libahci aesni_intel aes_x86_64 crypto_simd libata arcmsr usbcore cryptd i40e scsi_mod glue_helper lpc_ich i2c_i801 mfd_core usb_common
> [5746894.023137] CPU: 16 PID: 1316 Comm: nfsd Not tainted 4.19.0-17-amd64 #1 Debian 4.19.194-3
> [5746894.031916] Hardware name: DALCO AG S2600WFT/S2600WFT, BIOS SE5C620.86B.02.01.0008.031920191559 03/19/2019
> [5746894.042198] RIP: 0010:nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5746894.047704] Code: 80 88 a8 01 00 00 01 e9 52 fe ff ff 80 bb 15 01 00 00 00 0f 84 ef fe ff ff 44 89 fe 48 c7 c7 f0 10 58 c0 0f ce e8 89 70 3a d0 <0f> 0b e9 d7 fe ff ff 48 8b 83 18 01 00 00 8b 55 00 48 8d 75 04 89
> [5746894.067573] RSP: 0018:ffffa5228948fda8 EFLAGS: 00010286
> [5746894.073487] RAX: 0000000000000000 RBX: ffff97c0669ae3e0 RCX: 0000000000000000
> [5746894.081317] RDX: ffff97cc8f91efc0 RSI: ffff97cc8f9166b8 RDI: ffff97cc8f9166b8
> [5746894.089148] RBP: ffff97c0665b0068 R08: 00000000000005e8 R09: 0000000000aaaaaa
> [5746894.096993] R10: 0000000000000000 R11: 0000000000000001 R12: ffff97c0cc1cb400
> [5746894.104848] R13: ffff97c066aa8000 R14: ffff97c0665a9600 R15: 0000000018270000
> [5746894.112717] FS: 0000000000000000(0000) GS:ffff97cc8f900000(0000) knlGS:0000000000000000
> [5746894.121558] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [5746894.128035] CR2: 00007f83d25a68a0 CR3: 00000015b900a002 CR4: 00000000007606e0
> [5746894.135899] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [5746894.143764] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [5746894.151647] PKRU: 55555554
> [5746894.155117] Call Trace:
> [5746894.158373] nfsd4_proc_compound+0x342/0x660 [nfsd]
> [5746894.164084] nfsd_dispatch+0x9e/0x210 [nfsd]
> [5746894.169206] svc_process_common+0x345/0x750 [sunrpc]
> [5746894.175017] ? nfsd_destroy+0x50/0x50 [nfsd]
> [5746894.180155] svc_process+0xb7/0xf0 [sunrpc]
> [5746894.185194] nfsd+0xe3/0x140 [nfsd]
> [5746894.189545] kthread+0x112/0x130
> [5746894.193618] ? kthread_bind+0x30/0x30
> [5746894.198072] ret_from_fork+0x35/0x40
> [5746894.202439] ---[ end trace c6400532dff968eb ]---
> [5768733.993671] ------------[ cut here ]------------
> [5768733.999711] nfsd4_process_open2 failed to open newly-created file! status=10008
> [5768734.008148] WARNING: CPU: 9 PID: 1316 at fs/nfsd/nfs4proc.c:456 nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5768734.017448] Modules linked in: tcp_diag udp_diag raw_diag inet_diag unix_diag binfmt_misc rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache bonding quota_v2 quota_tree intel_rapl ipmi_ssif skx_edac nfit libnvdimm x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel intel_cstate ttm drm_kms_helper drm intel_uncore pcspkr intel_rapl_perf mei_me ioatdma iTCO_wdt evdev joydev pcc_cpufreq sg i2c_algo_bit iTCO_vendor_support mei dca ipmi_si wmi ipmi_devintf ipmi_msghandler acpi_power_meter acpi_pad button nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto ecb dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c crc32c_generic raid1
> [5768734.092781] raid0 multipath linear md_mod hid_generic usbhid hid sd_mod crc32c_intel xhci_pci ahci xhci_hcd libahci aesni_intel aes_x86_64 crypto_simd libata arcmsr usbcore cryptd i40e scsi_mod glue_helper lpc_ich i2c_i801 mfd_core usb_common
> [5768734.115967] CPU: 9 PID: 1316 Comm: nfsd Tainted: G W 4.19.0-17-amd64 #1 Debian 4.19.194-3
> [5768734.126331] Hardware name: DALCO AG S2600WFT/S2600WFT, BIOS SE5C620.86B.02.01.0008.031920191559 03/19/2019
> [5768734.136855] RIP: 0010:nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5768734.142623] Code: 80 88 a8 01 00 00 01 e9 52 fe ff ff 80 bb 15 01 00 00 00 0f 84 ef fe ff ff 44 89 fe 48 c7 c7 f0 10 58 c0 0f ce e8 89 70 3a d0 <0f> 0b e9 d7 fe ff ff 48 8b 83 18 01 00 00 8b 55 00 48 8d 75 04 89
> [5768734.162998] RSP: 0018:ffffa5228948fda8 EFLAGS: 00010286
> [5768734.169071] RAX: 0000000000000000 RBX: ffff97c0669ae3e0 RCX: 0000000000000000
> [5768734.177036] RDX: ffff97c090e9efc0 RSI: ffff97c090e966b8 RDI: ffff97c090e966b8
> [5768734.184996] RBP: ffff97c0665b0068 R08: 0000000000000608 R09: 0000000000aaaaaa
> [5768734.192945] R10: 0000000000000000 R11: 0000000000000001 R12: ffff97c08698b000
> [5768734.200885] R13: ffff97c066aa8000 R14: ffff97c0665a9600 R15: 0000000018270000
> [5768734.208815] FS: 0000000000000000(0000) GS:ffff97c090e80000(0000) knlGS:0000000000000000
> [5768734.217702] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [5768734.224236] CR2: 00007f9b4006df10 CR3: 00000015b900a002 CR4: 00000000007606e0
> [5768734.232157] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [5768734.240077] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [5768734.248017] PKRU: 55555554
> [5768734.251553] Call Trace:
> [5768734.254867] nfsd4_proc_compound+0x342/0x660 [nfsd]
> [5768734.260517] nfsd_dispatch+0x9e/0x210 [nfsd]
> [5768734.265570] svc_process_common+0x345/0x750 [sunrpc]
> [5768734.271373] ? nfsd_destroy+0x50/0x50 [nfsd]
> [5768734.276414] svc_process+0xb7/0xf0 [sunrpc]
> [5768734.281370] nfsd+0xe3/0x140 [nfsd]
> [5768734.285624] kthread+0x112/0x130
> [5768734.289610] ? kthread_bind+0x30/0x30
> [5768734.294030] ret_from_fork+0x35/0x40
> [5768734.298396] ---[ end trace c6400532dff968ec ]---
> [5795002.037239] ------------[ cut here ]------------
> [5795002.044280] nfsd4_process_open2 failed to open newly-created file! status=10008
> [5795002.053358] WARNING: CPU: 1 PID: 1315 at fs/nfsd/nfs4proc.c:456 nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5795002.063065] Modules linked in: tcp_diag udp_diag raw_diag inet_diag unix_diag binfmt_misc rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache bonding quota_v2 quota_tree intel_rapl ipmi_ssif skx_edac nfit libnvdimm x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel intel_cstate ttm drm_kms_helper drm intel_uncore pcspkr intel_rapl_perf mei_me ioatdma iTCO_wdt evdev joydev pcc_cpufreq sg i2c_algo_bit iTCO_vendor_support mei dca ipmi_si wmi ipmi_devintf ipmi_msghandler acpi_power_meter acpi_pad button nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto ecb dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c crc32c_generic raid1
> [5795002.138537] raid0 multipath linear md_mod hid_generic usbhid hid sd_mod crc32c_intel xhci_pci ahci xhci_hcd libahci aesni_intel aes_x86_64 crypto_simd libata arcmsr usbcore cryptd i40e scsi_mod glue_helper lpc_ich i2c_i801 mfd_core usb_common
> [5795002.161747] CPU: 1 PID: 1315 Comm: nfsd Tainted: G W 4.19.0-17-amd64 #1 Debian 4.19.194-3
> [5795002.172089] Hardware name: DALCO AG S2600WFT/S2600WFT, BIOS SE5C620.86B.02.01.0008.031920191559 03/19/2019
> [5795002.182668] RIP: 0010:nfsd4_open+0x4e0/0x6f0 [nfsd]
> [5795002.188400] Code: 80 88 a8 01 00 00 01 e9 52 fe ff ff 80 bb 15 01 00 00 00 0f 84 ef fe ff ff 44 89 fe 48 c7 c7 f0 10 58 c0 0f ce e8 89 70 3a d0 <0f> 0b e9 d7 fe ff ff 48 8b 83 18 01 00 00 8b 55 00 48 8d 75 04 89
> [5795002.208706] RSP: 0018:ffffa52289487da8 EFLAGS: 00010286
> [5795002.214775] RAX: 0000000000000000 RBX: ffff97c0669a83e0 RCX: 0000000000000000
> [5795002.222743] RDX: ffff97c090a9efc0 RSI: ffff97c090a966b8 RDI: ffff97c090a966b8
> [5795002.230710] RBP: ffff97c0669aa068 R08: 0000000000000628 R09: 0000000000aaaaaa
> [5795002.238684] R10: 0000000000000000 R11: 0000000000000001 R12: ffff97c21bb64200
> [5795002.246670] R13: ffff97c066aae000 R14: ffff97c0665a8000 R15: 0000000018270000
> [5795002.254611] FS: 0000000000000000(0000) GS:ffff97c090a80000(0000) knlGS:0000000000000000
> [5795002.263492] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [5795002.270097] CR2: 00007fba9f588590 CR3: 00000015b900a002 CR4: 00000000007606e0
> [5795002.278100] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [5795002.286091] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [5795002.294078] PKRU: 55555554
> [5795002.297634] Call Trace:
> [5795002.300910] nfsd4_proc_compound+0x342/0x660 [nfsd]
> [5795002.306572] nfsd_dispatch+0x9e/0x210 [nfsd]
> [5795002.311617] svc_process_common+0x345/0x750 [sunrpc]
> [5795002.317421] ? nfsd_destroy+0x50/0x50 [nfsd]
> [5795002.322480] svc_process+0xb7/0xf0 [sunrpc]
> [5795002.327433] nfsd+0xe3/0x140 [nfsd]
> [5795002.331728] kthread+0x112/0x130
> [5795002.335718] ? kthread_bind+0x30/0x30
> [5795002.340144] ret_from_fork+0x35/0x40
> [5795002.344475] ---[ end trace c6400532dff968ed ]---
>
> But I have as well no reproducing recipe to trigger it.
>
> The kernel is the current Debian buster distro kernel, based on
> 4.19.194.
>
> This initally looked similar than
> https://bugzilla.kernel.org/show_bug.cgi?id=195725 but the user did
> get there status=5, so EIO, so seems different issue.
>
> Regards,
> Salvatore
next prev parent reply other threads:[~2021-09-27 15:53 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-09-27 6:10 nfsd4_process_open2 failed to open newly-created file! status=10008 ; warning at fs/nfsd/nfs4proc.c for nfsd4_open Salvatore Bonaccorso
2021-09-27 15:53 ` J. Bruce Fields [this message]
2021-09-28 5:11 ` Salvatore Bonaccorso
2021-09-28 19:39 ` J. Bruce Fields
2021-09-29 4:06 ` Salvatore Bonaccorso
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20210927155338.GA30593@fieldses.org \
--to=bfields@fieldses.org \
--cc=bonaccos@ee.ethz.ch \
--cc=chuck.lever@oracle.com \
--cc=linux-nfs@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.