afs: Better tracing of protocol errors

Include the site of detection of AFS protocol errors in trace lines to
better be able to determine what went wrong.

Signed-off-by: David Howells <dhowells@redhat.com>

diff --git a/fs/afs/cmservice.c b/fs/afs/cmservice.c
index 9e51d6fe7e8f975f34f877217a28a8e99bcfa5e4..58f79301a71647b094afcf76e1bba5775771f250 100644 (file)
--- a/fs/afs/cmservice.c
+++ b/fs/afs/cmservice.c
@@ -189,7 +189,8 @@ static int afs_deliver_cb_callback(struct afs_call *call)
                call->count = ntohl(call->tmp);
                _debug("FID count: %u", call->count);
                if (call->count > AFSCBMAX)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_cb_fid_count);
 
                call->buffer = kmalloc(array3_size(call->count, 3, 4),
                                       GFP_KERNEL);
@@ -234,7 +235,8 @@ static int afs_deliver_cb_callback(struct afs_call *call)
                call->count2 = ntohl(call->tmp);
                _debug("CB count: %u", call->count2);
                if (call->count2 != call->count && call->count2 != 0)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_cb_count);
                call->offset = 0;
                call->unmarshall++;
 

diff --git a/fs/afs/fsclient.c b/fs/afs/fsclient.c
index 50929cb91732f5adec19706788e6a31aeb8beb03..d9a5815945dcdbb4bbf3524a8e636cb21c55ee9c 100644 (file)
--- a/fs/afs/fsclient.c
+++ b/fs/afs/fsclient.c
@@ -233,7 +233,7 @@ static int xdr_decode_AFSFetchStatus(struct afs_call *call,
 
 bad:
        xdr_dump_bad(*_bp);
-       return afs_protocol_error(call, -EBADMSG);
+       return afs_protocol_error(call, -EBADMSG, afs_eproto_bad_status);
 }
 
 /*
@@ -399,9 +399,10 @@ static int afs_deliver_fs_fetch_status_vnode(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        xdr_decode_AFSCallBack(call, vnode, &bp);
        if (call->reply[1])
                xdr_decode_AFSVolSync(&bp, call->reply[1]);
@@ -580,9 +581,10 @@ static int afs_deliver_fs_fetch_data(struct afs_call *call)
                        return ret;
 
                bp = call->buffer;
-               if (afs_decode_status(call, &bp, &vnode->status, vnode,
-                                     &vnode->status.data_version, req) < 0)
-                       return afs_protocol_error(call, -EBADMSG);
+               ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                                       &vnode->status.data_version, req);
+               if (ret < 0)
+                       return ret;
                xdr_decode_AFSCallBack(call, vnode, &bp);
                if (call->reply[1])
                        xdr_decode_AFSVolSync(&bp, call->reply[1]);
@@ -733,10 +735,13 @@ static int afs_deliver_fs_create_vnode(struct afs_call *call)
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
        xdr_decode_AFSFid(&bp, call->reply[1]);
-       if (afs_decode_status(call, &bp, call->reply[2], NULL, NULL, NULL) < 0 ||
-           afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, call->reply[2], NULL, NULL, NULL);
+       if (ret < 0)
+               return ret;
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        xdr_decode_AFSCallBack_raw(&bp, call->reply[3]);
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
@@ -839,9 +844,10 @@ static int afs_deliver_fs_remove(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        _leave(" = 0 [done]");
@@ -929,10 +935,13 @@ static int afs_deliver_fs_link(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &vnode->status, vnode, NULL, NULL) < 0 ||
-           afs_decode_status(call, &bp, &dvnode->status, dvnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode, NULL, NULL);
+       if (ret < 0)
+               return ret;
+       ret = afs_decode_status(call, &bp, &dvnode->status, dvnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        _leave(" = 0 [done]");
@@ -1016,10 +1025,13 @@ static int afs_deliver_fs_symlink(struct afs_call *call)
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
        xdr_decode_AFSFid(&bp, call->reply[1]);
-       if (afs_decode_status(call, &bp, call->reply[2], NULL, NULL, NULL) ||
-           afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, call->reply[2], NULL, NULL, NULL);
+       if (ret < 0)
+               return ret;
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        _leave(" = 0 [done]");
@@ -1122,13 +1134,16 @@ static int afs_deliver_fs_rename(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &orig_dvnode->status, orig_dvnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
-       if (new_dvnode != orig_dvnode &&
-           afs_decode_status(call, &bp, &new_dvnode->status, new_dvnode,
-                             &call->expected_version_2, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &orig_dvnode->status, orig_dvnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
+       if (new_dvnode != orig_dvnode) {
+               ret = afs_decode_status(call, &bp, &new_dvnode->status, new_dvnode,
+                                       &call->expected_version_2, NULL);
+               if (ret < 0)
+                       return ret;
+       }
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        _leave(" = 0 [done]");
@@ -1231,9 +1246,10 @@ static int afs_deliver_fs_store_data(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        afs_pages_written_back(vnode, call);
@@ -1407,9 +1423,10 @@ static int afs_deliver_fs_store_status(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       if (afs_decode_status(call, &bp, &vnode->status, vnode,
-                             &call->expected_version, NULL) < 0)
-               return afs_protocol_error(call, -EBADMSG);
+       ret = afs_decode_status(call, &bp, &vnode->status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        /* xdr_decode_AFSVolSync(&bp, call->reply[X]); */
 
        _leave(" = 0 [done]");
