[Ecls-list] Slow prettyprinting (update)

[Waldek Hebisch]

I have written that prettyprinting in ECL is slow.  To investigate
that further I have build profiling version of ECL.  I did this
using the following configure command line:

CFLAGS='-g -p -Os' LDFLAGS='-g -p' ./configure --enable-shared=no --prefix=/var/tmp/hebisch/usrp > clogg 2>&1 &

Note that '-Os' means that code will be optimized for space, which
is different than '-O2' optimization normally used by ECL.

First, a little disclaimer: there is a substantial difference in real
time needed to run program and run time showing in the profile.  So,
a lot of time is spent in un-profiled code.  This means time spent in
profiling machinery (counting how many times each function is called)
and also time spent in C library.  Since time showing in the profile
does not differ too much from time spent on uprofiled run (3.38s compared
to 5.01s) I belive that the results have some relevance.

I have used a test file which contains a single S-expression.  wc
reports 14280 words and 110843 characters.

I compared two runs: one where I read the file and print the length
of resulting list and the second one where I pretty-print the list.

Now, I noted a strange thing: profiler tells me that about 1.60s
(that is _half_) of the execution time showing in the profile
is spent in ecl_read_object_with_delimiter and functions
called from it.

OTOH the run where I read the file shows that speed of reading is 
reasonable (total time for reading is 0.08s in profiling version
and 0.017s in unprofiled one).

So, the question is what is ecl_read_object_with_delimiter reading,
and why it takes so much time?  I have noticed that ECL puts
constant data in strings, maybe reading constants is resposible
for this?

BTW: I also noticed that ECL has substantial startup time, it
seems that cl_read_object_with_delimiter has non-trivial part
in the startup time.

-- 
                              Waldek Hebisch
hebisch at math.uni.wroc.pl