How to measure effects of OUString::intern ?

[Mark Wielaard]

On Tue, Jul 30, 2013 at 09:29:31AM +0100, Michael Meeks wrote:
> > > 	You saw the OUString debugging code: RTL_LOG_STRING_NEW /
> > > _STRING_DELETE etc. that can produce a long but crunch-able set of
> > > printfs on stdout: many of which are sadly not that useful due to
> > > OUStringBuffer mutation (IIRC - but presumably some more work could
> > > clean that up).
> > 
> > I hadn't seen that yet, but that might be useful to see which strings
> > are recreated multiple times and so are candidates for interning.
> > Is there already code to enable/trigger RTL_LOG_STRING_NEW?
> > Or should I just write my own hooks?
> 
> 	I guess you just write your own fprintf(stderr,) etc. in the strimp.hxx
> header ? of course, converting them to UTF8 and printing them is a bit
> of a PITA since strimp.hxx is used in both 8bit and 16bit strings.

I decided to add some SDT probes at the RTL_LOG_STRING_NEW/DELETE
locations. With a little preprocessor magic you can easily split it
in 8bit and 16bit variants (so this introduces probes for new_string_8,
new_string_16, delete_string_8, delete_string_16 with as arguments the
string, the refcount, length and buffer). The SDT probes have zero
overhead (just adds a NOP and a special ELF NOTES section to the binary)
and can be used with gdb or systemtap to collect some statistics
(or simply just log/print all strings created/deleted). They are also
source compatible with dtrace for systems that supports that (I have never
used dtrace so I hope someone could test that). Could you have a look if
that looks fine to integrate: https://gerrit.libreoffice.org/5256

Hopefully that will make it easier to reason about how to handle strings.
For example this will give the 20 most created strings (refCount == 1):

[mark at toonder libreoffice (master)]$ stap -e 'global strings[60000]; probe process("install/ure/lib/libuno_sal.so.3").mark("new_string_16") { if ($arg2 == 1) strings[user_string_utf16($arg4)]++ }' -c install/program/soffice | head -20
strings["en-US"]=0x28d2
strings["file://"]=0x2277
strings["/"]=0x1883
strings["void"]=0x12be
strings["en"]=0x128f
strings["/usr/local"]=0xb1f
strings["Label"]=0x9c0
strings["US"]=0x94d
strings["Name"]=0x8f0
strings["string"]=0x879
strings["/home/mark"]=0x86b
strings[""]=0x767
strings["any"]=0x6e4
strings["Type"]=0x666
strings["UIName"]=0x656
strings["type"]=0x631
strings["^"]=0x5e0
strings["Command"]=0x5de
strings["bin/java"]=0x5c5
strings["jre/bin/java"]=0x5c5

That should give us a hint about which strings would benefit from interning.
The empty string is already special cases, which looks like a good thing.
The top two seem to come from detecting the current locale and creating
URLs for local files. It also shows libreoffice trying to find a usable
java binary creates lots of strings (it looks like a lot of different
locations are tried).

Looking at the 8-bit strings is also interesting:
$ stap -e 'global strings[60000]; probe process("install/ure/lib/libuno_sal.so.3").mark("new_string_8") { if ($arg2 == 1) strings[user_string($arg4)]++ }' -c install/program/soffice | head -20
strings[" "]=0x1485
strings["115 117 110 46 98 111 111 116 46 99 108 97 115 115 46 112 97 116 104 61 47 117 115 114 47 108 105 98 47 106 118 109 47 106 97 118 97 45 49 46 55 46 48 45 111 112 101 110 106 100 107 45 49 46 55 46 48 46 50 53 45 50 46 51 46 49 48 46 49 48 46 102 99 49 57 46 120 56 54 95 54 52 47 106 114 101 47 108 105 98 47 114 101 115 111 117 114 99 101 115 46 106 97 114 58 47 117 115 114 47 108 105 98 47 106 118 109 47 106 97 118 97 45 49 46 55 46 48 45 111 112 101 110 106 100 107 45 49 46 55 46 48 46 50 53 45 50 46 51 4"]=0xb31
strings["><value"]=0x702
strings["</prop>"]=0x702
strings["46"]=0x4dd
strings["1"]=0x488
strings["97"]=0x34b
strings["/"]=0x2a9
strings["101"]=0x29c
strings["114"]=0x271
strings["47"]=0x260
strings["0"]=0x25a
strings["105"]=0x239
strings["110"]=0x238
strings["111"]=0x1f7
strings["115"]=0x1c3
strings["106"]=0x1b1
strings["*include:"]=0x1aa
strings["en-us"]=0x19c
strings["-"]=0x194

Most of those are created by the ppdparser which slurps in .ppd files as
a std::vector of OStrings and then runs a parse (two times?) over them.
I wonder if that could be done more efficiently. And also why does it do
that during startup, isn't that only needed when printing?

Cheers,

Mark