After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 702758 - Add a tracing functionality to Vala
Add a tracing functionality to Vala
Status: RESOLVED OBSOLETE
Product: vala
Classification: Core
Component: Methods
unspecified
Other Linux
: Normal enhancement
: ---
Assigned To: Vala maintainers
Vala maintainers
Depends on:
Blocks:
 
 
Reported: 2013-06-20 16:42 UTC by Anirudh Sanjeev
Modified: 2018-05-22 14:49 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Patch to add trace functionality (3.41 KB, patch)
2013-06-20 16:42 UTC, Anirudh Sanjeev
none Details | Review
Updated patch to also print timestamp with the logs (3.69 KB, patch)
2013-06-21 14:39 UTC, Anirudh Sanjeev
none Details | Review
Patch to add trace functionality (4.98 KB, patch)
2013-06-22 13:52 UTC, Anirudh Sanjeev
none Details | Review

Description Anirudh Sanjeev 2013-06-20 16:42:10 UTC
Created attachment 247356 [details] [review]
Patch to add trace functionality

This patch adds a new argument `--enable-trace` to valac which enables tracing the path the program is taking, by printing the name of each function that is executed to stdout.

The benefit of this is that it will help someone quickly identify relevant functions in an unfamiliar codebase. Enabling tracing and reproducing a bug will give a user a starting point of functions to look at, improving developer productivity.
Comment 1 Anirudh Sanjeev 2013-06-21 14:39:12 UTC
Created attachment 247448 [details] [review]
Updated patch to also print timestamp with the logs

I was dog-fooding the trace functionality and found that it's better if there's a timestamp when working with GUI apps.

The workflow for using trace on a GUI app is as follows:

1. Enable trace and compile.
2. Run the program, this would likely output a lot of trace statements.
3. Move your mouse over the GUI element you want to activate (which might trigger some mouseover messages)
4. Wait 4-5 seconds
5. Activate the GUI element with your mouse.

Since you wait, the functions when you activate the element will have a new timestamp and will be easier to differentiate.
Comment 2 Luca Bruno 2013-06-21 18:27:08 UTC
What about creating a gdb or systemtap script to trace method calls instead?
Comment 3 Anirudh Sanjeev 2013-06-22 07:26:28 UTC
I have been able to get tracing working through systemtap, based on a blog post by fabiand [1], yet I proceeded to write this patch.

Here is my reasoning, as a list of advantages my approach offers:

1. Simplicity: Activate the feature by just passing another argument to the compiler. And simply re-compile when you want to turn off the trace. For a new/casual contributor, this might make a world of difference.

2. Show actual Vala function names, and class names, rather than showing the names of the generated C functions.

3. Only Relevant Functions: The systemtap approach requires you to specify a regex of functions that you wish to trace. On larger projects with multiple classes/namespaces this might be unfeasible. On the other hand "--enable-trace" only shows functions that are written in vala, not the calls to glib/gtk.

4. [In development] Show param values, thread ID: I am improving the patch to show the values of parameters passed to the function if it's a common type like int/string/etc. This will vastly help debugging. It will also show the thread ID and help debug race conditions and multi-threading issues.

