On Tue, Jun 11, 2019 at 3:37 PM Chuck Lever <chuck.lever@xxxxxxxxxx> wrote:
>
>
>
> > 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".
Unfortunately, "error=" but not "error=0" isn't easily translated into
the vi search... ("error=-" was more convenient).
Can we keep the value of the error= negative but change it to the
positive value for the show_nfsv4_errors()?
> >> 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
>
>
>
