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 535223 - gbookmark file inefficiency ...
gbookmark file inefficiency ...
Status: RESOLVED FIXED
Product: glib
Classification: Platform
Component: general
2.16.x
Other Linux
: Normal normal
: ---
Assigned To: gtkdev
gtkdev
Depends on:
Blocks:
 
 
Reported: 2008-05-28 09:28 UTC by Michael Meeks
Modified: 2008-07-21 13:05 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
[PATCH] Fixed for GBookmarkFile (8.74 KB, patch)
2008-07-20 09:10 UTC, Emmanuele Bassi (:ebassi)
committed Details | Review

Description Michael Meeks 2008-05-28 09:28:25 UTC
Just stracing glib startup and I see:

  line  call
  3213	time(NULL)                              = 1211965787
...
  4610	time(NULL)                              = 1211965787

ie. we did over a thousand time calls (back to back) on startup ;-)

It seems it comes from here:

(gdb) bt
  • #0 *__GI_time
    at ../sysdeps/unix/sysv/linux/time.c line 29
  • #1 bookmark_app_info_new
    at gbookmarkfile.c line 230
  • #2 start_element_raw_cb
    at gbookmarkfile.c line 838
  • #3 IA__g_markup_parse_context_parse
    at gmarkup.c line 1348
  • #4 IA__g_bookmark_file_load_from_data
    at gbookmarkfile.c line 1430
  • #5 IA__g_bookmark_file_load_from_file
    at gbookmarkfile.c line 1719
  • #6 build_recent_items_list
    at gtkrecentmanager.c line 628


Of course - notice that 'time' returns a granularity of seconds anyway ;-)

How many seconds do we think it is going to take to parse the recent files ? and could we not simply call 'time' once ahead of time (sic) ;->
Comment 1 Michael Meeks 2008-05-28 09:32:37 UTC
in my glib - all callers of bookmark_app_info_new then set the stamp (or set it to time (NULL)) - or free the structure.

So the fix is:

-   retval->stamp = time (NULL);
+   retval->stamp = 0;

;-) of course - the saving in time is less than a second per app that uses bookmarks, but ... in some situations: eg. virtualised system calls like this are quite expensive.
Comment 2 Michael Meeks 2008-05-28 09:38:49 UTC
Interestingly the same bug would do well to be fixed in gtkrecentmanager.c at the same time ;-) [ cut & paste ? ].
Comment 3 Michael Meeks 2008-05-28 09:52:30 UTC
Yet more interestingly I see several thousands of:

  8765	stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3661, ...}) = 0
...
 10513	stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3661, ...}) = 0

all back to back; a cursory breakpoint in ___xstat64 shows that:

(gdb) bt
  • #0 ___xstat64
    at ../sysdeps/unix/sysv/linux/xstat64.c line 50
  • #1 __tzfile_read
    at tzfile.c line 170
  • #2 tzset_internal
    at tzset.c line 421
  • #3 __tzset
    at tzset.c line 577
  • #4 __strftime_internal
    at strftime_l.c line 572
  • #5 *__GI_strftime
    at strftime.c line 27
  • #6 IA__g_time_val_to_iso8601
    at gtimer.c line 415
  • #7 timestamp_to_iso8601
    at gbookmarkfile.c line 1561
  • #8 IA__g_bookmark_file_to_data
    at gbookmarkfile.c line 527
  • #9 IA__g_bookmark_file_to_file
    at gbookmarkfile.c line 1950
  • #10 gtk_recent_manager_real_changed
    at gtkrecentmanager.c line 450
  • #11 _gtk_recent_manager_sync
    at gtkrecentmanager.c line 2367
  • #12 IA__gtk_main
    at gtkmain.c line 1217
  • #13 main

It's not immediately clear what to do about that I guess ;-) but well - it's clearly not that ideal to be doing thousands of back-to-back stats of the same file micro-seconds apart ;-)
Comment 4 Emmanuele Bassi (:ebassi) 2008-06-04 06:43:43 UTC
(In reply to comment #2)
> So the fix is:
> 
> -   retval->stamp = time (NULL);
> +   retval->stamp = 0;
> 
> ;-) of course - the saving in time is less than a second per app that uses
> bookmarks, but ... in some situations: eg. virtualised system calls like this
> are quite expensive.

will apply in gbookmarkfile.c, and in gtkrecentmanager.c as well. thanks.

(In reply to comment #3)
> Yet more interestingly I see several thousands of:
> 
>   8765  stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3661, ...}) = 0

ugh.

> It's not immediately clear what to do about that I guess ;-) but well - it's
> clearly not that ideal to be doing thousands of back-to-back stats of the same
> file micro-seconds apart ;-)