@@ -1612,7 +1629,8 @@ static int afs_deliver_fs_get_volume_status(struct afs_call *call)
                call->count = ntohl(call->tmp);
                _debug("volname length: %u", call->count);
                if (call->count >= AFSNAMEMAX)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_volname_len);
                call->offset = 0;
                call->unmarshall++;
 
@@ -1659,7 +1677,8 @@ static int afs_deliver_fs_get_volume_status(struct afs_call *call)
                call->count = ntohl(call->tmp);
                _debug("offline msg length: %u", call->count);
                if (call->count >= AFSNAMEMAX)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_offline_msg_len);
                call->offset = 0;
                call->unmarshall++;
 
@@ -1706,7 +1725,8 @@ static int afs_deliver_fs_get_volume_status(struct afs_call *call)
                call->count = ntohl(call->tmp);
                _debug("motd length: %u", call->count);
                if (call->count >= AFSNAMEMAX)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_motd_len);
                call->offset = 0;
                call->unmarshall++;
 
@@ -2109,8 +2129,10 @@ static int afs_deliver_fs_fetch_status(struct afs_call *call)
 
        /* unmarshall the reply once we've received all of it */
        bp = call->buffer;
-       afs_decode_status(call, &bp, status, vnode,
-                         &call->expected_version, NULL);
+       ret = afs_decode_status(call, &bp, status, vnode,
+                               &call->expected_version, NULL);
+       if (ret < 0)
+               return ret;
        callback[call->count].version   = ntohl(bp[0]);
        callback[call->count].expiry    = ntohl(bp[1]);
        callback[call->count].type      = ntohl(bp[2]);
@@ -2206,7 +2228,8 @@ static int afs_deliver_fs_inline_bulk_status(struct afs_call *call)
                tmp = ntohl(call->tmp);
                _debug("status count: %u/%u", tmp, call->count2);
                if (tmp != call->count2)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_ibulkst_count);
 
                call->count = 0;
                call->unmarshall++;
@@ -2221,10 +2244,11 @@ static int afs_deliver_fs_inline_bulk_status(struct afs_call *call)
 
                bp = call->buffer;
                statuses = call->reply[1];
-               if (afs_decode_status(call, &bp, &statuses[call->count],
-                                     call->count == 0 ? vnode : NULL,
-                                     NULL, NULL) < 0)
-                       return afs_protocol_error(call, -EBADMSG);
+               ret = afs_decode_status(call, &bp, &statuses[call->count],
+                                       call->count == 0 ? vnode : NULL,
+                                       NULL, NULL);
+               if (ret < 0)
+                       return ret;
 
                call->count++;
                if (call->count < call->count2)
@@ -2244,7 +2268,8 @@ static int afs_deliver_fs_inline_bulk_status(struct afs_call *call)
                tmp = ntohl(call->tmp);
                _debug("CB count: %u", tmp);
                if (tmp != call->count2)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_ibulkst_cb_count);
                call->count = 0;
                call->unmarshall++;
        more_cbs:

diff --git a/fs/afs/inode.c b/fs/afs/inode.c
index 479b7fdda1244f5bf210694e275826cba99b5553..ab4e7a15c205acdf5de48031bb713d801bc6ce75 100644 (file)
--- a/fs/afs/inode.c
+++ b/fs/afs/inode.c
@@ -82,7 +82,7 @@ static int afs_inode_init_from_status(struct afs_vnode *vnode, struct key *key)
        default:
                printk("kAFS: AFS vnode with undefined type\n");
                read_sequnlock_excl(&vnode->cb_lock);
-               return afs_protocol_error(NULL, -EBADMSG);
+               return afs_protocol_error(NULL, -EBADMSG, afs_eproto_file_type);
        }
 
        inode->i_blocks         = 0;

