| Message ID | 1693510547-29288-1-git-send-email-dai.ngo@oracle.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | [v2,1/1] NFSD: add trace points to track server copy progress | expand |
> -----邮件原件----- > 发件人: Dai Ngo <dai.ngo@oracle.com> > 发送时间: 2023年9月1日 3:36 > 收件人: chuck.lever@oracle.com; jlayton@kernel.org > 抄送: linux-nfs@vger.kernel.org > 主题: [PATCH v2 1/1] NFSD: add trace points to track server copy progress > > Add trace points on destination server to track inter and intra server copy > operations. > > Signed-off-by: Dai Ngo <dai.ngo@oracle.com> > --- > v2: rename trace points from nfsd4_trace_... to nfsd_trace_... > fix kernel test robot by removing ifdef CONFIG_NFS_V4_2 in trace.h > Hi, Dai I'm testing this patch base on 7ba2090ca64ea1aa435744884124387db1fac70f via Fedora 38. but got some oops message. Pls have a look. Regards, - Chen How to reproduce: server: trace-cmd record -e nfsd:nfsd_copy* client mount -o vers=4.2 192.168.122.212:/nfstest /mnt/test mount -o vers=4.2 192.168.122.212:/nfsscratch /mnt/scratch cp /mnt/test/some-file.tgz /mnt/scratch [ 713.008623] CPU: 0 PID: 1562 Comm: nfsd Kdump: loaded Not tainted 6.5.0+ #14 [ 713.008660] Hardware name: Red Hat KVM/RHEL-AV, BIOS 1.13.0-2.module+el8.3.0+7353+9de0a3cc 04/01/2014 [ 713.008699] RIP: 0010:trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] [ 713.008868] Code: 48 8b 53 20 48 89 50 30 48 8b 53 28 48 89 50 38 48 8b 53 30 48 89 50 40 48 8b b3 f8 00 00 00 48 8d 50 4c 48 8d 8e b8 00 00 00 <48> 8b b6 b8 00 00 00 48 89 70 4c 48 8b 41 08 48 89 42 08 48 8b 41 [ 713.008944] RSP: 0018:ff22381280edfd78 EFLAGS: 00010202 [ 713.008972] RAX: ff12ee8a8007701c RBX: ff12ee8a820988e0 RCX: 00000000000000b8 [ 713.009004] RDX: ff12ee8a80077068 RSI: 0000000000000000 RDI: ff22381280edfd78 [ 713.009036] RBP: ff12ee8a90afdf00 R08: 0000000000000001 R09: 0000000000000000 [ 713.009055] R10: 0000000000000000 R11: 0000000000038560 R12: ff22381280edfd78 [ 713.009064] R13: ff12ee8a959b4000 R14: 0000000000000000 R15: ff12ee8a820988c0 [ 713.009074] FS: 0000000000000000(0000) GS:ff12ee8afba00000(0000) knlGS:0000000000000000 [ 713.009084] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 713.009091] CR2: 00000000000000b8 CR3: 0000000110970004 CR4: 0000000000771ef0 [ 713.009104] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 713.009113] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 713.009123] PKRU: 55555554 [ 713.009127] Call Trace: [ 713.009134] <TASK> [ 713.009139] ? __die+0x1f/0x70 [ 713.009148] ? page_fault_oops+0x171/0x4f0 [ 713.009157] ? __kmem_cache_alloc_node+0x175/0x310 [ 713.009167] ? security_prepare_creds+0xc5/0xe0 [ 713.009177] ? exc_page_fault+0x7b/0x180 [ 713.009186] ? asm_exc_page_fault+0x22/0x30 [ 713.009195] ? trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] [ 713.009237] ? trace_event_raw_event_nfsd_copy_class+0x4b/0x140 [nfsd] [ 713.009274] nfsd4_copy+0x47d/0x6e0 [nfsd] [ 713.009319] nfsd4_proc_compound+0x399/0x6f0 [nfsd] [ 713.009360] ? __pfx_nfsd+0x10/0x10 [nfsd] [ 713.009401] nfsd_dispatch+0x80/0x1b0 [nfsd] [ 713.009442] svc_process_common+0x439/0x6e0 [sunrpc] [ 713.009510] ? __pfx_nfsd_dispatch+0x10/0x10 [nfsd] [ 713.009551] ? __pfx_nfsd+0x10/0x10 [nfsd] [ 713.009599] svc_process+0x12d/0x170 [sunrpc] [ 713.009890] nfsd+0x80/0xd0 [nfsd] [ 713.010142] kthread+0xf0/0x120 [ 713.010352] ? __pfx_kthread+0x10/0x10 [ 713.010569] ret_from_fork+0x2d/0x50 [ 713.010771] ? __pfx_kthread+0x10/0x10 [ 713.010972] ret_from_fork_asm+0x1b/0x30 [ 713.011176] </TASK> [ 713.011374] Modules linked in: rpcsec_gss_krb5 rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd auth_rpcgss nfs_acl lockd grace nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill sunrpc ip_set nf_tables nfnetlink qrtr intel_rapl_msr intel_rapl_common nfit libnvdimm kvm_intel kvm snd_hda_codec_generic ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec iTCO_wdt irqbypass intel_pmc_bxt snd_hda_core iTCO_vendor_support snd_hwdep snd_pcm snd_timer snd i2c_i801 i2c_smbus pcspkr lpc_ich soundcore virtio_balloon joydev fuse loop zram xfs crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic ghash_clmulni_intel qxl sha512_ssse3 drm_ttm_helper virtio_net ttm virtio_blk net_failover virtio_console failover serio_raw scsi_dh_rdac scsi_dh_emc scsi_dh_alua dm_multipath qemu_fw_cfg [ 713.013232] CR2: 00000000000000b8 [ 713.013460] ---[ end trace 0000000000000000 ]--- [ 713.013688] RIP: 0010:trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] [ 713.013944] Code: 48 8b 53 20 48 89 50 30 48 8b 53 28 48 89 50 38 48 8b 53 30 48 89 50 40 48 8b b3 f8 00 00 00 48 8d 50 4c 48 8d 8e b8 00 00 00 <48> 8b b6 b8 00 00 00 48 89 70 4c 48 8b 41 08 48 89 42 08 48 8b 41 [ 713.014406] RSP: 0018:ff22381280edfd78 EFLAGS: 00010202 [ 713.014644] RAX: ff12ee8a8007701c RBX: ff12ee8a820988e0 RCX: 00000000000000b8 [ 713.014880] RDX: ff12ee8a80077068 RSI: 0000000000000000 RDI: ff22381280edfd78 [ 713.015117] RBP: ff12ee8a90afdf00 R08: 0000000000000001 R09: 0000000000000000 [ 713.015351] R10: 0000000000000000 R11: 0000000000038560 R12: ff22381280edfd78 [ 713.015590] R13: ff12ee8a959b4000 R14: 0000000000000000 R15: ff12ee8a820988c0 [ 713.015821] FS: 0000000000000000(0000) GS:ff12ee8afba00000(0000) knlGS:0000000000000000 [ 713.016057] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 713.016296] CR2: 00000000000000b8 CR3: 0000000110970004 CR4: 0000000000771ef0 [ 713.016536] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 713.016778] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 713.017019] PKRU: 55555554 [ 713.017263] note: nfsd[1562] exited with irqs disabled [ 713.017532] note: nfsd[1562] exited with preempt_count 2 [ 835.057703] ------------[ cut here ]------------ [ 835.058376] WARNING: CPU: 2 PID: 1712 at kernel/trace/ring_buffer.c:5304 reset_disabled_cpu_buffer+0x254/0x270 [ 835.058643] Modules linked in: rpcsec_gss_krb5 rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd auth_rpcgss nfs_acl lockd grace nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill sunrpc ip_set nf_tables nfnetlink qrtr intel_rapl_msr intel_rapl_common nfit libnvdimm kvm_intel kvm snd_hda_codec_generic ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec iTCO_wdt irqbypass intel_pmc_bxt snd_hda_core iTCO_vendor_support snd_hwdep snd_pcm snd_timer snd i2c_i801 i2c_smbus pcspkr lpc_ich soundcore virtio_balloon joydev fuse loop zram xfs crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic ghash_clmulni_intel qxl sha512_ssse3 drm_ttm_helper virtio_net ttm virtio_blk net_failover virtio_console failover serio_raw scsi_dh_rdac scsi_dh_emc scsi_dh_alua dm_multipath qemu_fw_cfg [ 835.060996] CPU: 2 PID: 1712 Comm: trace-cmd Kdump: loaded Tainted: G D 6.5.0+ #14 [ 835.061311] Hardware name: Red Hat KVM/RHEL-AV, BIOS 1.13.0-2.module+el8.3.0+7353+9de0a3cc 04/01/2014 [ 835.061633] RIP: 0010:reset_disabled_cpu_buffer+0x254/0x270 [ 835.061952] Code: 28 01 00 00 00 00 00 00 4c 89 e7 e8 56 13 d7 00 90 5b 48 89 ee 4c 89 ef 5d 41 5c 41 5d e9 c4 0a d7 00 48 8b 43 10 f0 ff 40 08 <0f> 0b eb e3 89 c6 4c 89 e7 e8 2e 16 d7 00 90 e9 d4 fd ff ff 0f 1f [ 835.062611] RSP: 0018:ff2238128073bbd0 EFLAGS: 00010002 [ 835.062945] RAX: ff12ee8a8003e700 RBX: ff12ee8a80040c00 RCX: 0000000000000000 [ 835.063282] RDX: 0000000000000001 RSI: 0000000000000000 RDI: 0000000000000000 [ 835.063619] RBP: 0000000000000206 R08: 0000000000000000 R09: 0000000000000000 [ 835.063941] R10: 0000000000000001 R11: 0000000000000100 R12: ff12ee8a8003e700 [ 835.064260] R13: ff12ee8a80040c18 R14: ff12ee8a82d4ac98 R15: ff12ee8a82d4ac00 [ 835.064576] FS: 00007f433e809780(0000) GS:ff12ee8afbb00000(0000) knlGS:0000000000000000 [ 835.064884] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 835.065190] CR2: 00005635914ef0f8 CR3: 0000000110970006 CR4: 0000000000771ee0 [ 835.065495] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 835.065788] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 835.066082] PKRU: 55555554 [ 835.066374] Call Trace: [ 835.066666] <TASK> [ 835.066943] ? reset_disabled_cpu_buffer+0x254/0x270 [ 835.067216] ? __warn+0x7d/0x130 [ 835.067488] ? reset_disabled_cpu_buffer+0x254/0x270 [ 835.067761] ? report_bug+0x18d/0x1c0 [ 835.068029] ? handle_bug+0x3c/0x80 [ 835.068294] ? exc_invalid_op+0x13/0x60 [ 835.068558] ? asm_exc_invalid_op+0x16/0x20 [ 835.068827] ? reset_disabled_cpu_buffer+0x254/0x270 [ 835.069087] ring_buffer_reset_online_cpus+0x7e/0xc0 [ 835.069346] tracing_reset_online_cpus+0x6e/0xc0 [ 835.069610] tracing_open+0x143/0x160 [ 835.069864] ? __pfx_tracing_open+0x10/0x10 [ 835.070120] do_dentry_open+0x200/0x4f0 [ 835.070371] path_openat+0xafe/0x1160 [ 835.070627] do_filp_open+0xaf/0x160 [ 835.070880] do_sys_openat2+0xab/0xe0 [ 835.071129] ? kmem_cache_free+0x1e/0x3e0 [ 835.071380] __x64_sys_openat+0x53/0xa0 [ 835.071636] do_syscall_64+0x59/0x90 [ 835.071883] ? syscall_exit_to_user_mode+0x27/0x40 [ 835.072128] ? do_syscall_64+0x68/0x90 [ 835.072367] ? syscall_exit_to_user_mode+0x27/0x40 [ 835.072604] ? do_syscall_64+0x68/0x90 [ 835.072825] entry_SYSCALL_64_after_hwframe+0x6e/0xd8 [ 835.073044] RIP: 0033:0x7f433e918015 [ 835.073254] Code: 83 e2 40 75 50 89 f0 f7 d0 a9 00 00 41 00 74 45 80 3d d6 c5 0d 00 00 74 60 89 da 4c 89 e6 bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 7f 00 00 00 48 8b 55 b8 64 48 2b 14 25 28 [ 835.073690] RSP: 002b:00007ffd20591490 EFLAGS: 00000202 ORIG_RAX: 0000000000000101 [ 835.073904] RAX: ffffffffffffffda RBX: 0000000000000241 RCX: 00007f433e918015 [ 835.074116] RDX: 0000000000000241 RSI: 00005635914db9c0 RDI: 00000000ffffff9c [ 835.074325] RBP: 00007ffd20591500 R08: 0000000000000004 R09: 0000000000000001 [ 835.074532] R10: 00000000000001b6 R11: 0000000000000202 R12: 00005635914db9c0 [ 835.074736] R13: 000056359037a976 R14: 000056359037a976 R15: 0000000000000001 [ 835.074933] </TASK> [ 835.075121] ---[ end trace 0000000000000000 ]---
Hi Chen, Did you also apply this patch: [PATCH 1/2] NFSD: initialize copy->cp_clp early in nfsd4_copy for use by trace point This patch is a prerequisite for [PATCH v2 1/1] NFSD: add trace points to track server copy progress Sorry for the confusion. -Dai On 9/11/23 7:39 PM, Hanxiao Chen (Fujitsu) wrote: >> -----邮件原件----- >> 发件人: Dai Ngo <dai.ngo@oracle.com> >> 发送时间: 2023年9月1日 3:36 >> 收件人: chuck.lever@oracle.com; jlayton@kernel.org >> 抄送: linux-nfs@vger.kernel.org >> 主题: [PATCH v2 1/1] NFSD: add trace points to track server copy progress >> >> Add trace points on destination server to track inter and intra server copy >> operations. >> >> Signed-off-by: Dai Ngo <dai.ngo@oracle.com> >> --- >> v2: rename trace points from nfsd4_trace_... to nfsd_trace_... >> fix kernel test robot by removing ifdef CONFIG_NFS_V4_2 in trace.h >> > Hi, Dai > > I'm testing this patch base on 7ba2090ca64ea1aa435744884124387db1fac70f via Fedora 38. > but got some oops message. > Pls have a look. > > Regards, > - Chen > > How to reproduce: > server: > trace-cmd record -e nfsd:nfsd_copy* > > client > mount -o vers=4.2 192.168.122.212:/nfstest /mnt/test > mount -o vers=4.2 192.168.122.212:/nfsscratch /mnt/scratch > > > cp /mnt/test/some-file.tgz /mnt/scratch > > > [ 713.008623] CPU: 0 PID: 1562 Comm: nfsd Kdump: loaded Not tainted 6.5.0+ #14 > [ 713.008660] Hardware name: Red Hat KVM/RHEL-AV, BIOS 1.13.0-2.module+el8.3.0+7353+9de0a3cc 04/01/2014 > [ 713.008699] RIP: 0010:trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] > [ 713.008868] Code: 48 8b 53 20 48 89 50 30 48 8b 53 28 48 89 50 38 48 8b 53 30 48 89 50 40 48 8b b3 f8 00 00 00 48 8d 50 4c 48 8d 8e b8 00 00 00 <48> 8b b6 b8 00 00 00 48 89 70 4c 48 8b 41 08 48 89 42 08 48 8b 41 > [ 713.008944] RSP: 0018:ff22381280edfd78 EFLAGS: 00010202 > [ 713.008972] RAX: ff12ee8a8007701c RBX: ff12ee8a820988e0 RCX: 00000000000000b8 > [ 713.009004] RDX: ff12ee8a80077068 RSI: 0000000000000000 RDI: ff22381280edfd78 > [ 713.009036] RBP: ff12ee8a90afdf00 R08: 0000000000000001 R09: 0000000000000000 > [ 713.009055] R10: 0000000000000000 R11: 0000000000038560 R12: ff22381280edfd78 > [ 713.009064] R13: ff12ee8a959b4000 R14: 0000000000000000 R15: ff12ee8a820988c0 > [ 713.009074] FS: 0000000000000000(0000) GS:ff12ee8afba00000(0000) knlGS:0000000000000000 > [ 713.009084] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 713.009091] CR2: 00000000000000b8 CR3: 0000000110970004 CR4: 0000000000771ef0 > [ 713.009104] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 713.009113] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > [ 713.009123] PKRU: 55555554 > [ 713.009127] Call Trace: > [ 713.009134] <TASK> > [ 713.009139] ? __die+0x1f/0x70 > [ 713.009148] ? page_fault_oops+0x171/0x4f0 > [ 713.009157] ? __kmem_cache_alloc_node+0x175/0x310 > [ 713.009167] ? security_prepare_creds+0xc5/0xe0 > [ 713.009177] ? exc_page_fault+0x7b/0x180 > [ 713.009186] ? asm_exc_page_fault+0x22/0x30 > [ 713.009195] ? trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] > [ 713.009237] ? trace_event_raw_event_nfsd_copy_class+0x4b/0x140 [nfsd] > [ 713.009274] nfsd4_copy+0x47d/0x6e0 [nfsd] > [ 713.009319] nfsd4_proc_compound+0x399/0x6f0 [nfsd] > [ 713.009360] ? __pfx_nfsd+0x10/0x10 [nfsd] > [ 713.009401] nfsd_dispatch+0x80/0x1b0 [nfsd] > [ 713.009442] svc_process_common+0x439/0x6e0 [sunrpc] > [ 713.009510] ? __pfx_nfsd_dispatch+0x10/0x10 [nfsd] > [ 713.009551] ? __pfx_nfsd+0x10/0x10 [nfsd] > [ 713.009599] svc_process+0x12d/0x170 [sunrpc] > [ 713.009890] nfsd+0x80/0xd0 [nfsd] > [ 713.010142] kthread+0xf0/0x120 > [ 713.010352] ? __pfx_kthread+0x10/0x10 > [ 713.010569] ret_from_fork+0x2d/0x50 > [ 713.010771] ? __pfx_kthread+0x10/0x10 > [ 713.010972] ret_from_fork_asm+0x1b/0x30 > [ 713.011176] </TASK> > [ 713.011374] Modules linked in: rpcsec_gss_krb5 rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd auth_rpcgss nfs_acl lockd grace nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill sunrpc ip_set nf_tables nfnetlink qrtr intel_rapl_msr intel_rapl_common nfit libnvdimm kvm_intel kvm snd_hda_codec_generic ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec iTCO_wdt irqbypass intel_pmc_bxt snd_hda_core iTCO_vendor_support snd_hwdep snd_pcm snd_timer snd i2c_i801 i2c_smbus pcspkr lpc_ich soundcore virtio_balloon joydev fuse loop zram xfs crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic ghash_clmulni_intel qxl sha512_ssse3 drm_ttm_helper virtio_net ttm virtio_blk net_failover virtio_console failover serio_raw scsi_dh_rdac scsi_dh_emc scsi_dh_alua dm_multipath qemu_fw_cfg > [ 713.013232] CR2: 00000000000000b8 > [ 713.013460] ---[ end trace 0000000000000000 ]--- > [ 713.013688] RIP: 0010:trace_event_raw_event_nfsd_copy_class+0xd6/0x140 [nfsd] > [ 713.013944] Code: 48 8b 53 20 48 89 50 30 48 8b 53 28 48 89 50 38 48 8b 53 30 48 89 50 40 48 8b b3 f8 00 00 00 48 8d 50 4c 48 8d 8e b8 00 00 00 <48> 8b b6 b8 00 00 00 48 89 70 4c 48 8b 41 08 48 89 42 08 48 8b 41 > [ 713.014406] RSP: 0018:ff22381280edfd78 EFLAGS: 00010202 > [ 713.014644] RAX: ff12ee8a8007701c RBX: ff12ee8a820988e0 RCX: 00000000000000b8 > [ 713.014880] RDX: ff12ee8a80077068 RSI: 0000000000000000 RDI: ff22381280edfd78 > [ 713.015117] RBP: ff12ee8a90afdf00 R08: 0000000000000001 R09: 0000000000000000 > [ 713.015351] R10: 0000000000000000 R11: 0000000000038560 R12: ff22381280edfd78 > [ 713.015590] R13: ff12ee8a959b4000 R14: 0000000000000000 R15: ff12ee8a820988c0 > [ 713.015821] FS: 0000000000000000(0000) GS:ff12ee8afba00000(0000) knlGS:0000000000000000 > [ 713.016057] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 713.016296] CR2: 00000000000000b8 CR3: 0000000110970004 CR4: 0000000000771ef0 > [ 713.016536] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 713.016778] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > [ 713.017019] PKRU: 55555554 > [ 713.017263] note: nfsd[1562] exited with irqs disabled > [ 713.017532] note: nfsd[1562] exited with preempt_count 2 > [ 835.057703] ------------[ cut here ]------------ > [ 835.058376] WARNING: CPU: 2 PID: 1712 at kernel/trace/ring_buffer.c:5304 reset_disabled_cpu_buffer+0x254/0x270 > [ 835.058643] Modules linked in: rpcsec_gss_krb5 rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd auth_rpcgss nfs_acl lockd grace nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill sunrpc ip_set nf_tables nfnetlink qrtr intel_rapl_msr intel_rapl_common nfit libnvdimm kvm_intel kvm snd_hda_codec_generic ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec iTCO_wdt irqbypass intel_pmc_bxt snd_hda_core iTCO_vendor_support snd_hwdep snd_pcm snd_timer snd i2c_i801 i2c_smbus pcspkr lpc_ich soundcore virtio_balloon joydev fuse loop zram xfs crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic ghash_clmulni_intel qxl sha512_ssse3 drm_ttm_helper virtio_net ttm virtio_blk net_failover virtio_console failover serio_raw scsi_dh_rdac scsi_dh_emc scsi_dh_alua dm_multipath qemu_fw_cfg > [ 835.060996] CPU: 2 PID: 1712 Comm: trace-cmd Kdump: loaded Tainted: G D 6.5.0+ #14 > [ 835.061311] Hardware name: Red Hat KVM/RHEL-AV, BIOS 1.13.0-2.module+el8.3.0+7353+9de0a3cc 04/01/2014 > [ 835.061633] RIP: 0010:reset_disabled_cpu_buffer+0x254/0x270 > [ 835.061952] Code: 28 01 00 00 00 00 00 00 4c 89 e7 e8 56 13 d7 00 90 5b 48 89 ee 4c 89 ef 5d 41 5c 41 5d e9 c4 0a d7 00 48 8b 43 10 f0 ff 40 08 <0f> 0b eb e3 89 c6 4c 89 e7 e8 2e 16 d7 00 90 e9 d4 fd ff ff 0f 1f > [ 835.062611] RSP: 0018:ff2238128073bbd0 EFLAGS: 00010002 > [ 835.062945] RAX: ff12ee8a8003e700 RBX: ff12ee8a80040c00 RCX: 0000000000000000 > [ 835.063282] RDX: 0000000000000001 RSI: 0000000000000000 RDI: 0000000000000000 > [ 835.063619] RBP: 0000000000000206 R08: 0000000000000000 R09: 0000000000000000 > [ 835.063941] R10: 0000000000000001 R11: 0000000000000100 R12: ff12ee8a8003e700 > [ 835.064260] R13: ff12ee8a80040c18 R14: ff12ee8a82d4ac98 R15: ff12ee8a82d4ac00 > [ 835.064576] FS: 00007f433e809780(0000) GS:ff12ee8afbb00000(0000) knlGS:0000000000000000 > [ 835.064884] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 835.065190] CR2: 00005635914ef0f8 CR3: 0000000110970006 CR4: 0000000000771ee0 > [ 835.065495] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 835.065788] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 > [ 835.066082] PKRU: 55555554 > [ 835.066374] Call Trace: > [ 835.066666] <TASK> > [ 835.066943] ? reset_disabled_cpu_buffer+0x254/0x270 > [ 835.067216] ? __warn+0x7d/0x130 > [ 835.067488] ? reset_disabled_cpu_buffer+0x254/0x270 > [ 835.067761] ? report_bug+0x18d/0x1c0 > [ 835.068029] ? handle_bug+0x3c/0x80 > [ 835.068294] ? exc_invalid_op+0x13/0x60 > [ 835.068558] ? asm_exc_invalid_op+0x16/0x20 > [ 835.068827] ? reset_disabled_cpu_buffer+0x254/0x270 > [ 835.069087] ring_buffer_reset_online_cpus+0x7e/0xc0 > [ 835.069346] tracing_reset_online_cpus+0x6e/0xc0 > [ 835.069610] tracing_open+0x143/0x160 > [ 835.069864] ? __pfx_tracing_open+0x10/0x10 > [ 835.070120] do_dentry_open+0x200/0x4f0 > [ 835.070371] path_openat+0xafe/0x1160 > [ 835.070627] do_filp_open+0xaf/0x160 > [ 835.070880] do_sys_openat2+0xab/0xe0 > [ 835.071129] ? kmem_cache_free+0x1e/0x3e0 > [ 835.071380] __x64_sys_openat+0x53/0xa0 > [ 835.071636] do_syscall_64+0x59/0x90 > [ 835.071883] ? syscall_exit_to_user_mode+0x27/0x40 > [ 835.072128] ? do_syscall_64+0x68/0x90 > [ 835.072367] ? syscall_exit_to_user_mode+0x27/0x40 > [ 835.072604] ? do_syscall_64+0x68/0x90 > [ 835.072825] entry_SYSCALL_64_after_hwframe+0x6e/0xd8 > [ 835.073044] RIP: 0033:0x7f433e918015 > [ 835.073254] Code: 83 e2 40 75 50 89 f0 f7 d0 a9 00 00 41 00 74 45 80 3d d6 c5 0d 00 00 74 60 89 da 4c 89 e6 bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 7f 00 00 00 48 8b 55 b8 64 48 2b 14 25 28 > [ 835.073690] RSP: 002b:00007ffd20591490 EFLAGS: 00000202 ORIG_RAX: 0000000000000101 > [ 835.073904] RAX: ffffffffffffffda RBX: 0000000000000241 RCX: 00007f433e918015 > [ 835.074116] RDX: 0000000000000241 RSI: 00005635914db9c0 RDI: 00000000ffffff9c > [ 835.074325] RBP: 00007ffd20591500 R08: 0000000000000004 R09: 0000000000000001 > [ 835.074532] R10: 00000000000001b6 R11: 0000000000000202 R12: 00005635914db9c0 > [ 835.074736] R13: 000056359037a976 R14: 000056359037a976 R15: 0000000000000001 > [ 835.074933] </TASK> > [ 835.075121] ---[ end trace 0000000000000000 ]--- > > > > > >
> -----邮件原件----- > 发件人: dai.ngo@oracle.com <dai.ngo@oracle.com> > 发送时间: 2023年9月12日 21:59 > 主题: Re: 回复: [PATCH v2 1/1] NFSD: add trace points to track server copy > progress > > Hi Chen, > > Did you also apply this patch: > > [PATCH 1/2] NFSD: initialize copy->cp_clp early in nfsd4_copy for use by trace > point > > This patch is a prerequisite for > [PATCH v2 1/1] NFSD: add trace points to track server copy progress > > Sorry for the confusion. > > -Dai > Hi, Dai [PATCH v2 1/1] NFSD: add trace points to track server copy progress work as expected with: [PATCH 1/2] NFSD: initialize copy->cp_clp early in nfsd4_copy for use by trace So Tested-by: Chen Hanxiao <chenhx.fnst@fujitsu.com> Regards, - Chen
diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c index 62f6aba6140b..cac4528faa73 100644 --- a/fs/nfsd/nfs4proc.c +++ b/fs/nfsd/nfs4proc.c @@ -1760,6 +1760,7 @@ static int nfsd4_do_async_copy(void *data) struct nfsd4_copy *copy = (struct nfsd4_copy *)data; __be32 nfserr; + trace_nfsd_copy_do_async(copy); if (nfsd4_ssc_is_inter(copy)) { struct file *filp; @@ -1800,17 +1801,23 @@ nfsd4_copy(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, copy->cp_clp = cstate->clp; if (nfsd4_ssc_is_inter(copy)) { + trace_nfsd_copy_inter(copy); if (!inter_copy_offload_enable || nfsd4_copy_is_sync(copy)) { status = nfserr_notsupp; goto out; } status = nfsd4_setup_inter_ssc(rqstp, cstate, copy); - if (status) + if (status) { + trace_nfsd_copy_done(copy, status); return nfserr_offload_denied; + } } else { + trace_nfsd_copy_intra(copy); status = nfsd4_setup_intra_ssc(rqstp, cstate, copy); - if (status) + if (status) { + trace_nfsd_copy_done(copy, status); return status; + } } memcpy(©->fh, &cstate->current_fh.fh_handle, @@ -1847,6 +1854,7 @@ nfsd4_copy(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, copy->nf_dst->nf_file, true); } out: + trace_nfsd_copy_done(copy, status); release_copy_files(copy); return status; out_err: diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h index 803904348871..fbc0ccb40424 100644 --- a/fs/nfsd/trace.h +++ b/fs/nfsd/trace.h @@ -1863,6 +1863,93 @@ TRACE_EVENT(nfsd_end_grace, ) ); +DECLARE_EVENT_CLASS(nfsd_copy_class, + TP_PROTO( + const struct nfsd4_copy *copy + ), + TP_ARGS(copy), + TP_STRUCT__entry( + __field(bool, intra) + __field(bool, async) + __field(u32, src_cl_boot) + __field(u32, src_cl_id) + __field(u32, src_so_id) + __field(u32, src_si_generation) + __field(u32, dst_cl_boot) + __field(u32, dst_cl_id) + __field(u32, dst_so_id) + __field(u32, dst_si_generation) + __field(u64, src_cp_pos) + __field(u64, dst_cp_pos) + __field(u64, cp_count) + __sockaddr(addr, sizeof(struct sockaddr_in6)) + ), + TP_fast_assign( + const stateid_t *src_stp = ©->cp_src_stateid; + const stateid_t *dst_stp = ©->cp_dst_stateid; + + __entry->intra = test_bit(NFSD4_COPY_F_INTRA, ©->cp_flags); + __entry->async = !test_bit(NFSD4_COPY_F_SYNCHRONOUS, ©->cp_flags); + __entry->src_cl_boot = src_stp->si_opaque.so_clid.cl_boot; + __entry->src_cl_id = src_stp->si_opaque.so_clid.cl_id; + __entry->src_so_id = src_stp->si_opaque.so_id; + __entry->src_si_generation = src_stp->si_generation; + __entry->dst_cl_boot = dst_stp->si_opaque.so_clid.cl_boot; + __entry->dst_cl_id = dst_stp->si_opaque.so_clid.cl_id; + __entry->dst_so_id = dst_stp->si_opaque.so_id; + __entry->dst_si_generation = dst_stp->si_generation; + __entry->src_cp_pos = copy->cp_src_pos; + __entry->dst_cp_pos = copy->cp_dst_pos; + __entry->cp_count = copy->cp_count; + __assign_sockaddr(addr, ©->cp_clp->cl_addr, + sizeof(struct sockaddr_in6)); + ), + TP_printk("client=%pISpc intra=%d async=%d " + "src_stateid[si_generation:0x%x cl_boot:0x%x cl_id:0x%x so_id:0x%x] " + "dst_stateid[si_generation:0x%x cl_boot:0x%x cl_id:0x%x so_id:0x%x] " + "cp_src_pos=%llu cp_dst_pos=%llu cp_count=%llu", + __get_sockaddr(addr), __entry->intra, __entry->async, + __entry->src_si_generation, __entry->src_cl_boot, + __entry->src_cl_id, __entry->src_so_id, + __entry->dst_si_generation, __entry->dst_cl_boot, + __entry->dst_cl_id, __entry->dst_so_id, + __entry->src_cp_pos, __entry->dst_cp_pos, __entry->cp_count + ) +); + +#define DEFINE_COPY_EVENT(name) \ +DEFINE_EVENT(nfsd_copy_class, nfsd_copy_##name, \ + TP_PROTO(const struct nfsd4_copy *copy), \ + TP_ARGS(copy)) + +DEFINE_COPY_EVENT(inter); +DEFINE_COPY_EVENT(intra); +DEFINE_COPY_EVENT(do_async); + +TRACE_EVENT(nfsd_copy_done, + TP_PROTO( + const struct nfsd4_copy *copy, + __be32 status + ), + TP_ARGS(copy, status), + TP_STRUCT__entry( + __field(int, status) + __field(bool, intra) + __field(bool, async) + __sockaddr(addr, sizeof(struct sockaddr_in6)) + ), + TP_fast_assign( + __entry->status = be32_to_cpu(status); + __entry->intra = test_bit(NFSD4_COPY_F_INTRA, ©->cp_flags); + __entry->async = !test_bit(NFSD4_COPY_F_SYNCHRONOUS, ©->cp_flags); + __assign_sockaddr(addr, ©->cp_clp->cl_addr, + sizeof(struct sockaddr_in6)); + ), + TP_printk("addr=%pISpc status=%d intra=%d async=%d ", + __get_sockaddr(addr), __entry->status, __entry->intra, __entry->async + ) +); + #endif /* _NFSD_TRACE_H */ #undef TRACE_INCLUDE_PATH
Add trace points on destination server to track inter and intra server copy operations. Signed-off-by: Dai Ngo <dai.ngo@oracle.com> --- v2: rename trace points from nfsd4_trace_... to nfsd_trace_... fix kernel test robot by removing ifdef CONFIG_NFS_V4_2 in trace.h fs/nfsd/nfs4proc.c | 12 +++++-- fs/nfsd/trace.h | 87 ++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 97 insertions(+), 2 deletions(-)