> On Jan 4, 2018, at 2:36 PM, Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
>
> On Thu, 4 Jan 2018 14:10:21 -0500
> Chuck Lever <chuck.lever@xxxxxxxxxx> wrote:
>
>>>> #define nfs_show_stable(stable) \
>>>> __print_symbolic(stable, \
>>>> { NFS_UNSTABLE, " (UNSTABLE)" }, \
>>>> { NFS_DATA_SYNC, " (DATA_SYNC)" }, \
>>>> { NFS_FILE_SYNC, " (FILE_SYNC)" })
>>>>
>>>> When the field contains 0 it displays "(UNSTABLE)", and when the field
>>>> contains a non-zero value the displayed symbol is blank.
>>> nfs_initiate_write,
>>> Can you show my what is in
>
> Are you sure that it isn't another number there?
>
>>>
>>> /sys/kernel/debug/tracing/events/nfs/nfs_initiate_write/format
>>
>> This is with current v4.15-rc6 code base:
>>
>> name: nfs_initiate_write
>> ID: 1818
>> format:
>> field:unsigned short common_type; offset:0; size:2; signed:0;
>> field:unsigned char common_flags; offset:2; size:1; signed:0;
>> field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
>> field:int common_pid; offset:4; size:4; signed:1;
>>
>> field:loff_t offset; offset:8; size:8; signed:1;
>> field:unsigned long count; offset:16; size:8; signed:0;
>> field:enum nfs3_stable_how stable; offset:24; size:4; signed:1;
>> field:dev_t dev; offset:28; size:4; signed:0;
>> field:u32 fhandle; offset:32; size:4; signed:0;
>> field:u64 fileid; offset:40; size:8; signed:0;
>>
>> print fmt: "fileid=%02x:%02x:%llu fhandle=0x%08x offset=%lld count=%lu stable=%d%s", ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1))), (unsigned long long)REC->fileid, REC->fhandle, REC->offset, REC->count, REC->stable, __print_symbolic(REC->stable, { 0, " (UNSTABLE)" }, { 1, " (DATA_SYNC)" }, { 2, " (FILE_SYNC)" })
>
> This looks like it should work fine.
>
> Can you try this:
>
> trace-cmd record -e nfs_initiate_write
>
> do stuff to trigger the event, then hit Ctrl^C
>
> See if "trace-cmd report" shows it. If not do:
>
> trace-cmd report -R
>
> Which will suppress the translation of the output and show you the raw
> values. That way, you will see what is in the stable field.
This is with:
TRACE_DEFINE_ENUM(NFS_UNSTABLE);
TRACE_DEFINE_ENUM(NFS_DATA_SYNC);
TRACE_DEFINE_ENUM(NFS_FILE_SYNC);
#define nfs_show_stable(stable) \
__print_symbolic(stable, \
{ NFS_UNSTABLE, "NFS_UNSTABLE" }, \
{ NFS_DATA_SYNC, "NFS_DATA_SYNC" }, \
{ NFS_FILE_SYNC, "NFS_FILE_SYNC" })
Here's "cat /sys/kernel/debug/events/tracing/nfs/nfs_initiate_write/format" :
print_fmt: "fileid=%02x:%02x:%llu fhandle=0x%08x offset=%lld count=%lu stable=%d (%s)", ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1))), (unsigned long long)REC->fileid, REC->fhandle, REC->offset, REC->count, REC->stable, __print_symbolic(REC->stable, { 0, "NFS_UNSTABLE" }, { 1, "NFS_DATA_SYNC" }, { NFS_FILE_SYNC, "NFS_FILE_SYNC" })
The last element in the __print_symbolic table is wrong. For comparison,
here's an excerpt of "strings nfs.ko | grep NFS_FILE_SYNC" :
"fileid=%02x:%02x:%llu fhandle=0x%08x offset=%lld count=%lu stable=%d (%s)", ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1))), (unsigned long long)REC->fileid, REC->fhandle, REC->offset, REC->count, REC->stable, __print_symbolic(REC->stable, { NFS_UNSTABLE, "NFS_UNSTABLE" }, { NFS_DATA_SYNC, "NFS_DATA_SYNC" }, { NFS_FILE_SYNC, "NFS_FILE_SYNC" })
Note this copy of the table contains three symbolic names. I haven't been
able to find the code that adjusts the print_fmt string to understand the
difference with the output from "cat /sys/kernel ..." . But that code
doesn't seem to adjust the last element in the __print_symbolic table.
trace-cmd report
<...>-11353 [001] 6211.728494: nfs_initiate_write: fileid=00:2a:301409 fhandle=0x820b4b2e offset=0 count=601 stable=2 ()
<...>-11353 [004] 6211.728783: nfs_initiate_write: fileid=00:2a:301410 fhandle=0x0c844ccd offset=0 count=738 stable=2 ()
<...>-11353 [001] 6211.729023: nfs_initiate_write: fileid=00:2a:301411 fhandle=0xc02e4c53 offset=0 count=4015 stable=2 ()
<...>-11353 [005] 6211.729351: nfs_initiate_write: fileid=00:2a:301412 fhandle=0xcaeb454a offset=0 count=282 stable=2 ()
<...>-11353 [003] 6211.729651: nfs_initiate_write: fileid=00:2a:301413 fhandle=0x064145d4 offset=0 count=7688 stable=2 ()
trace-cmd report -R
<...>-11353 [001] 6211.728494: nfs_initiate_write: offset=0 count=0x259 stable=2 dev=42 fhandle=2181778222 fileid=301409
<...>-11353 [004] 6211.728783: nfs_initiate_write: offset=0 count=0x2e2 stable=2 dev=42 fhandle=209997005 fileid=301410
<...>-11353 [001] 6211.729023: nfs_initiate_write: offset=0 count=0xfaf stable=2 dev=42 fhandle=3224259667 fileid=301411
<...>-11353 [005] 6211.729351: nfs_initiate_write: offset=0 count=0x11a stable=2 dev=42 fhandle=3404416330 fileid=301412
<...>-11353 [003] 6211.729651: nfs_initiate_write: offset=0 count=0x1e08 stable=2 dev=42 fhandle=104941012 fileid=301413
Thanks for your advice!
--
Chuck Lever
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