diff --git a/fs/afs/internal.h b/fs/afs/internal.h
index 72de1f157d20235b4c2a103d5f098b5b9cf7dd1f..73770a2a231129d3ae4dbe09b8328e3d7ffe93e4 100644 (file)
--- a/fs/afs/internal.h
+++ b/fs/afs/internal.h
@@ -931,7 +931,7 @@ extern void afs_flat_call_destructor(struct afs_call *);
 extern void afs_send_empty_reply(struct afs_call *);
 extern void afs_send_simple_reply(struct afs_call *, const void *, size_t);
 extern int afs_extract_data(struct afs_call *, void *, size_t, bool);
-extern int afs_protocol_error(struct afs_call *, int);
+extern int afs_protocol_error(struct afs_call *, int, enum afs_eproto_cause);
 
 static inline int afs_transfer_reply(struct afs_call *call)
 {

diff --git a/fs/afs/rxrpc.c b/fs/afs/rxrpc.c
index 639c16882e93259f0724af24c3dcac157ecb8156..9757c2d953f13484adab71d7646ad21acfdd19bd 100644 (file)
--- a/fs/afs/rxrpc.c
+++ b/fs/afs/rxrpc.c
@@ -939,8 +939,9 @@ int afs_extract_data(struct afs_call *call, void *buf, size_t count,
 /*
  * Log protocol error production.
  */
-noinline int afs_protocol_error(struct afs_call *call, int error)
+noinline int afs_protocol_error(struct afs_call *call, int error,
+                               enum afs_eproto_cause cause)
 {
-       trace_afs_protocol_error(call, error, __builtin_return_address(0));
+       trace_afs_protocol_error(call, error, cause);
        return error;
 }

diff --git a/fs/afs/vlclient.c b/fs/afs/vlclient.c
index c3b740813fc719850ca188f892d4f653352e8600..d0f95c4ab05edad508db0d451bb828ded97ca624 100644 (file)
--- a/fs/afs/vlclient.c
+++ b/fs/afs/vlclient.c
@@ -451,7 +451,8 @@ again:
                call->count2    = ntohl(*bp); /* Type or next count */
 
                if (call->count > YFS_MAXENDPOINTS)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_fsendpt_num);
 
                alist = afs_alloc_addrlist(call->count, FS_SERVICE, AFS_FS_PORT);
                if (!alist)
@@ -475,7 +476,8 @@ again:
                        size = sizeof(__be32) * (1 + 4 + 1);
                        break;
                default:
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_fsendpt_type);
                }
 
                size += sizeof(__be32);
