mbox series

[0/5] Assertion and debugging helpers

Message ID cover.1744794336.git.dsterba@suse.com (mailing list archive)
Headers show
Series Assertion and debugging helpers | expand

Message

David Sterba April 16, 2025, 9:08 a.m. UTC
Hi,

this is a RFC series. We need to improve debugging and logging helpers
so there's no ASSERT(0) or the convoluted
WARN_ON(IS_DEFINED(CONFIG_BTRFS_DEBUG)). This was mentioned in past
discussions so here's my proposal.

The series is only build tested, I'd like to hear some feedback if this
is going the right direction or if there are suggestions for fine
tuning.

1) Add verbose ASSERT macro, so we can print additional information when
it triggers, namely printing the values of the assertion expression.
More details in the first patch, basic pattern is something like

    VASSERT(value > limit, "value=%llu limit=%llu", value, limit);

The second patch shows it's application in volumes.c, converting about
half where it's relevant. There are about 800 assertions in fs/btrfs/
and we don't need to convert them all. This can be done incrementally
and as needed.

The verbose version is another macro, although with some preprocessor
magic it should be possible to make ASSERT take variable number of
arguments. Does not seem worth though.

2) Wrap WARN_ON(IS_DEFINED(CONFIG_BTRFS_DEBUG)) to DEBUG_WARN() with
optional message with printk format. This is used to replace the
WARN_ON(...) above and also the ASSERT(0).

The ultimate goal for me is to get rid of all ASSERT(0), it's not used
consistently and looks like it's a note to the code author. There may be
several reasons for it's use and although I've converted almost all to
DEBUG_WARN it may miss the intentions.

In some cases it may be better to add proper error handling, print a
message or warn and exit with error. Possibly the are cases where the
code cannot continue, meaning it should be a BUG_ON but this is also
something we want to convert to proper error handling.

David Sterba (5):
  btrfs: add verbose version of ASSERT
  btrfs: example use of VASSERT() in volumes.c
  btrfs: add debug build only WARN
  btrfs: convert WARN_ON(IS_ENABLED(CONFIG_BTRFS_DEBUG)) to DEBUG_WARN
  btrfs: convert ASSERT(0) to DEBUG_WARN()

 fs/btrfs/backref.c         |  4 +--
 fs/btrfs/delayed-ref.c     |  2 +-
 fs/btrfs/dev-replace.c     |  2 +-
 fs/btrfs/disk-io.c         |  2 +-
 fs/btrfs/extent-tree.c     |  2 +-
 fs/btrfs/extent_io.c       |  4 +--
 fs/btrfs/extent_map.c      |  2 +-
 fs/btrfs/free-space-tree.c | 27 +++++++++-------
 fs/btrfs/inode.c           |  6 ++--
 fs/btrfs/messages.h        | 30 ++++++++++++++++++
 fs/btrfs/qgroup.c          |  6 ++--
 fs/btrfs/relocation.c      |  4 +--
 fs/btrfs/send.c            |  4 +--
 fs/btrfs/space-info.c      |  2 +-
 fs/btrfs/tree-checker.c    |  8 ++---
 fs/btrfs/volumes.c         | 64 ++++++++++++++++++++++++--------------
 fs/btrfs/zoned.c           |  2 +-
 17 files changed, 109 insertions(+), 62 deletions(-)

Comments

Qu Wenruo April 16, 2025, 10:55 a.m. UTC | #1
在 2025/4/16 18:38, David Sterba 写道:
> Hi,
> 
> this is a RFC series. We need to improve debugging and logging helpers
> so there's no ASSERT(0) or the convoluted
> WARN_ON(IS_DEFINED(CONFIG_BTRFS_DEBUG)). This was mentioned in past
> discussions so here's my proposal.
> 
> The series is only build tested, I'd like to hear some feedback if this
> is going the right direction or if there are suggestions for fine
> tuning.
> 
> 1) Add verbose ASSERT macro, so we can print additional information when
> it triggers, namely printing the values of the assertion expression.
> More details in the first patch, basic pattern is something like
> 
>      VASSERT(value > limit, "value=%llu limit=%llu", value, limit);

I think the idea is pretty good for debug.

I have hit too many cases where outputting the values will immediately 
help me pinning down the cause, other than adding extra outputs and then 
curse myself being too stupid.


