> On Jun 11, 2019, at 3:33 PM, Olga Kornievskaia <aglo@xxxxxxxxx> wrote:
>
> On Tue, Jun 11, 2019 at 11:09 AM Chuck Lever <chuck.lever@xxxxxxxxxx> wrote:
>>
>> I noticed that NFS status values stopped working again.
>>
>> trace_print_symbols_seq() takes an unsigned long. Passing a negative
>> errno or negative NFSERR value just confuses it, and since we're
>> using C macros here and not static inline functions, all bets are
>> off due to implicit type casting.
>>
>> Straight-line the calling conventions so that error codes are stored
>> in the trace record as positive values in an unsigned long field.
>>
>> It's often the case that an error value that is positive is a byte
>> count but when it's negative, it's an error (e.g. nfs4_write). Fix
>> those cases so that the value that is eventually stored in the
>> error field is a positive NFS status or errno, or zero.
>>
>
> Hi Chuck,
>
> To clarify, so on error case, we no longer going be seeing a negative
> value so error=-5 (EIO) would be error=5 (EIO)? I have always relied
> on searching for "error=-" thru the trace_pipe log for errors. Do we
> really need to change that?
error= will be zero or a positive errno/status code. If the trace point
has a count= or task->tk_status= you can see the byte count when
error=0.
So now the search will be for anything that has "error=" but is not
"error=0".
>> Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
>> ---
>> fs/nfs/nfs4trace.h | 120 ++++++++++++++++++++++++++--------------------------
>> 1 file changed, 60 insertions(+), 60 deletions(-)
>>
>> diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h
>> index 6beb1f2..9a01731 100644
>> --- a/fs/nfs/nfs4trace.h
>> +++ b/fs/nfs/nfs4trace.h
>> @@ -156,7 +156,7 @@
>> TRACE_DEFINE_ENUM(NFS4ERR_XDEV);
>>
>> #define show_nfsv4_errors(error) \
>> - __print_symbolic(-(error), \
>> + __print_symbolic(error, \
>> { NFS4_OK, "OK" }, \
>> /* Mapped by nfs4_stat_to_errno() */ \
>> { EPERM, "EPERM" }, \
>> @@ -348,7 +348,7 @@
>>
>> TP_STRUCT__entry(
>> __string(dstaddr, clp->cl_hostname)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -357,7 +357,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) dstaddr=%s",
>> + "error=%lu (%s) dstaddr=%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> __get_str(dstaddr)
>> @@ -420,7 +420,7 @@
>> __field(unsigned int, highest_slotid)
>> __field(unsigned int, target_highest_slotid)
>> __field(unsigned int, status_flags)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -435,7 +435,7 @@
>> __entry->error = res->sr_status;
>> ),
>> TP_printk(
>> - "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> + "error=%lu (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> "highest_slotid=%u target_highest_slotid=%u "
>> "status_flags=%u (%s)",
>> __entry->error,
>> @@ -467,7 +467,7 @@
>> __field(unsigned int, seq_nr)
>> __field(unsigned int, highest_slotid)
>> __field(unsigned int, cachethis)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -476,11 +476,11 @@
>> __entry->seq_nr = args->csa_sequenceid;
>> __entry->highest_slotid = args->csa_highestslotid;
>> __entry->cachethis = args->csa_cachethis;
>> - __entry->error = -be32_to_cpu(status);
>> + __entry->error = be32_to_cpu(status);
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> + "error=%lu (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> "highest_slotid=%u",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -504,7 +504,7 @@
>> __field(unsigned int, seq_nr)
>> __field(unsigned int, highest_slotid)
>> __field(unsigned int, cachethis)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -513,11 +513,11 @@
>> __entry->seq_nr = args->csa_sequenceid;
>> __entry->highest_slotid = args->csa_highestslotid;
>> __entry->cachethis = args->csa_cachethis;
>> - __entry->error = -be32_to_cpu(status);
>> + __entry->error = be32_to_cpu(status);
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> + "error=%lu (%s) session=0x%08x slot_nr=%u seq_nr=%u "
>> "highest_slotid=%u",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -572,18 +572,18 @@
>>
>> TP_STRUCT__entry(
>> __field(u32, op)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> __entry->op = op;
>> - __entry->error = -error;
>> + __entry->error = error;
>> ),
>>
>> TP_printk(
>> - "operation %d: nfs status %d (%s)",
>> - __entry->op,
>> - __entry->error, show_nfsv4_errors(__entry->error)
>> + "error=%lu (%s) operation %d:",
>> + __entry->error, show_nfsv4_errors(__entry->error),
>> + __entry->op
>> )
>> );
>>
>> @@ -597,7 +597,7 @@
>> TP_ARGS(ctx, flags, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(unsigned int, flags)
>> __field(unsigned int, fmode)
>> __field(dev_t, dev)
>> @@ -615,7 +615,7 @@
>> const struct nfs4_state *state = ctx->state;
>> const struct inode *inode = NULL;
>>
>> - __entry->error = error;
>> + __entry->error = -error;
>> __entry->flags = flags;
>> __entry->fmode = (__force unsigned int)ctx->mode;
>> __entry->dev = ctx->dentry->d_sb->s_dev;
>> @@ -647,7 +647,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) flags=%d (%s) fmode=%s "
>> + "error=%lu (%s) flags=%d (%s) fmode=%s "
>> "fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "name=%02x:%02x:%llu/%s stateid=%d:0x%08x "
>> "openstateid=%d:0x%08x",
>> @@ -733,7 +733,7 @@
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> __field(unsigned int, fmode)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> ),
>> @@ -753,7 +753,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fmode=%s fileid=%02x:%02x:%llu "
>> + "error=%lu (%s) fmode=%s fileid=%02x:%02x:%llu "
>> "fhandle=0x%08x openstateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -795,7 +795,7 @@
>> TP_ARGS(request, state, cmd, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, cmd)
>> __field(char, type)
>> __field(loff_t, start)
>> @@ -825,7 +825,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) cmd=%s:%s range=%lld:%lld "
>> + "error=%lu (%s) cmd=%s:%s range=%lld:%lld "
>> "fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "stateid=%d:0x%08x",
>> __entry->error,
>> @@ -865,7 +865,7 @@
>> TP_ARGS(request, state, lockstateid, cmd, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, cmd)
>> __field(char, type)
>> __field(loff_t, start)
>> @@ -901,7 +901,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) cmd=%s:%s range=%lld:%lld "
>> + "error=%lu (%s) cmd=%s:%s range=%lld:%lld "
>> "fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "stateid=%d:0x%08x lockstateid=%d:0x%08x",
>> __entry->error,
>> @@ -970,7 +970,7 @@
>> TP_STRUCT__entry(
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> ),
>> @@ -986,7 +986,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) dev=%02x:%02x fhandle=0x%08x "
>> + "error=%lu (%s) dev=%02x:%02x fhandle=0x%08x "
>> "stateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1007,7 +1007,7 @@
>> TP_ARGS(state, lsp, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> @@ -1029,7 +1029,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "stateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1064,7 +1064,7 @@
>>
>> TP_STRUCT__entry(
>> __field(dev_t, dev)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(u64, dir)
>> __string(name, name->name)
>> ),
>> @@ -1072,12 +1072,12 @@
>> TP_fast_assign(
>> __entry->dev = dir->i_sb->s_dev;
>> __entry->dir = NFS_FILEID(dir);
>> - __entry->error = error;
>> + __entry->error = -error;
>> __assign_str(name, name->name);
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) name=%02x:%02x:%llu/%s",
>> + "error=%lu (%s) name=%02x:%02x:%llu/%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> MAJOR(__entry->dev), MINOR(__entry->dev),
>> @@ -1114,7 +1114,7 @@
>> TP_STRUCT__entry(
>> __field(dev_t, dev)
>> __field(u64, ino)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -1124,7 +1124,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) inode=%02x:%02x:%llu",
>> + "error=%lu (%s) inode=%02x:%02x:%llu",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> MAJOR(__entry->dev), MINOR(__entry->dev),
>> @@ -1145,7 +1145,7 @@
>>
>> TP_STRUCT__entry(
>> __field(dev_t, dev)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(u64, olddir)
>> __string(oldname, oldname->name)
>> __field(u64, newdir)
>> @@ -1162,7 +1162,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) oldname=%02x:%02x:%llu/%s "
>> + "error=%lu (%s) oldname=%02x:%02x:%llu/%s "
>> "newname=%02x:%02x:%llu/%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1187,18 +1187,18 @@
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> __entry->dev = inode->i_sb->s_dev;
>> __entry->fileid = NFS_FILEID(inode);
>> __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode));
>> - __entry->error = error;
>> + __entry->error = error < 0 ? -error : 0;
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x",
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> MAJOR(__entry->dev), MINOR(__entry->dev),
>> @@ -1238,7 +1238,7 @@
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> ),
>> @@ -1255,7 +1255,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "stateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1295,7 +1295,7 @@
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> __field(unsigned int, valid)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -1307,7 +1307,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "valid=%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1342,7 +1342,7 @@
>> TP_ARGS(clp, fhandle, inode, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> @@ -1363,7 +1363,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "dstaddr=%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1397,7 +1397,7 @@
>> TP_ARGS(clp, fhandle, inode, stateid, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(dev_t, dev)
>> __field(u32, fhandle)
>> __field(u64, fileid)
>> @@ -1424,7 +1424,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "stateid=%d:0x%08x dstaddr=%s",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1460,7 +1460,7 @@
>> TP_ARGS(name, len, id, error),
>>
>> TP_STRUCT__entry(
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(u32, id)
>> __dynamic_array(char, name, len > 0 ? len + 1 : 1)
>> ),
>> @@ -1475,8 +1475,8 @@
>> ),
>>
>> TP_printk(
>> - "error=%d id=%u name=%s",
>> - __entry->error,
>> + "error=%lu (%s) id=%u name=%s",
>> + __entry->error, show_nfsv4_errors(__entry->error),
>> __entry->id,
>> __get_str(name)
>> )
>> @@ -1509,7 +1509,7 @@
>> __field(u64, fileid)
>> __field(loff_t, offset)
>> __field(size_t, count)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> ),
>> @@ -1523,7 +1523,7 @@
>> __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode));
>> __entry->offset = hdr->args.offset;
>> __entry->count = hdr->args.count;
>> - __entry->error = error;
>> + __entry->error = error < 0 ? -error : 0;
>> __entry->stateid_seq =
>> be32_to_cpu(state->stateid.seqid);
>> __entry->stateid_hash =
>> @@ -1531,7 +1531,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "offset=%lld count=%zu stateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1569,7 +1569,7 @@
>> __field(u64, fileid)
>> __field(loff_t, offset)
>> __field(size_t, count)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> ),
>> @@ -1583,7 +1583,7 @@
>> __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode));
>> __entry->offset = hdr->args.offset;
>> __entry->count = hdr->args.count;
>> - __entry->error = error;
>> + __entry->error = error < 0 ? -error : 0;
>> __entry->stateid_seq =
>> be32_to_cpu(state->stateid.seqid);
>> __entry->stateid_hash =
>> @@ -1591,7 +1591,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "offset=%lld count=%zu stateid=%d:0x%08x",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1630,7 +1630,7 @@
>> __field(u64, fileid)
>> __field(loff_t, offset)
>> __field(size_t, count)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> ),
>>
>> TP_fast_assign(
>> @@ -1644,7 +1644,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "offset=%lld count=%zu",
>> __entry->error,
>> show_nfsv4_errors(__entry->error),
>> @@ -1694,7 +1694,7 @@
>> __field(u32, iomode)
>> __field(u64, offset)
>> __field(u64, count)
>> - __field(int, error)
>> + __field(unsigned long, error)
>> __field(int, stateid_seq)
>> __field(u32, stateid_hash)
>> __field(int, layoutstateid_seq)
>> @@ -1727,7 +1727,7 @@
>> ),
>>
>> TP_printk(
>> - "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> + "error=%lu (%s) fileid=%02x:%02x:%llu fhandle=0x%08x "
>> "iomode=%s offset=%llu count=%llu stateid=%d:0x%08x "
>> "layoutstateid=%d:0x%08x",
>> __entry->error,
--
Chuck Lever
