Bug 42637 – new-run-webkit-tests: Support auto indentation based on call stack depth for debugging

• Component: Tools / Tests
• Status: RESOLVED WONTFIX

[Hayato Ito]

It would be nice to indent output of logging automatically based on call stack depth like:

100720 22:30:15                test_files.py:65   DEBUG Gathering tests from: ['fast/css'] relative to /Users/hayato/src/webkit/WebKit/LayoutTests
100720 22:30:15                test_files.py:104  DEBUG Test gathering took 0.015220 seconds
100720 22:30:15                  printing.py:538  INFO Using port 'mac-leopard'
100720 22:30:15                metered_stream.py:126  INFO Parsing expectations ...
100720 22:30:15                    test_expectations.py:388  ERROR 

Such an auto-indentation helps me to trace new-run-webkit-tests for debugging.
This might be helpful for others.

[Hayato Ito]

Created attachment 62067 [details]
verbose-auto-indent

[Ojan Vafai]

Dirk, what do you think of this?

I'm resistant to adding another commandline parameter. Maybe we should just always do this for --verbose if it's useful.

[Dirk Pranke]

I agree that we shouldn't add another command line option for this. I am fine with just making this the default (in the verbose case; the non-verbose case shouldn't change at all as a result of this patch).

There's a small part of me that wonders if just the debug statements should be indented, so that ERROR/WARN/INFO stays on the left. I'd sort of have to see the different output and compare.

[Hayato Ito]

Created attachment 62553 [details]
All log levels are indented.

[Hayato Ito]

Created attachment 62554 [details]
Only debug level statements are indented.

[Hayato Ito]

Hi Dirk,
Thank you for the comments.

(In reply to comment #3)
> I agree that we shouldn't add another command line option for this. I am fine with just making this the default (in the verbose case; the non-verbose case shouldn't change at all as a result of this patch).
> 
> There's a small part of me that wonders if just the debug statements should be indented, so that ERROR/WARN/INFO stays on the left. I'd sort of have to see the different output and compare.

Okay. I've attached the two log files for the comparison:
1. All log level statements are indented.
2. Only debug level statements are indented.

I am not sure which is better. IMHO, it would be easily viewable if all log level statements are equally indented.
What do you think about them?

I don't have any particular opinion about that this auto-indent feature should be default for '--verbose'.
I am just afraid that someone does not like such an auto-indent.

[Dirk Pranke]

(In reply to comment #6)

Hi Hayato, 

Thanks for posting the examples. After looking at them, indenting only the debugging statements looks goofy, so let's not do that.

One more change, though ... it looks like every print statement is being indented by some number of spaces (since there's probably a fixed size call stack 4-5 deep before any actual message), and that's just creating wasted whitespace (maybe 6-8 characters). It seems like maybe the correction for self.depth on line 147 of printing.py maybe isn't working right, or could be tweaked?

As to annoying some people with the change to --verbose, some people will always be annoyed by any UI change; I don't think there's enough of them to justify the complexity of adding an additional switch, but if there is demand for one, we can add it in later.

[Ojan Vafai]

Actually, now that I look at the output, it's not clear to me how this would help in debugging. It's not like it gives you a call stack or anything. What cases would this be helpful in?

[Hayato Ito]

Thank you for the comment.

(In reply to comment #7)
> (In reply to comment #6)
> 
> Hi Hayato, 
> 
> Thanks for posting the examples. After looking at them, indenting only the debugging statements looks goofy, so let's not do that.
> 
> One more change, though ... it looks like every print statement is being indented by some number of spaces (since there's probably a fixed size call stack 4-5 deep before any actual message), and that's just creating wasted whitespace (maybe 6-8 characters). It seems like maybe the correction for self.depth on line 147 of printing.py maybe isn't working right, or could be tweaked?

It would be difficult to know 'baseline' of stack depth.
I've tried to get it, but I am afraid that there is no way to tell that in confident. It is fragile value.
So we have to adapt an reasonable value as the baseline of stack depth, like 4 or 5 as you suggested. I'll modify it later.

> 
> As to annoying some people with the change to --verbose, some people will always be annoyed by any UI change; I don't think there's enough of them to justify the complexity of adding an additional switch, but if there is demand for one, we can add it in later.

[Hayato Ito]

Thank you for the comment.

(In reply to comment #8)
> Actually, now that I look at the output, it's not clear to me how this would help in debugging. It's not like it gives you a call stack or anything. What cases would this be helpful in?

I agree your concern.
For those who starts reading new-run-webkit-test code, such an indentation would be useful especially when a lot of _log.debug were inserted, as I actually did to understand the flow of new-run-webkit-test.

Once you are familiar with new-run-webkit-test code base, it would not be so useful than before.

I am afraid that making it default for '--verbose' is annoying for a lot of guys.
In a meantime, I'd like to hear more opinions. I am not confident that this patch is worth to be added.

[Eric Seidel (no email)]

Comment on attachment 62067 [details]
verbose-auto-indent

I dont' see why this is useful.

[Dirk Pranke]

closing ... I  think we agreed this wasn't that useful?

[Hayato Ito]

Okay. I forgot this. We don't need that.

(In reply to comment #12)
> closing ... I  think we agreed this wasn't that useful?