Add bbcode support for printing output (colored debug messages, better logging)

[georgwacker]

In reference to better logging #19122 and #10870, this simple change enables styling of print messages.
The editor output log already uses a RichTextLabel, so why not use the bbcode functionality?

If performance is a concern (add_text vs append_bbcode) perhaps we could make it an editor setting?

If used, the bbcode will of course show up in the log files, I believe the same is true for coloring output in Unity. I don't think this is an issue if you want colored output for debugging, though.

This is how it looks:

print("normal print")
print("[rainbow]normal print[/rainbow]")
print_debug("[color=aqua]Debug: [/color]", "[color=lime]Object 02[/color]")

[Calinou]

How well does this perform if you print large amounts of text every frame (while staying below the 4,096 characters per second limit)?

See also #2308. We could parse ANSI escape codes and convert them to BBCode for use in the editor output.

[georgwacker]

Here are the test results, I recorded the fps every frame and took the average at the end. Let me know if that method of testing is flawed.

add_text
56.32
56.382
56.322

append_bbc
56.328
56.32
56.339

Regarding the ANSI escapes, I find them rather cryptic to write and could never remember them after a while. Wrapping those in a print_color function could be done, but using the existing bbcode functionality goes beyond just color (even though the default output font does not support italic or bolds that well).
Using the same bbcode that is already established for the RichTextLabel to enable all sorts of styling seems like an elegant solution to me.

Here is the code I used for testing:

var fps = []
var samples = 1000
var max_chars = 4096
var char_count = 0
var d = 0
var i = 0

func _process(delta):
    if(i<samples):
        d += delta

        if d >= 1:
            d = 0
            char_count = 0
            
        var p = "[color=aqua]Debug: [/color][color=lime]Object 02[/color]"
        var allowed_chars = min(max(max_chars - char_count, 0), p.length())
        
        if allowed_chars == 0: return
        
        if allowed_chars < p.length():
            p = p.substr(0, allowed_chars)
        
        char_count += allowed_chars
        if char_count < max_chars:
            print(p)
        
        fps.append(Performance.get_monitor(Performance.TIME_FPS))
        i += 1
    
    if i == samples:
        var fps_avg = 0.0
        for f in fps:
            fps_avg += f
        fps_avg /= fps.size()
        print(fps_avg)
        i += 1

[Calinou]

Regarding the ANSI escapes, I find them rather cryptic to write and could never remember them after a while.

I agree, this is mostly about providing a way to print colored text that works both in terminal output and the editor's Output tab. We could also strip those automatically when the terminal output is not a TTY (e.g. writing to a file).

