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 688337 - simple compile-time-selectable profiling points
simple compile-time-selectable profiling points
Status: RESOLVED OBSOLETE
Product: glib
Classification: Platform
Component: general
unspecified
Other Linux
: Normal enhancement
: ---
Assigned To: gtkdev
gtkdev
Depends on:
Blocks: 588139
 
 
Reported: 2012-11-14 17:23 UTC by Simon McVittie
Modified: 2018-05-24 14:50 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Add basic infrastructure for profiling points (7.90 KB, patch)
2012-11-14 17:25 UTC, Simon McVittie
none Details | Review
Emit profiling points around dispatch(), and for long dispatch() (1.57 KB, patch)
2012-11-14 17:26 UTC, Simon McVittie
none Details | Review
g_find_program_in_path: refactor to have a single exit path (1.54 KB, patch)
2012-11-14 17:26 UTC, Simon McVittie
none Details | Review
g_find_program_in_path: emit profiling messages (1.03 KB, patch)
2012-11-14 17:26 UTC, Simon McVittie
none Details | Review
g_file_get_contents: emit profiling messages (1.36 KB, patch)
2012-11-14 17:26 UTC, Simon McVittie
none Details | Review
g_file_set_contents: emit profiling messages (1.03 KB, patch)
2012-11-14 17:27 UTC, Simon McVittie
none Details | Review
Add some profiling to blocking D-Bus calls (5.16 KB, patch)
2012-11-14 17:27 UTC, Simon McVittie
none Details | Review
Add profiling points in gstdio functions (6.45 KB, patch)
2012-11-14 17:27 UTC, Simon McVittie
none Details | Review
g_spawn_sync: add profiling points (1.78 KB, patch)
2012-11-14 17:27 UTC, Simon McVittie
none Details | Review
g_settings_sync: add profiling points (1.78 KB, patch)
2012-11-14 17:28 UTC, Simon McVittie
none Details | Review
GLocalFileInputStream: emit profiling messages (1.45 KB, patch)
2012-11-14 17:28 UTC, Simon McVittie
none Details | Review
GLocalFileOutputStream: emit profiling messages (4.85 KB, patch)
2012-11-14 17:28 UTC, Simon McVittie
none Details | Review
GLocalFileInfo: emit profiling messages (3.07 KB, patch)
2012-11-14 17:28 UTC, Simon McVittie
none Details | Review
GLocalFile: emit profiling messages (6.27 KB, patch)
2012-11-14 17:29 UTC, Simon McVittie
none Details | Review

Description Simon McVittie 2012-11-14 17:23:27 UTC
A number of GNOME modules have access()-based "profiling points" which can be used in conjunction with strace to get an idea of how long an application spends, for instance, blocking on I/O. While working on Bug #687362 I've found it useful to add some of these to GLib and GIO.

I realise that in general, GNOME developers are more in favour of systemtap - perhaps because many GNOME developers use Fedora, which has a kernel with the utrace patchset necessary to make userland systemtap points useful...
Comment 1 Simon McVittie 2012-11-14 17:25:37 UTC
Created attachment 228984 [details] [review]
Add basic infrastructure for profiling points


Loosely based on what's in Folks, which was inspired by
<http://people.gnome.org/~federico/news-2006-03.html#timeline-tools>.

Yes, I know systemtap exists - but user-space systemtap tracepoints
require an unmerged kernel patch, whereas combining access() with
strace works anywhere. It's access() because that's: a syscall, making
it visible to strace; harmless, since it's read-only and has no
side-effects; and classed as a filename by strace, which means it
displays the argument in full, rather than truncating at 32 bytes.