the stat() of localtime is due to the conversion of the timestamps from string form to seconds from the epoch; this is really lame, glibc should be caching that stuff. other than that, we surely care about the timezone used to save a file inside the recently used files; maybe less so inside a bookmarks file, but special casing one is going to be a pain.(In reply to comment #1)
Comment 5 Michael Meeks 2008-06-04 09:00:59 UTC
Weelll ... ;-) reading the gbookmark.c code - I guess we could simply store the time internally in UTC - and thus avoid all the conversions on read, and all the conversions on write too: leaving just a few conversions for getters/setters - which (I hope) there are fewer of.

Failing that, we could store & invalidate a parallel 'gmtime' variant of each of the 3 fields at some cost. Of course - a solution to this:

$ grep '<bookmark:application ' ~/.recently-used.xbel  | wc -l
711

is also interesting - do we really need an ever-growing recently-used file ? :-)
Comment 6 Emmanuele Bassi (:ebassi) 2008-06-04 09:25:59 UTC
(In reply to comment #5)
> Weelll ... ;-) reading the gbookmark.c code - I guess we could simply store the
> time internally in UTC - and thus avoid all the conversions on read, and all
> the conversions on write too: leaving just a few conversions for
> getters/setters - which (I hope) there are fewer of.

the time is stored internally in UTC - because that's what it's written to and read from the storage file. but maybe I'm misunderstanding.

> $ grep '<bookmark:application ' ~/.recently-used.xbel  | wc -l
> 711
> 
> is also interesting - do we really need an ever-growing recently-used file ?
> :-)

it's not "ever-growing" anymore: the list is clamped at 30 days and it can be set to fewer (or more) days using GtkSettings:gtk-recent-files-max-age.
Comment 7 Michael Meeks 2008-06-04 11:40:37 UTC
Oh ? I assumed that it was converted to localtime on read & back again (via gmtime) on write for some reason: but it's not you're right :-)

Having said that - if we are calling gmtime ourselves anyway ... why don't we just write out the time information ourselves with a custom printf ? it's not as if we need much complexity to get from:

 struct tm {
               int tm_sec;         /* seconds */
               int tm_min;         /* minutes */
               int tm_hour;        /* hours */
               int tm_mday;        /* day of the month */
               int tm_mon;         /* month */
               int tm_year;        /* year */
...

to something like: ISO_8601_FORMAT "%Y-%m-%dT%H:%M:%SZ"

  2007-11-09T15:30:47Z

surely something like a g_strdup_printf ("%4d-%.2d-%.2dT%.2d:%.2d:%.2dZ") with the relevant fields would do just as well - and also produce a true ISO date - AFAICS from reading glibc: strftime seems to do some quite funky things around (eg.) 'eras' [ could an Arabic based date pop out of it ? ].

glibc/time/strftime_l.c (my_strftime) seems to have:

      /* POSIX.1 requires that local time zone information is used as
	 though strftime called tzset.  */
# if HAVE_TZSET
      tzset ();
# endif

meaning glibc prolly can't do much better for us here.
Comment 8 Matthias Clasen 2008-07-20 02:25:07 UTC
Emmanuele, whats the status of this ?
Comment 9 Emmanuele Bassi (:ebassi) 2008-07-20 09:04:23 UTC
I have some changes in the GBookmarkFile format I'm going to commit - plus some changes in the spec that I agreed with the KDE developers, as they are supporting the bookmark file format in their file selector.

I'll attach the patch to this bug, which contains the time() change Michael suggested, and a change in the format to reduce the number of strdup_printf() calls when writing to the file.
Comment 10 Emmanuele Bassi (:ebassi) 2008-07-20 09:10:26 UTC
Created attachment 114848 [details] [review]
[PATCH] Fixed for GBookmarkFile

the patch contains multiple fixes for GBookmarkFile:

- remove the Unix timestamp usage inside the metadata section; this was the last usage of a g_strdup_printf() inside the serialization code - see bug 518160 and bug 523877

- rework g_time_val_to_iso8601() to avoid the strftime() call and use the struct tm fields, as the format is fixed and we know how to serialize it.

- avoid calling time() multiple times.
Comment 11 Michael Meeks 2008-07-21 08:19:19 UTC
looks lovely to me :-) thakns Emmanuele.
Comment 12 Emmanuele Bassi (:ebassi) 2008-07-21 13:05:29 UTC
committed to trunk

2008-07-21  Emmanuele Bassi  <ebassi@gnome.org>

	* glib/gbookmarkfile.c:
	(bookmark_app_info_new): Do not set the timestamp value
	using time(), as it will be overwritten anyway. (#535223,
	Michael Meeks)

	(parse_application_element),
	(bookmark_app_info_dump): Support the "modified" attribute,
	which takes an ISO-formatted string instead of a Unix time
	stamp, to keep the number of g_strdup_printf() calls to a
	minimum.

	* glib/gtimer.c:
	(g_time_val_to_iso8601): Do not use strftime(): we know
	the format and contents of the ISO 8601 date format we
	use.

	* tests/bookmarks/valid-03.xbel: Add a test file for the
	modified attribute.