[PATCH 1/1] btrfs: add kernel scrub log messages

[PATCH 1/1] btrfs: add kernel scrub log messages

[Anand Jain]

scrub kernel messages helps debug and audit, add them to the log.

Signed-off-by: Anand Jain <anand.jain@oracle.com>
---
 fs/btrfs/scrub.c | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
index 902819d3cf41..d7a92521019e 100644
--- a/fs/btrfs/scrub.c
+++ b/fs/btrfs/scrub.c
@@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
 	mutex_unlock(&fs_info->scrub_lock);
 
 	if (!is_dev_replace) {
+		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");
 		/*
 		 * by holding device list mutex, we can
 		 * kick off writing super in log tree sync.
@@ -3897,6 +3898,10 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
 	if (progress)
 		memcpy(progress, &sctx->stat, sizeof(*progress));
 
+	if (!is_dev_replace)
+		btrfs_info(fs_info, "scrub: devid %llu %s:%d",
+			   devid, ret ? "not finished":"finished", ret);
+
 	mutex_lock(&fs_info->scrub_lock);
 	dev->scrub_ctx = NULL;
 	scrub_workers_put(fs_info);
-- 
1.8.3.1

Re: [PATCH 1/1] btrfs: add kernel scrub log messages

[Nikolay Borisov]

On 17.12.18 г. 5:15 ч., Anand Jain wrote:
> scrub kernel messages helps debug and audit, add them to the log.
> 
> Signed-off-by: Anand Jain <anand.jain@oracle.com>
> ---
>  fs/btrfs/scrub.c | 5 +++++
>  1 file changed, 5 insertions(+)
> 
> diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
> index 902819d3cf41..d7a92521019e 100644
> --- a/fs/btrfs/scrub.c
> +++ b/fs/btrfs/scrub.c
> @@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>  	mutex_unlock(&fs_info->scrub_lock);
>  
>  	if (!is_dev_replace) {
> +		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");

Perhahps those messages needs to be with btrfs_debug, since they are
only really useful when someone is debugging otherwise we will make
btrfs rather noisy.

>  		/*
>  		 * by holding device list mutex, we can
>  		 * kick off writing super in log tree sync.
> @@ -3897,6 +3898,10 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>  	if (progress)
>  		memcpy(progress, &sctx->stat, sizeof(*progress));
>  
> +	if (!is_dev_replace)
> +		btrfs_info(fs_info, "scrub: devid %llu %s:%d",
> +			   devid, ret ? "not finished":"finished", ret);
> +
>  	mutex_lock(&fs_info->scrub_lock);
>  	dev->scrub_ctx = NULL;
>  	scrub_workers_put(fs_info);
> 

Re: [PATCH 1/1] btrfs: add kernel scrub log messages

[Anand Jain]

On 12/17/2018 02:39 PM, Nikolay Borisov wrote:
> 
> 
> On 17.12.18 г. 5:15 ч., Anand Jain wrote:
>> scrub kernel messages helps debug and audit, add them to the log.
>>
>> Signed-off-by: Anand Jain <anand.jain@oracle.com>
>> ---
>>   fs/btrfs/scrub.c | 5 +++++
>>   1 file changed, 5 insertions(+)
>>
>> diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
>> index 902819d3cf41..d7a92521019e 100644
>> --- a/fs/btrfs/scrub.c
>> +++ b/fs/btrfs/scrub.c
>> @@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>>   	mutex_unlock(&fs_info->scrub_lock);
>>   
>>   	if (!is_dev_replace) {
>> +		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");
> 
> Perhahps those messages needs to be with btrfs_debug, since they are
> only really useful when someone is debugging otherwise we will make
> btrfs rather noisy.

  Not really, its part of audit as well, it should be info. It helps to
  understand the maintenance history of the FS.

Thanks, Anand

>>   		/*
>>   		 * by holding device list mutex, we can
>>   		 * kick off writing super in log tree sync.
>> @@ -3897,6 +3898,10 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>>   	if (progress)
>>   		memcpy(progress, &sctx->stat, sizeof(*progress));
>>   
>> +	if (!is_dev_replace)
>> +		btrfs_info(fs_info, "scrub: devid %llu %s:%d",
>> +			   devid, ret ? "not finished":"finished", ret);
>> +
>>   	mutex_lock(&fs_info->scrub_lock);
>>   	dev->scrub_ctx = NULL;
>>   	scrub_workers_put(fs_info);
>>

Re: [PATCH 1/1] btrfs: add kernel scrub log messages

[David Sterba]

On Mon, Dec 17, 2018 at 08:39:08AM +0200, Nikolay Borisov wrote:
> 
> 
> On 17.12.18 г. 5:15 ч., Anand Jain wrote:
> > scrub kernel messages helps debug and audit, add them to the log.
> > 
> > Signed-off-by: Anand Jain <anand.jain@oracle.com>
> > ---
> >  fs/btrfs/scrub.c | 5 +++++
> >  1 file changed, 5 insertions(+)
> > 
> > diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
> > index 902819d3cf41..d7a92521019e 100644
> > --- a/fs/btrfs/scrub.c
> > +++ b/fs/btrfs/scrub.c
> > @@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
> >  	mutex_unlock(&fs_info->scrub_lock);
> >  
> >  	if (!is_dev_replace) {
> > +		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");
> 
> Perhahps those messages needs to be with btrfs_debug, since they are
> only really useful when someone is debugging otherwise we will make
> btrfs rather noisy.

I've heared complaints about too noisy and not enough information in the
log. The compromise is to use INFO level as it's the last before DEBUG.

Compare output of 'dmesg' on a system that passed fstests with

  dmesg -l emerg,alert,crit,err,warn

and

  dmesg -l emerg,alert,crit,err,warn,notice,info

In the first one you'll see conditions that are worth user attention
(something's wrong, something needs to be fixed), while in the other
not. If you find something that's not at the right level considering the
visibility, please send a patch.

Re: [PATCH 1/1] btrfs: add kernel scrub log messages

[David Sterba]

On Mon, Dec 17, 2018 at 11:15:12AM +0800, Anand Jain wrote:
> scrub kernel messages helps debug and audit, add them to the log.
> 
> Signed-off-by: Anand Jain <anand.jain@oracle.com>
> ---
>  fs/btrfs/scrub.c | 5 +++++
>  1 file changed, 5 insertions(+)
> 
> diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
> index 902819d3cf41..d7a92521019e 100644
> --- a/fs/btrfs/scrub.c
> +++ b/fs/btrfs/scrub.c
> @@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>  	mutex_unlock(&fs_info->scrub_lock);
>  
>  	if (!is_dev_replace) {
> +		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");

Why do you print a fixed and known string using %s?

>  		/*
>  		 * by holding device list mutex, we can
>  		 * kick off writing super in log tree sync.
> @@ -3897,6 +3898,10 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>  	if (progress)
>  		memcpy(progress, &sctx->stat, sizeof(*progress));
>  
> +	if (!is_dev_replace)
> +		btrfs_info(fs_info, "scrub: devid %llu %s:%d",
> +			   devid, ret ? "not finished":"finished", ret);

Spaces around binary operators please: ret ? "not finished" : "finished"

What's the reason to print the error code here? It is returned from the
ioctl.

Re: [PATCH 1/1] btrfs: add kernel scrub log messages

[Anand Jain]

On 01/03/2019 01:20 AM, David Sterba wrote:
> On Mon, Dec 17, 2018 at 11:15:12AM +0800, Anand Jain wrote:
>> scrub kernel messages helps debug and audit, add them to the log.
>>
>> Signed-off-by: Anand Jain <anand.jain@oracle.com>
>> ---
>>   fs/btrfs/scrub.c | 5 +++++
>>   1 file changed, 5 insertions(+)
>>
>> diff --git a/fs/btrfs/scrub.c b/fs/btrfs/scrub.c
>> index 902819d3cf41..d7a92521019e 100644
>> --- a/fs/btrfs/scrub.c
>> +++ b/fs/btrfs/scrub.c
>> @@ -3876,6 +3876,7 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>>   	mutex_unlock(&fs_info->scrub_lock);
>>   
>>   	if (!is_dev_replace) {
>> +		btrfs_info(fs_info, "scrub: devid %llu %s", devid, "started");
my bad, will fix.
> 
> Why do you print a fixed and known string using %s?
> 
>>   		/*
>>   		 * by holding device list mutex, we can
>>   		 * kick off writing super in log tree sync.
>> @@ -3897,6 +3898,10 @@ int btrfs_scrub_dev(struct btrfs_fs_info *fs_info, u64 devid, u64 start,
>>   	if (progress)
>>   		memcpy(progress, &sctx->stat, sizeof(*progress));
>>   
>> +	if (!is_dev_replace)
>> +		btrfs_info(fs_info, "scrub: devid %llu %s:%d",
>> +			   devid, ret ? "not finished":"finished", ret);
> 
> Spaces around binary operators please: ret ? "not finished" : "finished"

added in v2.
> What's the reason to print the error code here? It is returned from the
> ioctl.

It does not get logged. Help offline debugging.