Manual [color] tags would remain available, but converting them to ANSI codes might not be trivial (unless you convert all of them as true color codes, which aren't supported everywhere).

[georgwacker]

Looking at the user side, I would be against a print_color after all, because you can't combine it with other print variants that we already have, like print_debug (which is very useful).

The BBCode approach would potentially open up other uses, like opening more things in the editor via URLs that are clickable in the output log.

I would suggest the following: If the user wants to print out colored text, they would include the bbcode (like in this PR) in a desired print variant. Then, the bbcode gets stripped for file logging. If the color tag is a predefined color, convert it to ANSI escapes for TTY, otherwise print it without color.

Besides the automatic coloring of errors, warnings and stack_traces (#33505) I don't think we need a dedicated function for coloring TTY output if we take this editor first approach. If the user or plugin writer wants colors, they use the BBCode and it would trickle down to TTY and file log, while also coloring the editor output.

For a headless mode, this would mean to still use BBCode which gets converted to the matching ANSI codes for TTY.

[aaronfranke]

@georgwacker Is this still desired? If so, it needs to be rebased on the latest master branch. While there are no conflicts, rebasing is important so that reviewers can easily test the PR.

[KoBeWi]

I did an even simpler performance test:

func _ready() -> void:
	var time = Time.get_ticks_usec()
	for i in 1000:
		print("spam")
	print(Time.get_ticks_usec() - time)
	
	time = Time.get_ticks_usec()
	for i in 1000:
		print("[b]spam[/b]")
	print(Time.get_ticks_usec() - time)

With add_text():

With append_text() (formerly append_bbcode()):

For some reason the bbcode method turned out faster. Even if I didn't do the test in proper conditions, there isn't any visible performance drawback to using bbcode, so it's just a matter of whether we want it enabled or not.

[KoBeWi]

Still needs rebase.

[georgwacker]

Rebased and tested

[Faless]

I am a bit concerned about the side effects this PR can have.
As an example, the [img] tag can trigger reading from the FS, and given the print might come from a user string, this could lead to potential security issues (present or future, the log4j issue is only few days old).
All in all, this seems more a feature creep than an actual need, I would advice to at least have it disabled by default.

[YuriSizov]

Some very obvious need for bbcodes here would be making reported error paths navigatable by clicking on them.

[Faless]

Some very obvious need for bbcodes here would be making reported error paths navigatable by clicking on them.

But does the bbcode need to be applied to the values inside print itself? I.e. potentially any user generated string?
I don't think that's the case. If we want that text link we should only add the bbcode to the push_error, as for colors, we should adapt a level system like most loggers do info/warn/err with different colors.

[YuriSizov]

But does the bbcode need to be applied to the values inside print itself? I.e. potentially any user generated string? I don't think that's the case. If we want that text link we should only add the bbcode to the push_error, as for colors, we should adapt a level system like most loggers do info/warn/err with different colors.

Well, as the log is just a rich text label, that would be tricky to separate, no? We'd need to have a way to sanitize user input but still add it as a part of bbcode-able RTL control.

[Faless]

Well, as the log is just a rich text label, that would be tricky to separate, no?

Well, the fact that it's tricky to implement safely, doesn't mean we should implement it in an unsafe way.

[groud]

I kind of agree with @Faless here. Unless I am wrong, there's no need for something else than colors and bold/italic support there. I am not against adding support for those in the output panel, but I am not sure it should go through a subset of the bbcode-style syntax.

Also, I think we should make it so a standard terminal and the output panel stay consistent. Thus I'd be maybe more in favor of supporting ANSI escape code instead.

[ghost]

The ANSI code solution will work also because Windows and Linux or different operating systems/terminals can use different color codes. So by providing a unified color command it will be sorted out automatically before being sent to the terminal/output.

[Zireael07]

@filipworksdev: Note that Windows prior to some version doesn't really recognize ANSI :(

[Calinou]

@filipworksdev: Note that Windows prior to some version doesn't really recognize ANSI :(

We can enable virtual terminal processing on Windows 10 and later, and strip ANSI escape codes from printed text on older Windows versions. This way, printing to the console doesn't look broken on old Windows versions, but it won't be colored (which is probably fine, given Windows versions prior to 10 are now EOL).

[akien-mga]

We discussed this in a PR review meeting and suggest adding a separate path for bbcode formatted prints, keeping the default print behavior unchanged. So users who really want colored output can opt-in to it for their own code (and not for user-provided strings).

[voylin]

What is the progress on this? Kind of looking forward to this feature.

[Calinou]

@voylin This pull request needs to be amended to use a separate method for BBCode-enabled printing before it can be merged. See Akien's comment above. I'd suggest print_bbcode() or print_rich() (the latter is slightly shorter).

This approach means it's no longer possible to use print_debug() or print_verbose() at the same time, but more methods could be added for this if there's significant demand.

Feel free to do this work on your end and open a pull request against master 🙂

[voylin]

Feel free to do this work on your end and open a pull request against master 🙂

I think this could be a good first issue to work on, I'll try my best 😉

[voylin]

I've been trying all day, but my skills are apparently not good enough. Was able to create a function, that can print in the console and the terminal. However, I just can't find away to give it a type that gets passed to the add_message function. It gets stuck somewhere in the error checking so it never gets the function.
So I'm giving up on this one, I hope someone else may be able to do this.

Sorry @Calinou , I still have some work on my c++ (But also breakpoints don't work to trace how the function goes)
So hopefully someone else will be able to do this ^^"

For the next person taking over:
The print function is located in "core/variant/variant_utility.cpp". Copy that function and call it something like "print_rich"
That one sends everything to print_line() in "core/string/print_string.h", which on turn sends it to __print_line().
What I did here was make a function called print_rich_line() which goes to __print_rich_line().

In that function before the string get's send to OS::get_singleton()->print() I copy the string to another variable and exchange all the bbcode with ANSI code. From there it got impossible for me to track how it goes further and how to give it a different type in editor/editor_log.cpp. I tried adding an extra bool (typedef void (*PrintHandlerFunc)(void *, const String &p_string, bool p_error, bool p_rich);), however did not work.

And in editor/editor_log.h I made a new message type called MSG_TYPE_RICH, so when the message has that type, the string gets append_text instead of add_text to the log.

Not sure if this explanation is helpful to anybody, but because breakpoints just didn't work, I had to spend the first 4 hours searching the pattern in which it goes, and I still couldn't find all the in between functions (my guess is that those functions are probably for error checking.)

[Calinou]

In that function before the string get's send to OS::get_singleton()->print() I copy the string to another variable and exchange all the bbcode with ANSI code. From there it got impossible for me to track how it goes further and how to give it a different type in editor/editor_log.cpp. I tried adding an extra bool (typedef void (*PrintHandlerFunc)(void *, const String &p_string, bool p_error, bool p_rich);), however did not work.

Note that the BBCode → ANSI code translation is an optional step. It doesn't have to be done for an initial revision of a pull request. Printing the text to the console as-is is fine for now, even if it's not very readable due to BBCode tags appearing in plain text in the console. This is mostly a debugging helper anyway 🙂

Implementing stripping of BBCode tags when printing to stdout/stderr would improve readability while keeping functionality intact within the editor Output panel. BBCode → ANSI translation is icing on the cake here.

---

If anyone else is interested in going that route, I wrote a BBCode to ANSI converter in GDScript. It only replies on string replacement, but it seems fairly robust already:

Relying on string replacement means that nested color tags won't behave correctly, but this can be worked around by not relying on nested color tags (which looks identical to the end user). Nested style tags are supported by using ANSI escape codes that allow resetting only the style, not the color.

This code should be easy to translate to C++, making it slightly faster in the process.

[voylin]

@Calinou I've tried my best today to make it work. #60675
It's working, but I am almost certain that the way I implemented it is wrong and will probably be laughed at by more skilled people. ^^" But it's working, so now it's only a matter of cleaning up the code I think.

Thanks for the example of the BBCodes to ANSI, I forgot about some of the BBCodes in my first try so I used your script as a reference.

It doesn't have to be done for an initial revision of a pull request.
In my pull request it prints out things correctly in the terminal and in the editor output. So that will be my initial revision and I hope people will be able to give me advice on how to make it ready so it can get merged. Thanks for all the help so far, it's been a great learning experience. ^o^

[voylin]

Not sure if this can be closed or not, but I feel confident that my pull request #60675 does everything that the creator of this pull request desired.

Thanks again for motivating me! I'm glad that I didn't give up after all. ^^

[Calinou]

Superseded by #60675. Thanks for the contribution nonetheless!