Via some slightly ugly cpp, gprofileprivate.h can be used from either
GLib itself (in which case it's an intra-library call), or GObject/GIO
(in which case it's a GLIB_PRIVATE_CALL).

These profiling points are by no means zero-overhead - they are
themselves I/O, after all, and they contain a malloc/free - but they can
give a general picture of where the time is going, and how long
annotated functions take.
Comment 2 Simon McVittie 2012-11-14 17:26:04 UTC
Created attachment 228985 [details] [review]
Emit profiling points around dispatch(), and for long  dispatch()

---

Requires Bug #588139.
Comment 3 Simon McVittie 2012-11-14 17:26:20 UTC
Created attachment 228986 [details] [review]
g_find_program_in_path: refactor to have a single exit  path
Comment 4 Simon McVittie 2012-11-14 17:26:35 UTC
Created attachment 228987 [details] [review]
g_find_program_in_path: emit profiling messages
Comment 5 Simon McVittie 2012-11-14 17:26:47 UTC
Created attachment 228988 [details] [review]
g_file_get_contents: emit profiling messages
Comment 6 Simon McVittie 2012-11-14 17:27:03 UTC
Created attachment 228989 [details] [review]
g_file_set_contents: emit profiling messages
Comment 7 Simon McVittie 2012-11-14 17:27:17 UTC
Created attachment 228990 [details] [review]
Add some profiling to blocking D-Bus calls
Comment 8 Simon McVittie 2012-11-14 17:27:34 UTC
Created attachment 228991 [details] [review]
Add profiling points in gstdio functions
Comment 9 Simon McVittie 2012-11-14 17:27:48 UTC
Created attachment 228992 [details] [review]
g_spawn_sync: add profiling points
Comment 10 Simon McVittie 2012-11-14 17:28:01 UTC
Created attachment 228993 [details] [review]
g_settings_sync: add profiling points
Comment 11 Simon McVittie 2012-11-14 17:28:15 UTC
Created attachment 228994 [details] [review]
GLocalFileInputStream: emit profiling messages
Comment 12 Simon McVittie 2012-11-14 17:28:31 UTC
Created attachment 228995 [details] [review]
GLocalFileOutputStream: emit profiling messages
Comment 13 Simon McVittie 2012-11-14 17:28:45 UTC
Created attachment 228996 [details] [review]
GLocalFileInfo: emit profiling messages
Comment 14 Simon McVittie 2012-11-14 17:29:00 UTC
Created attachment 228997 [details] [review]
GLocalFile: emit profiling messages
Comment 15 Simon McVittie 2012-11-14 17:34:04 UTC
It isn't necessarily useful or important to have all of those profiling points: they're a first attempt at annotating a useful proportion of blocking calls, to get a general picture of what's going on when gnome-shell freezes for a moment.

They could probably benefit from some sort of bitmask to determine which ones are emitted.

I've deliberately made their interface such that they can log anything (e.g. useful context like filenames), and could equally well be any combination of: an access() trace point, a systemtap trace point, a valgrind VALGRIND_PRINTF, a write to stderr, or whatever.
Comment 16 Colin Walters 2013-01-04 16:21:49 UTC
The access() thing is quite a hack, but a useful improvement probably would be having a static string like /nonexistent/glibprofiling/ at the head of the filename, because on Linux at least you'll end up with exactly one /nonexistent in the negative dentry cache instead of polluting it with junk.

Anyways in the big picture, I think we should wait a little bit and see how the systemtap/perf stuff works out.

Note for example:

http://gnu.wildebeest.org/blog/mjw/2012/05/24/pull-user-space-probe-instrumentation/

Which is available in upstream Linux 3.5 (shipped in Ubuntu 12.10, Fedora 17+, but not Debian Wheezy which is 3.2).
Comment 17 Philip Withnall 2016-06-16 17:01:45 UTC
(In reply to Colin Walters from comment #16)
> Anyways in the big picture, I think we should wait a little bit and see how
> the systemtap/perf stuff works out.
> 
> Note for example:
> 
> http://gnu.wildebeest.org/blog/mjw/2012/05/24/pull-user-space-probe-
> instrumentation/
> 
> Which is available in upstream Linux 3.5 (shipped in Ubuntu 12.10, Fedora
> 17+, but not Debian Wheezy which is 3.2).

SystemTap upstream seem to think it's reasonably easy to use SystemTap on Debian:

https://www.sourceware.org/systemtap/wiki/SystemtapOnDebian

smcv potentially disagrees, but thinks he should probably take another look at SystemTap on Debian again at some point and re-evaluate how much technical debt there is (if any/if much).

So personally I think we can standardise on SystemTap rather than a series of ad-hoc debugging solutions (like as proposed here, but there are others). Not because they're bad, but because it seems a bit silly for everyone to reinvent the wheel each time they encounter an issue which needs debugging like this.

Close this?
Comment 18 GNOME Infrastructure Team 2018-05-24 14:50:27 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/glib/issues/630.