[1]: http://dummdida.blogspot.in/2011/10/hinterher-tracing-vala-c-code-with.html
Comment 4 Luca Bruno 2013-06-22 07:31:39 UTC
(In reply to comment #3)
> 2. Show actual Vala function names, and class names, rather than showing the
> names of the generated C functions.

What about valac -g ?

> 3. Only Relevant Functions: The systemtap approach requires you to specify a
> regex of functions that you wish to trace. On larger projects with multiple
> classes/namespaces this might be unfeasible. On the other hand "--enable-trace"
> only shows functions that are written in vala, not the calls to glib/gtk.

Vala projects are usually well namespaced, so a regex would be perfect.

> 
> 4. [In development] Show param values, thread ID: I am improving the patch to
> show the values of parameters passed to the function if it's a common type like
> int/string/etc. This will vastly help debugging. It will also show the thread
> ID and help debug race conditions and multi-threading issues.

This could be done in gdb too I believe.
Comment 5 Anirudh Sanjeev 2013-06-22 08:06:13 UTC
(In reply to comment #4)
> What about valac -g ?

Yes, it is easy to infer the name of the method from a C function name. But this approach becomes significantly harder when function is generated from a lambda. It required me to go look a the #line in the C file, and find it in the original vala file.

By re-using vala's own infrastructure, my patch prints the exact line of even lambda functions.

> Vala projects are usually well namespaced, so a regex would be perfect.

There are examples of the contrary as well, as far as I've seen. Shotwell, for instance has numerous namespaces.

> This could be done in gdb too I believe.

Yes. This requires setting tracepoints, and using tdump to dump the collected data for each trace point. But from my understanding, it's not "real-time" when the user can see the correlation between a click and the functions that were executed as a result of that.

Since Vala emits C and ELF binaries there are a variety of great tools which perform the same functionality that my patch proposes.

My patch doesn't add functionality but merely makes it friction-less and convenient to use tracing functionality. I found that the Vala compiler has great infrastructure to emit relevant information directly during Codegen, and I decided to leverage it.

Ultimately it all comes down to the **simplicity**. This patch doesn't break any functionality, and is aimed solely to benefit casual/novice contributors to GNOME projects (like myself) written in Vala. If that doesn't seem like a good enough reason, please close this bug and I will maintain the patch for my personal usage.
Comment 6 Luca Bruno 2013-06-22 08:20:02 UTC
(In reply to comment #5)
> Yes, it is easy to infer the name of the method from a C function name. But
> this approach becomes significantly harder when function is generated from a
> lambda. It required me to go look a the #line in the C file, and find it in the
> original vala file.

I don't get it, don't you get directly the Vala function name when using valac -g ? At least in gdb.

> GNOME projects (like myself) written in Vala. If that doesn't seem like a good
> enough reason, please close this bug and I will maintain the patch for my
> personal usage.

I just think external tools may do this without the need to integrate into valac. At all you're writing the scripts once for all.
Comment 7 Anirudh Sanjeev 2013-06-22 13:52:32 UTC
Created attachment 247516 [details] [review]
Patch to add trace functionality

This is the final version of the patch which has all the functionality which I wan to add. The trace shows:

1. Timestamp of function invocation.
2. Location of function in the source code.
3. Name of function
4. List of arguments to the function
5. If the argument is a string/int/float, then print the value as well.

Example output for GNOME Gitg:

[1371908873] gitg-lanes.vala:107.2-107.24  Gitg.Lanes.next(Gitg.Commit, int:-1056355244, )
[1371908873] gitg-lanes.vala:448.2-448.48  Gitg.Lanes.find_lane_by_oid(Ggit.OId, int:-1056355368, )
[1371908873] gitg-color.vala:108.2-108.18  Gitg.Color.copy()
[1371908873] gitg-color.vala:23.1-23.27  Gitg.Color.new()
[1371908873] gitg-lanes.vala:473.2-473.31  Gitg.Lanes.lanes_list()
[1371908873] gitg-lane.vala:58.2-58.17  Gitg.Lane.copy()
[1371908873] gitg-lane.vala:46.2-46.23  Gitg.Lane.with_color(Gitg.Color?, )
[1371908873] gitg-lanes.vala:142.2-142.27  Gitg.Lanes.prepare_lanes(Gitg.Commit, int:0, )
[1371908873] gitg-lanes.vala:438.2-438.29  Gitg.Lanes.init_next_layer()
[1371908873] gitg-lanes.vala:58.3-58.18  Gitg.Lanes.LaneContainer.next(int:0, )
[1371908873] gitg-lane.vala:58.2-58.17  Gitg.Lane.copy()
[1371908873] gitg-lane.vala:46.2-46.23  Gitg.Lane.with_color(Gitg.Color?, )
[1371908873] gitg-commit.vala:76.2-76.25  Gitg.Commit.update_lanes(GLib.SList<Gitg.Lane>, int:0, )
[1371908873] gitg-commit.vala:62.2-62.29  Gitg.Commit.update_lane_tag()
Comment 8 Anirudh Sanjeev 2013-06-22 14:13:48 UTC
(In reply to comment #6)
> I just think external tools may do this without the need to integrate into
> valac. At all you're writing the scripts once for all.

Yes, you are correct that there are ways to reproduce the functionality that this patch provides without using this patch. And yes, writing the script, and setting it up once solves the problem once and for all.

Also, I tried reproducing this functionality in Gdb and systemtap as a learning exercise, and I wasn't able to.

The way I see it from the Vala Team's perspective, the consequences of accepting my patch is this:

Cons:
* Have to maintain this feature and fix any regressions this might introduce with future versions (I have ran tests and they all pass)

Pros:
* Gives all vala users tracing functionality with nothing extra to install or configure.

I completely understand if you feel that the patch is not acceptable.
Comment 9 GNOME Infrastructure Team 2018-05-22 14:49:31 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to GNOME's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.gnome.org/GNOME/vala/issues/383.