But the concern is, we already have too many different debugging tools 
just inside btrfs:

- btrfs_warn()/btrfs_err()/btrfs_crit()
   These are the most sane ones so far, and they saves us a lot of time
   debugging things like memory bitflip in tree-checkers.

- btrfs_debug()
   Looks like the least used ones, if someone is actively utilizing it,
   please let me know.

- WARN_ON()

- ASSERT()
   I'm definitely the abuser, almost all my patches have utilized one at
   least.

Now we will have another one, and we will need another set of rules for 
the newer one.

I know everyone loves new things, but I think we should sometimes to get 
it more consistent.

So, if we're pushing towards VASSERT(), then it should replace all 
ASSERT() eventually. At least mark the ASSERT() macro deprecated and 
stop new usages.

> 
> The second patch shows it's application in volumes.c, converting about
> half where it's relevant. There are about 800 assertions in fs/btrfs/
> and we don't need to convert them all. This can be done incrementally
> and as needed.
> 
> The verbose version is another macro, although with some preprocessor
> magic it should be possible to make ASSERT take variable number of
> arguments. Does not seem worth though.
> 
> 2) Wrap WARN_ON(IS_DEFINED(CONFIG_BTRFS_DEBUG)) to DEBUG_WARN() with
> optional message with printk format. This is used to replace the
> WARN_ON(...) above and also the ASSERT(0).

This looks very fine to me, independent from the VASSERT() part.

Thanks,
Qu>
> The ultimate goal for me is to get rid of all ASSERT(0), it's not used
> consistently and looks like it's a note to the code author. There may be
> several reasons for it's use and although I've converted almost all to
> DEBUG_WARN it may miss the intentions.
> 
> In some cases it may be better to add proper error handling, print a
> message or warn and exit with error. Possibly the are cases where the
> code cannot continue, meaning it should be a BUG_ON but this is also
> something we want to convert to proper error handling.
> 
> David Sterba (5):
>    btrfs: add verbose version of ASSERT
>    btrfs: example use of VASSERT() in volumes.c
>    btrfs: add debug build only WARN
>    btrfs: convert WARN_ON(IS_ENABLED(CONFIG_BTRFS_DEBUG)) to DEBUG_WARN
>    btrfs: convert ASSERT(0) to DEBUG_WARN()
> 
>   fs/btrfs/backref.c         |  4 +--
>   fs/btrfs/delayed-ref.c     |  2 +-
>   fs/btrfs/dev-replace.c     |  2 +-
>   fs/btrfs/disk-io.c         |  2 +-
>   fs/btrfs/extent-tree.c     |  2 +-
>   fs/btrfs/extent_io.c       |  4 +--
>   fs/btrfs/extent_map.c      |  2 +-
>   fs/btrfs/free-space-tree.c | 27 +++++++++-------
>   fs/btrfs/inode.c           |  6 ++--
>   fs/btrfs/messages.h        | 30 ++++++++++++++++++
>   fs/btrfs/qgroup.c          |  6 ++--
>   fs/btrfs/relocation.c      |  4 +--
>   fs/btrfs/send.c            |  4 +--
>   fs/btrfs/space-info.c      |  2 +-
>   fs/btrfs/tree-checker.c    |  8 ++---
>   fs/btrfs/volumes.c         | 64 ++++++++++++++++++++++++--------------
>   fs/btrfs/zoned.c           |  2 +-
>   17 files changed, 109 insertions(+), 62 deletions(-)
>
David Sterba April 16, 2025, 8:20 p.m. UTC | #2
On Wed, Apr 16, 2025 at 08:25:56PM +0930, Qu Wenruo wrote:
> 
> 
> 在 2025/4/16 18:38, David Sterba 写道:
> > Hi,
> > 
> > this is a RFC series. We need to improve debugging and logging helpers
> > so there's no ASSERT(0) or the convoluted
> > WARN_ON(IS_DEFINED(CONFIG_BTRFS_DEBUG)). This was mentioned in past
> > discussions so here's my proposal.
> > 
> > The series is only build tested, I'd like to hear some feedback if this
> > is going the right direction or if there are suggestions for fine
> > tuning.
> > 
> > 1) Add verbose ASSERT macro, so we can print additional information when
> > it triggers, namely printing the values of the assertion expression.
> > More details in the first patch, basic pattern is something like
> > 
> >      VASSERT(value > limit, "value=%llu limit=%llu", value, limit);
> 
> I think the idea is pretty good for debug.
> 
> I have hit too many cases where outputting the values will immediately 
> help me pinning down the cause, other than adding extra outputs and then 
> curse myself being too stupid.
> 
> 
> But the concern is, we already have too many different debugging tools 
> just inside btrfs:
> 
> - btrfs_warn()/btrfs_err()/btrfs_crit()
>    These are the most sane ones so far, and they saves us a lot of time
>    debugging things like memory bitflip in tree-checkers.