@@ -488,18 +490,21 @@ again:
                switch (call->count2) {
                case YFS_ENDPOINT_IPV4:
                        if (ntohl(bp[0]) != sizeof(__be32) * 2)
-                               return afs_protocol_error(call, -EBADMSG);
+                               return afs_protocol_error(call, -EBADMSG,
+                                                         afs_eproto_yvl_fsendpt4_len);
                        afs_merge_fs_addr4(alist, bp[1], ntohl(bp[2]));
                        bp += 3;
                        break;
                case YFS_ENDPOINT_IPV6:
                        if (ntohl(bp[0]) != sizeof(__be32) * 5)
-                               return afs_protocol_error(call, -EBADMSG);
+                               return afs_protocol_error(call, -EBADMSG,
+                                                         afs_eproto_yvl_fsendpt6_len);
                        afs_merge_fs_addr6(alist, bp + 1, ntohl(bp[5]));
                        bp += 6;
                        break;
                default:
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_fsendpt_type);
                }
 
                /* Got either the type of the next entry or the count of
@@ -518,7 +523,8 @@ again:
                if (!call->count)
                        goto end;
                if (call->count > YFS_MAXENDPOINTS)
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_vlendpt_type);
 
                call->unmarshall = 3;
 
@@ -546,7 +552,8 @@ again:
                        size = sizeof(__be32) * (1 + 4 + 1);
                        break;
                default:
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_vlendpt_type);
                }
 
                if (call->count > 1)
@@ -559,16 +566,19 @@ again:
                switch (call->count2) {
                case YFS_ENDPOINT_IPV4:
                        if (ntohl(bp[0]) != sizeof(__be32) * 2)
-                               return afs_protocol_error(call, -EBADMSG);
+                               return afs_protocol_error(call, -EBADMSG,
+                                                         afs_eproto_yvl_vlendpt4_len);
                        bp += 3;
                        break;
                case YFS_ENDPOINT_IPV6:
                        if (ntohl(bp[0]) != sizeof(__be32) * 5)
-                               return afs_protocol_error(call, -EBADMSG);
+                               return afs_protocol_error(call, -EBADMSG,
+                                                         afs_eproto_yvl_vlendpt6_len);
                        bp += 6;
                        break;
                default:
-                       return afs_protocol_error(call, -EBADMSG);
+                       return afs_protocol_error(call, -EBADMSG,
+                                                 afs_eproto_yvl_vlendpt_type);
                }
 
                /* Got either the type of the next entry or the count of

diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h
index d0a341bc45404b06c08f434d26030dd8be3138db..5c60ade2c7d88263f648cf299131f5a905c40761 100644 (file)
--- a/include/trace/events/afs.h
+++ b/include/trace/events/afs.h
@@ -84,6 +84,25 @@ enum afs_edit_dir_reason {
        afs_edit_dir_for_unlink,
 };
 
+enum afs_eproto_cause {
+       afs_eproto_bad_status,
+       afs_eproto_cb_count,
+       afs_eproto_cb_fid_count,
+       afs_eproto_file_type,
+       afs_eproto_ibulkst_cb_count,
+       afs_eproto_ibulkst_count,
+       afs_eproto_motd_len,
+       afs_eproto_offline_msg_len,
+       afs_eproto_volname_len,
+       afs_eproto_yvl_fsendpt4_len,
+       afs_eproto_yvl_fsendpt6_len,
+       afs_eproto_yvl_fsendpt_num,
+       afs_eproto_yvl_fsendpt_type,
+       afs_eproto_yvl_vlendpt4_len,
+       afs_eproto_yvl_vlendpt6_len,
+       afs_eproto_yvl_vlendpt_type,
+};
+
 #endif /* end __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY */
 
 /*
@@ -146,6 +165,24 @@ enum afs_edit_dir_reason {
        EM(afs_edit_dir_for_symlink,            "Symlnk") \
        E_(afs_edit_dir_for_unlink,             "Unlink")
 
+#define afs_eproto_causes                      \
+       EM(afs_eproto_bad_status,       "BadStatus") \
+       EM(afs_eproto_cb_count,         "CbCount") \
+       EM(afs_eproto_cb_fid_count,     "CbFidCount") \
+       EM(afs_eproto_file_type,        "FileTYpe") \
+       EM(afs_eproto_ibulkst_cb_count, "IBS.CbCount") \
+       EM(afs_eproto_ibulkst_count,    "IBS.FidCount") \
+       EM(afs_eproto_motd_len,         "MotdLen") \
+       EM(afs_eproto_offline_msg_len,  "OfflineMsgLen") \
+       EM(afs_eproto_volname_len,      "VolNameLen") \
+       EM(afs_eproto_yvl_fsendpt4_len, "YVL.FsEnd4Len") \
+       EM(afs_eproto_yvl_fsendpt6_len, "YVL.FsEnd6Len") \
+       EM(afs_eproto_yvl_fsendpt_num,  "YVL.FsEndCount") \
+       EM(afs_eproto_yvl_fsendpt_type, "YVL.FsEndType") \
+       EM(afs_eproto_yvl_vlendpt4_len, "YVL.VlEnd4Len") \
+       EM(afs_eproto_yvl_vlendpt6_len, "YVL.VlEnd6Len") \
+       E_(afs_eproto_yvl_vlendpt_type, "YVL.VlEndType")
+
 
 /*
  * Export enum symbols via userspace.
@@ -555,24 +592,25 @@ TRACE_EVENT(afs_edit_dir,
            );
 
 TRACE_EVENT(afs_protocol_error,
-           TP_PROTO(struct afs_call *call, int error, const void *where),
+           TP_PROTO(struct afs_call *call, int error, enum afs_eproto_cause cause),
 
-           TP_ARGS(call, error, where),
+           TP_ARGS(call, error, cause),
 
            TP_STRUCT__entry(
-                   __field(unsigned int,       call            )
-                   __field(int,                error           )
-                   __field(const void *,       where           )
+                   __field(unsigned int,               call            )
+                   __field(int,                        error           )
+                   __field(enum afs_eproto_cause,      cause           )
                             ),
 
            TP_fast_assign(
                    __entry->call = call ? call->debug_id : 0;
                    __entry->error = error;
-                   __entry->where = where;
+                   __entry->cause = cause;
                           ),
 
-           TP_printk("c=%08x r=%d sp=%pSR",
-                     __entry->call, __entry->error, __entry->where)
+           TP_printk("c=%08x r=%d %s",
+                     __entry->call, __entry->error,
+                     __print_symbolic(__entry->cause, afs_eproto_causes))
            );
 
 TRACE_EVENT(afs_cm_no_server,