Godot: Print() method - show line number and node where the print method was emited from

[blurymind]

The print method is a great debugging tool, but sometimes when we have it at many places of a script - it becomes somewhat difficult to trace back where it came from.

It would immencely help for debugging if when printing in godot editor, it also showed the node and line number of the script it got called from

[groud]

What for ? This is going to need a complex code instrumentation for you to retrieve a debugging text you wrote yourself ?
For debugging complex things we have a debugger. Printing too many stuff to debug is never a good idea.

[karroffel]

For GDNative there are error and warning print methods, those show the file and line number where the print came from. These prints will display in Godot like errors and warning emitted from the engine itself.

https://github.com/godotengine/godot/blob/7d6f210ccb5de9ef414f94ad42f9f3dea14c0493/modules/gdnative/gdnative/gdnative.cpp#L131-L141

Only a few print types are supported yet

https://github.com/godotengine/godot/blob/8fc298be5f859fdb9b7b228793554dee6b025a09/core/error_macros.h#L51-L56

Maybe an ERR_HANDLER_INFO could be added for that purpose?

[groud]

Having a dedicated error function might be a good idea though, for this I guess it would make sense.

[blurymind]

@groud How are we going to call it?
printd? (as in print debug)

[Paulb23]

Related to #3884 and #13335

[groud]

perror() maybe?

[ghost]

perror is ambiguous imo. It's not obvious what p stands for, and might get confused with printerr

3884 suggests printl which I think is alright, but by existing methods prints and printt put separator between parameters. It could be misunderstood as such method because of its name.

I suggest printdbg or printdebug since we seem to prefer longer name than short-but-ambiguous name.

[Zylann]

You could make your own log function using print_stack(), but it would include the custom function too.

[Zylann]

In fact, stack trace only makes sense for errors. For debugging, you have the debugger and print_stack(). To clean up your prints, either prefix them with "DDD" or something, or globsearch for 'print'.

[chanon]

This is really needed.

The idea of displaying it like in Chrome (https://github.com/godotengine/godot/issues/3884#issuecomment-226439436) is also good.

[chanon]

Looking at the code for print and print_stack in gdscript_functions.cpp this actually doesn't look hard to implement. I'm fed up with searching my code for stray prints so I will be implementing this.

I don't know if my pull request would be accepted, so if people have more input on this then please comment.

There are two things that need to be decided.

1. The name of the method
2. What will it display and how will it display it

I see printdbg and printdebug proposed and highly voted for. Of the two I prefer printdbg. But actually since I will be using this new print almost exclusively, I'd rather it be shorter. But I guess it would not be standard? For example I'd actually prefer a method called debug or trace.

For display, I think it could look like

Printed message - res://path/to/file.gd:34

Another option is

Printed message     res://path/to/file.gd:34

(separated by two tabs)

And another option is

res://path/to/file.gd:34 - Printed message

(put the file in front instead .. and there is also option of tabs separating)

And finally, another option is to leave out the full path and just show the file name.

file.gd:34 - Printed message

Printed message - file.gd:34



md5-1e49ad1aa88c7de000cf2e9f91a4dcfb



Printed message     res://path/to/file.gd:34 in function '_ready'

I'm liking this last version with tab separation and full path plus function name best.

[chanon]

OK, I created a pull request with this implemented.
The method name is currently printdbg, but I still prefer trace.
The output is displayed as

Printed message     from res://path/to/file.gd:34 in function '_ready'

[chanon]

After trying this out in my project, I found the output is a bit hard to parse.

Here is an example:

It looks messy.

I tried putting the source on a different line and I think it is easier to read, however it creates more lines.

[chanon]

If the 'in function' part is removed, then it may also help with readability.

[Zylann]

Multiline is how Unity does it, however it also separates all prints by a newline.

I also remembered that non-blocking breakpoints can also be useful to fulfill some debug print use cases https://github.com/godotengine/godot/issues/6576

On top of that, the lack of error and warning prints let me think that Godot just misses a proper logging system accessible from scripts (https://github.com/godotengine/godot/issues/7095, though that focuses on C++), because for now you can only either assert or print with no further info or any way to opt-out, format or pipe the messages where you want. But that could be a separate issue though.

[chanon]

Here is the same print output without the 'in function...' part and using 'At: ' as a prefix like in the engine error log

I think this looks best. I will be updating the pull request.

[chanon]

What could also be done is to expose the stack information that print_stack uses to GDScript, so people could create their own logging method in GDScript. I'm not sure where it should be exposed though.
EDIT: added as pull request #18976

Yes, a proper logging system would be good. Also, better editor integration would be great, so that clicking on a log line could bring you to the file/line and color highlighting for errors/info in the output window. Just nice-to-have stuff, but can help with productivity (or could be seen as bloat by some).

[chanon]

Just to show how I've used the get_stack in #18976 to create a customized print method
Now with a print method that looks like this:

func debug(text):
    var frame = get_stack()[1]
    print( "%30s:%-4d %s" % [frame.source.get_file(), frame.line, text] )

The same print output now looks like this:

[blurymind]

@chanon your method looks great. It would be nice if it's a part of godot imo - its a pretty fundamental debugging feature

[akien-mga]

It would be nice if it's a part of gdevelop imo - its a pretty fundamental debugging feature

Wrong FOSS engine :wink:

[blurymind]

@akien-mga
hahah true, sorry - I've been contributing to it lately and get things mixed up xD
Come to think of it - not sure if gdevelop has a print to console action- but does have a debugger

Corrected my post

Btw the idea for this request came from chrome's/electron's console debugger - and most web browser consoles - the console.log() command always prints out where it came from - similar to @chanon 's implementation.
Another nice thing about it is that it stacks multiple logs into one entry - this is what Unity3d does as well

See for example in firefox:

You can even search printouts with a filter search - its really nice

Perhaps better for another request

[blurymind]

filed another feature request for the search filter:
https://github.com/godotengine/godot/issues/19098

In any case I should add that it would also be useful if the script name and line output are also clickable. When clicked it should open the script and line it points to.

[Zylann]

Do we have an issue open about logging in general? I've seen quite a lot of issues relating to this topic so far.

[blurymind]

I also raised an issue request for error stacking here
https://github.com/godotengine/godot/issues/19121

@Zylann I dont think there is one - but it would be nice to have one :)
Would you like me to open it?

[chanon]

With #18966 and #18976 merged, I think this can be closed.

[blurymind]

@chanon 🥇 Thank you =)

[Zylann]

And if we do https://github.com/godotengine/godot/issues/19974 we will be able to track normal prints too, I guess?