Neither of that is mean for debugging, this is for users and for system
logs. The rules are described at https://btrfs.readthedocs.io/en/latest/dev/Development-notes.html#message-level

Though now that I see it, it does not mention btrfs_crit(), we have
about 60 of them and I think some of them could be turned to
btrfs_err().

> - btrfs_debug()
>    Looks like the least used ones, if someone is actively utilizing it,
>    please let me know.

Yeah, I think they've been there historically but I don't see any
consistent use. We may start deleting them as well or turning to trace
points if it's some notable event like repairing a block. Where it may
make sense is some internal debugging infrastructure like the leak
checkers to do a report before umount.

We can still keep the macros and helpers if anybody needs to write
custom debugging messages, I do that rather with btrfs_err with
searchable prefix so it's logged by default.

> - WARN_ON()

This is probably the most disordered way of debugging also present in
the release builds. The known problem is also that some systems are
configured to panic on warn so even a harmless warning has a bad impact.
I'd like to have them all audited and removed or replaced by something
more specific with an error so we don't have to guess the intentions for
the warnings. But this needs to be done case by case, there are about
300 of them.

> - ASSERT()
>    I'm definitely the abuser, almost all my patches have utilized one at
>    least.

This is actually good, please add more. The best time to add assertions
is when the code is written because the invariants and assumptions are
known.

We have the documentation at
https://btrfs.readthedocs.io/en/latest/dev/Development-notes.html#handling-unexpected-conditions
it may need some updates to give better guidelines.

> Now we will have another one, and we will need another set of rules for 
> the newer one.
> 
> I know everyone loves new things, but I think we should sometimes to get 
> it more consistent.

I'd like to unify and eventually reduce the number of the logging or
debugging primitives we use.

> So, if we're pushing towards VASSERT(), then it should replace all 
> ASSERT() eventually. At least mark the ASSERT() macro deprecated and 
> stop new usages.

You can consider VASSERT equivalent to ASSERT, the only reason it's a
different macro now is because I'd have to implement the variable number
of arguments and printk. But I can look into that, I agree that having
just ASSERT would be best in the long term.
David Sterba April 16, 2025, 10:30 p.m. UTC | #3
On Wed, Apr 16, 2025 at 10:20:56PM +0200, David Sterba wrote:
> > So, if we're pushing towards VASSERT(), then it should replace all 
> > ASSERT() eventually. At least mark the ASSERT() macro deprecated and 
> > stop new usages.
> 
> You can consider VASSERT equivalent to ASSERT, the only reason it's a
> different macro now is because I'd have to implement the variable number
> of arguments and printk. But I can look into that, I agree that having
> just ASSERT would be best in the long term.

I have something, so the following will work:

ASSERT(condition);
ASSERT(condition, "string");
ASSERT(condition, "string=%d", variable);
Qu Wenruo April 16, 2025, 10:44 p.m. UTC | #4
在 2025/4/17 08:00, David Sterba 写道:
> On Wed, Apr 16, 2025 at 10:20:56PM +0200, David Sterba wrote:
>>> So, if we're pushing towards VASSERT(), then it should replace all
>>> ASSERT() eventually. At least mark the ASSERT() macro deprecated and
>>> stop new usages.
>>
>> You can consider VASSERT equivalent to ASSERT, the only reason it's a
>> different macro now is because I'd have to implement the variable number
>> of arguments and printk. But I can look into that, I agree that having
>> just ASSERT would be best in the long term.
> 
> I have something, so the following will work:
> 
> ASSERT(condition);
> ASSERT(condition, "string");
> ASSERT(condition, "string=%d", variable);

That will be great, we can keep the single ASSERT() debug type, with all 
the new extra output.

Thanks,
Qu