Performance profiling of makeinfo

[Gavin Smith]

Inspired by Patrice's upload of profiling information for Parser.pm
with NYTProf (at http://pertusus.free.fr/nytprof/#f20), I thought I
would try profiling a run of makeinfo the same way. Eventually I
managed to install NYTProf, and ran it on elisp.texi from the Emacs
distribution (about 3.3M with all of its included files).

I don't really have anywhere to upload the results (if anybody is
interested they could always run a profile themselves), but here is
the summary of the top 15 functions:

115720;9;2;74.3s;133s;Texinfo::Convert::Paragraph::add_text

4680;2;1;48.3s;147s;Texinfo::Parser::_parse_texi (recurses: max depth
1, inclusive time 1.48s)

302718;23;2;36.9s;334s;Texinfo::Convert::Plaintext::_convert
(recurses: max depth 16, inclusive time 1442s)

37432;5;1;29.9s;57.8s;Texinfo::Parser::_deep_copy

438510;3;1;27.5s;29.6s;Texinfo::Convert::Paragraph::_add_next

37432;1;1;25.7s;27.3s;Data::Dumper::Dumpxs (xsub)

280448;3;1;19.6s;27.9s;Texinfo::Parser::_merge_text

394106;3;1;16.7s;16.7s;Texinfo::Convert::Paragraph::_add_pending_word

19891;10;2;11.7s;14.8s;Texinfo::Convert::Unicode::string_width

263915;1;1;11.0s;22.4s;Encode::encode

2765110;7;1;10.9s;10.9s;Texinfo::Convert::Paragraph::CORE:subst (opcode)

211376;26;1;10.5s;45.5s;Texinfo::Convert::Plaintext::_count_added

202838;2;1;9.85s;13.0s;Texinfo::Convert::Unicode::unicode_text

140272;1;1;6.14s;19.1s;Texinfo::Convert::Plaintext::_process_text

320630;8;1;6.04s;6.04s;Texinfo::Parser::_abort_empty_line

First number is the number of calls of the function, the first length
of time given is time spent in the function excluding other functions
called, and the second length of time includes time in other
functions.

The parser we know about already; I think Patrice had a look at this
before and couldn't see any obvious speed-ups.

I note a significant amount of time is spent in _deep_copy, which
takes a dump of a data structure and then reads it back in again with
"eval". Patrice, do you think it is worth investigating other ways of
duplicating a data structure? I saw a page at
http://stackoverflow.com/questions/388187/whats-the-best-way-to-make-a-deep-copy-of-a-data-structure-in-perl
that suggested using the "Clone" module instead.

The other surprise is how long it seems to take just refilling
paragraphs, in add_text in Paragraph.pm (28% of the total run time).
The detailed profiling information shows that Perl spends a lot of
time just in regular expressions.

I did try a few tweaks (for example, using the anchor \G and the "gc"
flag for regexes instead of removing the leading text, or getting the
function arguments without shift, like is recommended at
http://makepp.sourceforge.net/2.0/perl_performance.html), but it made
no noticable difference. I thought changing the logic inside add_text
to avoid repeating a check for whitespace when we have just checked
for whitespace might make a difference, but it appeared not to make a
difference, or if there was one it was so minor it was swamped by
variations in the time it took to run the program.

The only thing that maybe made a small difference was commenting out
anything to do with "underlying text", which possibly isn't used for
anything apart from debugging output (I think this is used if the case
of the text was changed).

I figure the best chance to speed up the calls to add_text is to
rewrite Paragraph.pm in C. This would also avoid the overhead of Perl
function calls to add_next for each word or gap between words. It
looks simple enough that the logic won't be that difficult. (Much
simpler than replacing Parser.pm, anyway.) We could get the screen
width of characters with the wcwidth function. I haven't made any
progress yet on rewriting the algorithm in C; I've spent some time
trying to figure out how to pass information between the main Perl
program in Plaintext.pm and an XS module.