2018-10-07 15:23:14

by Rodrigo Freire

[permalink] [raw]
Subject: [PATCH v3 0/2] CIFS: Info-level log support, print message when attempting mount.

Hi Steve,
From our conversation over v2, I came out with this v3 patch, which I broke
in two commits:

* The first commit in cifs_debug.h, creating the cifs_info() function.
- The aim of this commit is to allow to the developer to be able to print
informational-level data without having to use pr_info, pr_notice etc,
in line with other filesystems.
. One interesting and noteworthy feature of cifs_info() is that it is
transparent to the CIFS_DEBUG config state, either in "y" or "n".
. Also, by using KERN_INFO level, it can be safely filtered by a
maintainer / administrator, without cluttering their log monitors,
since this is a low level alert.
- I took the liberty to not add it inside the existing pr_debug, because
of the eventual need of some developer to print stuff that should be
printed not only in CIFS_DEBUG mode (as there are plenty of pr_notice
scattered over the code).
- Also, this is not a debug but a info message, so i liked cifs_info()
more ;-)
- I saw plenty of pr_notice() in CIFS code, but I resisted the urge to
convert them to cifs_info().

* The second commit contains the code printing a cifs_info() when attempting
a CIFS mount operation.

Appreciate your review.

V3: Created a new cifs_info() function, moved the mount attempt message to
cifs_info

V2: Created a loop to select the right cifs_dbg message to be printed,
considering the current system's scenario, in order to avoid a
duplicate message or stripping out important information in
debug.

Rodrigo Freire (2):
CIFS: Adds information-level logging function
CIFS: Print message when attempting a mount

fs/cifs/cifs_debug.h | 16 ++++++++++++++++
fs/cifs/cifsfs.c | 7 ++++++-
fs/cifs/transport.c | 2 +-
3 files changed, 23 insertions(+), 2 deletions(-)

--
1.8.3.1



2018-10-07 15:22:04

by Rodrigo Freire

[permalink] [raw]
Subject: [PATCH v3 2/2] CIFS: Print message when attempting a mount

Currently, no messages are printed when mounting a CIFS filesystem and
no debug configuration is enabled.

However, a CIFS mount information is valuable when troubleshooting
and/or forensic analyzing a system and finding out if was a CIFS
endpoint mount attempted.

Other filesystems such as XFS, EXT* does issue a printk() when mounting
their filesystems.

A terse log message is printed only if cifsFYI is not enabled. Otherwise,
the default full debug message is printed.

In order to not clutter and classify correctly the event messages, these
are logged as KERN_INFO level.

Sample mount operations:

[root@corinthians ~]# mount -o user=administrator //172.25.250.18/c$ /mnt
(non-existent system)

[root@corinthians ~]# mount -o user=administrator //172.25.250.19/c$ /mnt
(Valid system)

Kernel message log for the mount operations:

[ 450.464543] CIFS: Attempting to mount //172.25.250.18/c$
[ 456.478186] CIFS VFS: Error connecting to socket. Aborting operation.
[ 456.478381] CIFS VFS: cifs_mount failed w/return code = -113
[ 467.688866] CIFS: Attempting to mount //172.25.250.19/c$

Signed-off-by: Rodrigo Freire <[email protected]>
---
fs/cifs/cifsfs.c | 7 ++++++-
fs/cifs/transport.c | 2 +-
2 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/fs/cifs/cifsfs.c b/fs/cifs/cifsfs.c
index 7065426..ebdf25e 100644
--- a/fs/cifs/cifsfs.c
+++ b/fs/cifs/cifsfs.c
@@ -707,7 +707,12 @@ static int cifs_set_super(struct super_block *sb, void *data)
struct cifs_mnt_data mnt_data;
struct dentry *root;

- cifs_dbg(FYI, "Devname: %s flags: %d\n", dev_name, flags);
+ /* Prints in Kernel / CIFS log the attempted mount operation *
+ * IF CIFS_DEBUG && cifs_FYI */
+ if (cifsFYI)
+ cifs_dbg(FYI, "Devname: %s flags: %d\n", dev_name, flags);
+ else
+ cifs_info("Attempting to mount %s\n", dev_name);

