Re: [PATCH v2 6/6] ceph: print the client global_id in all the debug logs

[Xiubo Li <xiubli@redhat.com>]

On 6/14/23 05:50, Ilya Dryomov wrote:
> On Tue, Jun 13, 2023 at 11:51 AM Xiubo Li <xiubli@redhat.com> wrote:
>>
>> On 6/13/23 17:07, Ilya Dryomov wrote:
>>> On Mon, Jun 12, 2023 at 1:46 PM <xiubli@redhat.com> wrote:
>>>> From: Xiubo Li <xiubli@redhat.com>
>>>>
>>>> Multiple cephfs mounts on a host is increasingly common so disambiguating
>>>> messages like this is necessary and will make it easier to debug
>>>> issues.
>>>>
>>>> URL: https://tracker.ceph.com/issues/61590
>>>> Cc: Patrick Donnelly <pdonnell@redhat.com>
>>>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>>>> ---
>>>>    fs/ceph/acl.c        |   6 +-
>>>>    fs/ceph/addr.c       | 300 ++++++++++--------
>>>>    fs/ceph/caps.c       | 709 ++++++++++++++++++++++++-------------------
>>>>    fs/ceph/crypto.c     |  45 ++-
>>>>    fs/ceph/debugfs.c    |   4 +-
>>>>    fs/ceph/dir.c        | 222 +++++++++-----
>>>>    fs/ceph/export.c     |  39 ++-
>>>>    fs/ceph/file.c       | 268 +++++++++-------
>>>>    fs/ceph/inode.c      | 528 ++++++++++++++++++--------------
>>>>    fs/ceph/ioctl.c      |  10 +-
>>>>    fs/ceph/locks.c      |  62 ++--
>>>>    fs/ceph/mds_client.c | 616 +++++++++++++++++++++----------------
>>>>    fs/ceph/mdsmap.c     |  25 +-
>>>>    fs/ceph/metric.c     |   5 +-
>>>>    fs/ceph/quota.c      |  31 +-
>>>>    fs/ceph/snap.c       | 186 +++++++-----
>>>>    fs/ceph/super.c      |  64 ++--
>>>>    fs/ceph/xattr.c      |  97 +++---
>>>>    18 files changed, 1887 insertions(+), 1330 deletions(-)
>>>>
>>>> diff --git a/fs/ceph/acl.c b/fs/ceph/acl.c
>>>> index 8a56f979c7cb..970acd07908d 100644
>>>> --- a/fs/ceph/acl.c
>>>> +++ b/fs/ceph/acl.c
>>>> @@ -15,6 +15,7 @@
>>>>    #include <linux/slab.h>
>>>>
>>>>    #include "super.h"
>>>> +#include "mds_client.h"
>>>>
>>>>    static inline void ceph_set_cached_acl(struct inode *inode,
>>>>                                           int type, struct posix_acl *acl)
>>>> @@ -31,6 +32,7 @@ static inline void ceph_set_cached_acl(struct inode *inode,
>>>>
>>>>    struct posix_acl *ceph_get_acl(struct inode *inode, int type, bool rcu)
>>>>    {
>>>> +       struct ceph_client *cl = ceph_inode_to_client(inode);
>>>>           int size;
>>>>           unsigned int retry_cnt = 0;
>>>>           const char *name;
>>>> @@ -72,8 +74,8 @@ struct posix_acl *ceph_get_acl(struct inode *inode, int type, bool rcu)
>>>>           } else if (size == -ENODATA || size == 0) {
>>>>                   acl = NULL;
>>>>           } else {
>>>> -               pr_err_ratelimited("get acl %llx.%llx failed, err=%d\n",
>>>> -                                  ceph_vinop(inode), size);
>>>> +               pr_err_ratelimited_client(cl, "%s %llx.%llx failed, err=%d\n",
>>>> +                                         __func__, ceph_vinop(inode), size);
>>>>                   acl = ERR_PTR(-EIO);
>>>>           }
>>>>
>>>> diff --git a/fs/ceph/addr.c b/fs/ceph/addr.c
>>>> index e62318b3e13d..c772639dc0cb 100644
>>>> --- a/fs/ceph/addr.c
>>>> +++ b/fs/ceph/addr.c
>>>> @@ -79,18 +79,18 @@ static inline struct ceph_snap_context *page_snap_context(struct page *page)
>>>>     */
>>>>    static bool ceph_dirty_folio(struct address_space *mapping, struct folio *folio)
>>>>    {
>>>> -       struct inode *inode;
>>>> +       struct inode *inode = mapping->host;
>>>> +       struct ceph_client *cl = ceph_inode_to_client(inode);
>>>>           struct ceph_inode_info *ci;
>>>>           struct ceph_snap_context *snapc;
>>>>
>>>>           if (folio_test_dirty(folio)) {
>>>> -               dout("%p dirty_folio %p idx %lu -- already dirty\n",
>>>> -                    mapping->host, folio, folio->index);
>>>> +               dout_client(cl, "%s %llx.%llx %p idx %lu -- already dirty\n",
>>>> +                           __func__, ceph_vinop(inode), folio, folio->index);
>>> While having context information attached to each dout is nice, it
>>> certainly comes at a price of a lot of churn and automated backport
>>> disruption.
>> Yeah, certainly this will break automated backporting. But this should
>> be okay, I can generate the backport patches for each stable release for
>> this patch series, so after this it will make the automated backporting
>> work.
>>
>>>    I wonder how much value doing this for douts as opposed
>>> to just pr_* messages actually brings?
>> I think the 'dout()' was introduced by printing more context info, which
>> includes module/function names and line#, when the
>> CONFIG_CEPH_LIB_PRETTYDEBUG is enabled.
> dout() is just a wrapper around pr_debug().  It doesn't have anything
> to do with CONFIG_CEPH_LIB_PRETTYDEBUG per se which adds file names and
> line numbers.  IIRC dout() by itself just adds a space at the front to
> make debugging spew stand out.
>
>> Maybe we can remove CONFIG_CEPH_LIB_PRETTYDEBUG now, since the pr_* will
>> print the module name and also the caller for dout() and pr_* will print
>> the function name mostly ?
> To the best of my knowledge, CONFIG_CEPH_LIB_PRETTYDEBUG has always
> been disabled by default and it's not enabled by any distribution in
> their kernels.  I don't think anyone out there would miss it, but then
> it's not hurting either -- it's less than 20 lines of code with all
> ifdef-ery included.

Okay. I won't touch it.

Thanks


> Thanks,
>
>                  Ilya
>