Debug spew in BOARD_CONNECTED_ITEM

[John Beard]

When placing a component with the "O" tool in pcbnew, in a Debug build, a lot of DBG spew is produced when the as-yet-unplaced component is moved around:

* board_connected_item.cpp 97:
    DBG(printf( "%s: NULL netclass,type %d", __func__, Type() );)
* board_connected_item.cpp 115:
    DBG(printf( "%s: NULL board,type %d", __func__, Type() );)

I assume these warnings are spurious, as it doesn't seem to be causing issues. However, spamming the console with strings (especially ones without \n!) is pretty annoying - hundreds of copies of:

GetNetClass: NULL board,type 4GetClearance: NULL netclass,type 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type 4GetNetClass: NULL board,type 4

Can we just remove the debug and keep the behaviour, or should we be guarding this at a higher level? They've been there since 2014, so this probably affects 5.1 as well (but I don't have a Debug build of that ATM)

[Seth Hillbrand (sethh)]

Hmm... Maybe we should address the root here.

When placing with the option "Show Pad Clearance" on, we seem to be trying to draw the component clearance. But since the component isn't placed, we don't have the board reference.

The warnings should stay (maybe with better formatting) I think but we should turn off the references that are requesting clearance until the the component is placed.

[Jeff Young (jeyjey)]

Could we set its board reference earlier. Showing the clearance is useful even before the component is placed.

> On 12 Apr 2019, at 22:49, Seth Hillbrand <email address hidden> wrote:
>
> Hmm... Maybe we should address the root here.
>
> When placing with the option "Show Pad Clearance" on, we seem to be
> trying to draw the component clearance. But since the component isn't
> placed, we don't have the board reference.
>
> The warnings should stay (maybe with better formatting) I think but we
> should turn off the references that are requesting clearance until the
> the component is placed.
>

[Wayne Stambaugh (stambaughw)]

It seems like we should be setting the current board as the parent so that the clearances can be shown while the footprint is being placed. We should also replace printf() debugging output with wxLogTrace so we can turn the debug spew off by default.

[KiCad Janitor (kicad-janitor)]

Fixed in revision 1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf
https://git.launchpad.net/kicad/patch/?id=1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf

[John Beard (john-j-beard)]

If this is valid debug that alerts to a likely-wrong situation, perhaps wxLogDebug is better? Otherwise the mistake won't be visible until someone turns that particular trace on for some other reason?

On 14 April 2019 19:27:29 BST, KiCad Janitor <email address hidden> wrote:
>Fixed in revision 1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf
>https://git.launchpad.net/kicad/patch/?id=1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf
>
>** Changed in: kicad
> Status: In Progress => Fix Committed
>
>--
>You received this bug notification because you are subscribed to the
>bug
>report.
>https://bugs.launchpad.net/bugs/1824587
>
>Title:
> Debug spew in BOARD_CONNECTED_ITEM
>
>Status in KiCad:
> Fix Committed
>
>Bug description:
> When placing a component with the "O" tool in pcbnew, in a Debug
> build, a lot of DBG spew is produced when the as-yet-unplaced
> component is moved around:
>
> * board_connected_item.cpp 97:
> DBG(printf( "%s: NULL netclass,type %d", __func__, Type() );)
> * board_connected_item.cpp 115:
> DBG(printf( "%s: NULL board,type %d", __func__, Type() );)
>
> I assume these warnings are spurious, as it doesn't seem to be causing
> issues. However, spamming the console with strings (especially ones
> without \n!) is pretty annoying - hundreds of copies of:
>
> GetNetClass: NULL board,type 4GetClearance: NULL netclass,type
> 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type
> 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type
> 4GetNetClass: NULL board,type 4GetClearance: NULL netclass,type
> 4GetNetClass: NULL board,type 4
>
> Can we just remove the debug and keep the behaviour, or should we be
> guarding this at a higher level? They've been there since 2014, so
> this probably affects 5.1 as well (but I don't have a Debug build of
> that ATM)
>
>To manage notifications about this bug go to:
>https://bugs.launchpad.net/kicad/+bug/1824587/+subscriptions

[Seth Hillbrand (sethh)]

I'd second that approach.

[Wayne Stambaugh (stambaughw)]

My thinking on this is pretty straight forward. If an unexpected run
time condition occurs, use one of the wx debugging macros (wxASSERT,
wxCHECK, wxCHECK_RET, etc.). If you just want to look at internal state
information while the application is running, use wxLogTrace and turn
the output on/off as required. Does this debugging output not fall
under either of those categories?

On 4/14/2019 10:57 PM, Seth Hillbrand wrote:
> I'd second that approach.
>

[John Beard (john-j-beard)]

In principle it should be wxASSERT or friends, but it's in a paint event callback, so if it pops a dialog, it will all go a bit wrong, as the comment says:

    // DO NOT use wxASSERT, because GetClearance is called inside an OnPaint event
    // and a call to wxASSERT can crash the application.

Furthermore, as it happens on *every* paint event, a wxASSERT would be basically a system crash, as the application will be unusable for the hundreds of dialogs one after the other.

In this case, it's not critical debug (as it's been happening for a while), but it is still a "wrong" code path. I think wxLogDebug is an acceptable recourse to highlight the error without rendering the program unusable.

[Wayne Stambaugh (stambaughw)]

This may be one of those corner cases where wxLogDebug would be an acceptable albeit less than ideal solution. I'm somewhat surprised that the wx folks don't suppress the event queue and prevent any further paint events when an assertion is raised. This would prevent the crash. I wonder if this was due to a bug in the assertion handler that has been fixed. Has anyone tried an assert here to see if it still crashes? Maybe the comment is out of date. The problem with wxLogDebug is that you will not see the issue unless you are looking at the debug output for an issue. It seems to me that assert would be the correct way to get a developers attention that they mucked up something.

[KiCad Janitor (kicad-janitor)]

Fixed in revision 1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf
https://git.launchpad.net/kicad/patch/?id=1d2db311b2e364caddc2f56f6525eb7bcaf4b3bf