volume_info = cifs_get_volume_info((char *)data, dev_name, is_smb3);
if (IS_ERR(volume_info))
diff --git a/fs/cifs/transport.c b/fs/cifs/transport.c
index 78f96fa..c2afd6a 100644
--- a/fs/cifs/transport.c
+++ b/fs/cifs/transport.c
@@ -128,7 +128,7 @@ void cifs_mid_q_entry_release(struct mid_q_entry *midEntry)
if (cifsFYI & CIFS_TIMER) {
pr_debug(" CIFS slow rsp: cmd %d mid %llu",
midEntry->command, midEntry->mid);
- pr_info(" A: 0x%lx S: 0x%lx R: 0x%lx\n",
+ cifs_info(" A: 0x%lx S: 0x%lx R: 0x%lx\n",
now - midEntry->when_alloc,
now - midEntry->when_sent,
now - midEntry->when_received);
--
1.8.3.1


2018-10-07 15:22:22

by Rodrigo Freire

[permalink] [raw]
Subject: [PATCH v3 1/2] CIFS: Adds information-level logging function

Currently, CIFS lacks a internal logging function that prints out data
when CIFS_DEBUG=n. When CIFS_DEBUG=y, the only message level for CIFS
events are KERN_ERR or KERN_DEBUG.

This patch creates cifs_info(), which is useful for printing
non-critical event messges, at either CIFS_DEBUG state.

Signed-off-by: Rodrigo Freire <[email protected]>
---
fs/cifs/cifs_debug.h | 16 ++++++++++++++++
1 file changed, 16 insertions(+)

diff --git a/fs/cifs/cifs_debug.h b/fs/cifs/cifs_debug.h
index f4f3f08..72db298 100644
--- a/fs/cifs/cifs_debug.h
+++ b/fs/cifs/cifs_debug.h
@@ -47,6 +47,17 @@
*/
#ifdef CONFIG_CIFS_DEBUG

+/* Information level messages, minor events */
+#define cifs_info_func(ratefunc, fmt, ...) \
+do { \
+ pr_info_ ## ratefunc("CIFS: " fmt, ##__VA_ARGS__); \
+} while (0)
+
+#define cifs_info(fmt, ...) \
+do { \
+ cifs_info_func(ratelimited, fmt, ##__VA_ARGS__); \
+} while (0)
+
/* information message: e.g., configuration, major event */
#define cifs_dbg_func(ratefunc, type, fmt, ...) \
do { \
@@ -81,6 +92,11 @@
if (0) \
pr_debug(fmt, ##__VA_ARGS__); \
} while (0)
+
+#define cifs_info(fmt, ...) \
+do { \
+ pr_info("CIFS: "fmt, ##__VA_ARGS__); \
+} while (0)
#endif

#endif /* _H_CIFS_DEBUG */
--
1.8.3.1


2018-10-07 19:00:22

by Steve French

[permalink] [raw]
Subject: Re: [PATCH v3 0/2] CIFS: Info-level log support, print message when attempting mount.

Merged into cifs-2.6.git for-next

Made a trivial tab/space correction in the patch (pointed out by
checkpatch) and then added a trivial followon patch to address a
comment/style (trivial)
issue pointed out by checkpatch and to add a little more detailed
comments about generally when to use each debug function. If any
objections let me know.


On Sun, Oct 7, 2018 at 10:21 AM Rodrigo Freire <[email protected]> wrote:
>
> Hi Steve,
> From our conversation over v2, I came out with this v3 patch, which I broke
> in two commits:
>
> * The first commit in cifs_debug.h, creating the cifs_info() function.
> - The aim of this commit is to allow to the developer to be able to print
> informational-level data without having to use pr_info, pr_notice etc,
> in line with other filesystems.
> . One interesting and noteworthy feature of cifs_info() is that it is
> transparent to the CIFS_DEBUG config state, either in "y" or "n".
> . Also, by using KERN_INFO level, it can be safely filtered by a
> maintainer / administrator, without cluttering their log monitors,
> since this is a low level alert.
> - I took the liberty to not add it inside the existing pr_debug, because
> of the eventual need of some developer to print stuff that should be
> printed not only in CIFS_DEBUG mode (as there are plenty of pr_notice
> scattered over the code).
> - Also, this is not a debug but a info message, so i liked cifs_info()
> more ;-)
> - I saw plenty of pr_notice() in CIFS code, but I resisted the urge to
> convert them to cifs_info().
>
> * The second commit contains the code printing a cifs_info() when attempting
> a CIFS mount operation.
>
> Appreciate your review.
>
> V3: Created a new cifs_info() function, moved the mount attempt message to
> cifs_info
>
> V2: Created a loop to select the right cifs_dbg message to be printed,
> considering the current system's scenario, in order to avoid a
> duplicate message or stripping out important information in
> debug.
>
> Rodrigo Freire (2):
> CIFS: Adds information-level logging function
> CIFS: Print message when attempting a mount
>
> fs/cifs/cifs_debug.h | 16 ++++++++++++++++
> fs/cifs/cifsfs.c | 7 ++++++-
> fs/cifs/transport.c | 2 +-
> 3 files changed, 23 insertions(+), 2 deletions(-)
>
> --
> 1.8.3.1
>


--
Thanks,

Steve


Attachments:
0001-cifs-minor-clarification-in-comments.patch (1.91 kB)

2018-10-07 20:28:13

by Rodrigo Freire

[permalink] [raw]
Subject: Re: [PATCH v3 0/2] CIFS: Info-level log support, print message when attempting mount.

Thanks Steve! Sorry for overlooking it, whoops.

One more question; what’s your/community opinion on rewriting the existing pr_notice to the new cifs_info?

I could happily retrofit it.

Have a great week!

- RF
Sent from a mobile device

> On 7 Oct 2018, at 15:59, Steve French <[email protected]> wrote:
>
> Merged into cifs-2.6.git for-next
>
> Made a trivial tab/space correction in the patch (pointed out by
> checkpatch) and then added a trivial followon patch to address a
> comment/style (trivial)
> issue pointed out by checkpatch and to add a little more detailed
> comments about generally when to use each debug function. If any
> objections let me know.
>
>
>> On Sun, Oct 7, 2018 at 10:21 AM Rodrigo Freire <[email protected]> wrote:
>>
>> Hi Steve,
>> From our conversation over v2, I came out with this v3 patch, which I broke
>> in two commits:
>>
>> * The first commit in cifs_debug.h, creating the cifs_info() function.
>> - The aim of this commit is to allow to the developer to be able to print
>> informational-level data without having to use pr_info, pr_notice etc,
>> in line with other filesystems.
>> . One interesting and noteworthy feature of cifs_info() is that it is
>> transparent to the CIFS_DEBUG config state, either in "y" or "n".
>> . Also, by using KERN_INFO level, it can be safely filtered by a
>> maintainer / administrator, without cluttering their log monitors,
>> since this is a low level alert.
>> - I took the liberty to not add it inside the existing pr_debug, because
>> of the eventual need of some developer to print stuff that should be
>> printed not only in CIFS_DEBUG mode (as there are plenty of pr_notice
>> scattered over the code).
>> - Also, this is not a debug but a info message, so i liked cifs_info()
>> more ;-)
>> - I saw plenty of pr_notice() in CIFS code, but I resisted the urge to
>> convert them to cifs_info().
>>
>> * The second commit contains the code printing a cifs_info() when attempting
>> a CIFS mount operation.
>>
>> Appreciate your review.
>>
>> V3: Created a new cifs_info() function, moved the mount attempt message to
>> cifs_info
>>
>> V2: Created a loop to select the right cifs_dbg message to be printed,
>> considering the current system's scenario, in order to avoid a
>> duplicate message or stripping out important information in
>> debug.
>>
>> Rodrigo Freire (2):
>> CIFS: Adds information-level logging function
>> CIFS: Print message when attempting a mount
>>
>> fs/cifs/cifs_debug.h | 16 ++++++++++++++++
>> fs/cifs/cifsfs.c | 7 ++++++-
>> fs/cifs/transport.c | 2 +-
>> 3 files changed, 23 insertions(+), 2 deletions(-)
>>
>> --
>> 1.8.3.1
>>
>
>
> --
> Thanks,
>
> Steve
> <0001-cifs-minor-clarification-in-comments.patch>

2018-10-07 21:07:24

by Steve French

[permalink] [raw]
Subject: Re: [PATCH v3 0/2] CIFS: Info-level log support, print message when attempting mount.

On Sun, Oct 7, 2018 at 3:27 PM Rodrigo Freire <[email protected]> wrote:
>
> Thanks Steve! Sorry for overlooking it, whoops.
>
> One more question; what’s your/community opinion on rewriting the existing pr_notice to the new cifs_info?
>
> I could happily retrofit it.

I don't have a strong opinion. The four callers could be changed, but
my gut reaction
is that it is a much higher priority to add useful dynamic tracepoints
(ftrace ie trace-cmd)
to cifs to make it easier to debug real customer problems that are
currently awkward to
debug. By comparison, even ext4 has over 100 dynamic tracepoints, but larger
file systems like XFS has 500 (!), and nfs (including SunRPC) has about 100.

My guess is that going from our current 28 dynamic trace points (in
cifs.ko) to double
that (at least) will happen as developers add tracepoints to help them
debug real
problems (and of course it will help developers working on future problems even
more ...)


> > On 7 Oct 2018, at 15:59, Steve French <[email protected]> wrote:
> >
> > Merged into cifs-2.6.git for-next
> >
> > Made a trivial tab/space correction in the patch (pointed out by
> > checkpatch) and then added a trivial followon patch to address a
> > comment/style (trivial)
> > issue pointed out by checkpatch and to add a little more detailed
> > comments about generally when to use each debug function. If any
> > objections let me know.
> >
> >
> >> On Sun, Oct 7, 2018 at 10:21 AM Rodrigo Freire <[email protected]> wrote:
> >>
> >> Hi Steve,
> >> From our conversation over v2, I came out with this v3 patch, which I broke
> >> in two commits:
> >>
> >> * The first commit in cifs_debug.h, creating the cifs_info() function.
> >> - The aim of this commit is to allow to the developer to be able to print
> >> informational-level data without having to use pr_info, pr_notice etc,
> >> in line with other filesystems.
> >> . One interesting and noteworthy feature of cifs_info() is that it is
> >> transparent to the CIFS_DEBUG config state, either in "y" or "n".
<snip>


--
Thanks,

Steve