guile-2.9.1 impressions

guile-2.9.1 impressions

[Linas Vepstas]

So I pulled guile-2.9.1(beta) today, and gave it a spin. Looks
good/great! One bug -- some crazy multithreading bug,
reported as #33641

My use case: guile calling C++ code, which calls guile, which
calls C, ad nauseum. I have some 133 unit tests, of which
maybe 3/4ths tweak guile in some way. All but the
multi-threading pass, so happy!

Some comments about performance in this crazy-quilt
mixed environment. Most of code, both guile and C/C++
is fairly "thin", not doing a whole lot, before transitioning
into the other language. Thus, the performance is dominated
by the cost of the switch.

There are two different switches: from C++ to guile, and
from guile to C++.  For the first, I'm seeing a rate of about
30K  switches/sec C++ into guile (and back, this includes the return).

Calls going the other way are about 800K switches/sec
from guile into C++ (this also includes the return).   This is
on a 2014-vintage machine.

Clearly a big difference between the two. Many years ago,
I profiled this, but don't recall the results. The profile did not
reveal anything I could control very much or at all.

Thus, In this scenario, I don't really expect the gnu lightning
bytecode to affect performance very much; I'm mostly
bottlnecked in the switching of environments.

FWIW, I'm seeing speedups of 1x to 1.5x for interpreted
mode, and 1.3x to 2x for compiled code. Don't read too
much into these numbers: They're crazy mixes of calls
going in both directions.  But still, that's really quite good,
all things considered!

-- Linas

I cc'ed both guile-user and guile-devel; I'm not subscribed
to guile-devel, but also I did not see a 2.9.1-beta announce
on guile-user!
-- 
cassette tapes - analog TV - film cameras - you

Re: guile-2.9.1 impressions

[Linas Vepstas]

After sending the email below, I scanned the guile-devel archives,
and I see Thomas Morley talking about Lilypond performance.
The example program he offers up caught my eye: nested deep
in a loop is this:

(eval-string "'(a b c)")

Well -- oh -- ha -- I think this is the same culprit that is one of my
significant bottlenecks.  Although I'm mixing C++ and guile very
intensely, my main C++-calling-into-guile is more-or-less eval-string.
(its actually scm_eval_string() for me).  So I think that I can call and
and return from scm_eval_string() about 40K/sec on a five-year-old
vintage machine, passing it some trivial thing to evaluate.  (Python
is in a similar ballpark, if that provides any motivation.)

I'll bet, given Thomas' comments, that scm_eval_string() was thinner
and faster on guile-1.8.8

Thomas also mentioned the "string problem" ... I recall that, when
I looked string handling in the guile-2.1.x codebase, there was a
whole lotta pointless conversion back and forth between utf8 and
double-byte wide chars.  It was just tangled, for no good technical
reason. Code read like a bleary-eyed 3AM coding session, with
"obvious" inefficiencies in it.  Fixing it seemed "easy"; there's no
comp-sci in it, nothing subtle.  It was mostly just a tangle of spaghetti
trying to handle locales every which by by converting .. too many times.

I thought I might fix that but I got .. busy doing other things.  This might
be an unfair complaint, as it might very well be fixed in guile-2.2 or
guile-2.9 but ... if there is a string problem, the impression that strings
are slow, I suggest that an audit of the string handling code may well
reveal that the excessive conversions are still there.

In particular, I think the excessive string-conversion code showed up
in guile-2.0 and got worse in 2.2 as broader utf8 support was added ...

(I also humbly suggest that the guile internals should be 100% utf8.
From long experience, utf8 is amazingly clean and simple, and all the
other encoding schemes are just horrid messes of hacks and ick and
needless complexity and confusing confusion.)

-- Linas

On Wed, Dec 5, 2018 at 9:56 PM Linas Vepstas <linasvepstas@gmail.com> wrote:
>
> So I pulled guile-2.9.1(beta) today, and gave it a spin. Looks
> good/great! One bug -- some crazy multithreading bug,
> reported as #33641
>
> My use case: guile calling C++ code, which calls guile, which
> calls C, ad nauseum. I have some 133 unit tests, of which
> maybe 3/4ths tweak guile in some way. All but the
> multi-threading pass, so happy!
>
> Some comments about performance in this crazy-quilt
> mixed environment. Most of code, both guile and C/C++
> is fairly "thin", not doing a whole lot, before transitioning
> into the other language. Thus, the performance is dominated
> by the cost of the switch.
>
> There are two different switches: from C++ to guile, and
> from guile to C++.  For the first, I'm seeing a rate of about
> 30K  switches/sec C++ into guile (and back, this includes the return).
>
> Calls going the other way are about 800K switches/sec
> from guile into C++ (this also includes the return).   This is
> on a 2014-vintage machine.
>
> Clearly a big difference between the two. Many years ago,
> I profiled this, but don't recall the results. The profile did not
> reveal anything I could control very much or at all.
>
> Thus, In this scenario, I don't really expect the gnu lightning
> bytecode to affect performance very much; I'm mostly
> bottlnecked in the switching of environments.
>
> FWIW, I'm seeing speedups of 1x to 1.5x for interpreted
> mode, and 1.3x to 2x for compiled code. Don't read too
> much into these numbers: They're crazy mixes of calls
> going in both directions.  But still, that's really quite good,
> all things considered!
>
> -- Linas
>
> I cc'ed both guile-user and guile-devel; I'm not subscribed
> to guile-devel, but also I did not see a 2.9.1-beta announce
> on guile-user!
> --
> cassette tapes - analog TV - film cameras - you



-- 
cassette tapes - analog TV - film cameras - you

Re: guile-2.9.1 impressions

[Andy Wingo]

Hi!

On Thu 06 Dec 2018 06:21, Linas Vepstas <linasvepstas@gmail.com> writes:

> After sending the email below, I scanned the guile-devel archives,
> and I see Thomas Morley talking about Lilypond performance.
> The example program he offers up caught my eye: nested deep
> in a loop is this:
>
> (eval-string "'(a b c)")

In this case I believe Guile 2.9 / 3 should be significantly faster than
2.2, because `eval' is compiled to native code rather than bytecode.  My
measurements showed it to be on par with the hand-optimized C
implementation from 1.8 and before.  Depends of course on how much the
expander is part of your workload, there are differences relative to
Guile 1.8.  Anyway, thanks for the note and I just wanted to mention
this point.

Regarding Scheme -> C++ transitions, there is the possibility that this
too could be much faster with Guile 2.9.x given that these calls are now
JIT-compiled instead of interpreted.  We'll have to see.

Cheers,

Andy

Re: guile-2.9.1 impressions

[Linas Vepstas]

[-- Attachment #1: Type: text/plain, Size: 3200 bytes --]

Hi Andy,

Thanks!  I just tried out the master branch of guile in git (the one tagged
v2.9.2). It now passes all of my unit tests.  So that's good! ... More or
less -- there's still some infrequent multi-threading bug(s).  Let me
describe.

My unit test just transitions C->guile->C and returns, in rapid succession,
in 20 threads. So, in pseudocode:

SCM do_stuff(SCM a, SCM b) {
      scm_to_utf8_string(a);
      scm_to_int(b);
     ... minor stuff... return scm_from_int(...);
}
scm_c_define_gsubr("do-things",2,0,0, do_stuff);

void thing_doer(int thread_id) {
     for (i=0; i=15000; i++)
           char str[100];
           sprintf(str, "(do-things foo %d)", i);
           scm_c_catch(scm_eval_string,  str);
}

main () {
      for (int i=1; i<15; i++)   // start 15 threads
            std::thread(&thing_doer, i);
}

I'm guessing the above code spends maybe 90% of its time bouncing between
guile and C. The string "(do-things foo 42)" changes each time in the loop,
so, not sure how the compile vs. interpret tradeoff is done.  Either way,
its relatively trivial. Likewise, the do_stuff() C routine is fairly thin;
after decoding it's args, it doesn't do all that much (sub-microsecond of
computing).  Based on old, old measurements, scm_eval_string really is the
primary CPU consumer, in the 20-microseconds range. Launching 15 threads
means that this thing is racing as fast as it can.

Anyway, with guile-2.9.2, the above crashes after about 10-15 minutes,
either with memory corruption, or with segfault.  I worried, so I retested
with guile-2.2.4 ... which also crashes, but much much less frequently:
seven times in 44 hours wall-clock time (so once ever 6 hours).  Which is
still more than desired, but...OK.

So where's the crash? No clue. Could be my code, could be guile. Since
there's a big difference between guile-2.2 and guile-2.9, I'm ready to
blame guile. I did try to run it with `valgrind --tool helgrind` and got an
ocean of complaints about guile GC, which are probably harmless. I haven't
tried to dig deeper yet.

-- Linas


On Thu, May 23, 2019 at 2:28 PM Andy Wingo <wingo@pobox.com> wrote:

> Hi!
>
> On Thu 06 Dec 2018 06:21, Linas Vepstas <linasvepstas@gmail.com> writes:
>
> > After sending the email below, I scanned the guile-devel archives,
> > and I see Thomas Morley talking about Lilypond performance.
> > The example program he offers up caught my eye: nested deep
> > in a loop is this:
> >
> > (eval-string "'(a b c)")
>
> In this case I believe Guile 2.9 / 3 should be significantly faster than
> 2.2, because `eval' is compiled to native code rather than bytecode.  My
> measurements showed it to be on par with the hand-optimized C
> implementation from 1.8 and before.  Depends of course on how much the
> expander is part of your workload, there are differences relative to
> Guile 1.8.  Anyway, thanks for the note and I just wanted to mention
> this point.
>
> Regarding Scheme -> C++ transitions, there is the possibility that this
> too could be much faster with Guile 2.9.x given that these calls are now
> JIT-compiled instead of interpreted.  We'll have to see.
>
> Cheers,
>
> Andy
>


-- 
cassette tapes - analog TV - film cameras - you

[-- Attachment #2: Type: text/html, Size: 4416 bytes --]

Re: guile-2.9.1 impressions

[Linas Vepstas]

[-- Attachment #1: Type: text/plain, Size: 3882 bytes --]

Andy,

I want to temporarily, maybe permanently retract my last email. I found a
bug(let) in the intialization of my unit test that appears to maybe account
for all observed crashes, maybe. I'm re-verifying on multiple machines but
this will take 24-48 hours.  Basically, it looks like guile-2.9.2 is crash
free (for the last 6 hours) on one os/compiler/glibc combination, I have to
cross-check on another.

--linas

On Sun, May 26, 2019 at 8:40 AM Linas Vepstas <linasvepstas@gmail.com>
wrote:

> Hi Andy,
>
> Thanks!  I just tried out the master branch of guile in git (the one
> tagged v2.9.2). It now passes all of my unit tests.  So that's good! ...
> More or less -- there's still some infrequent multi-threading bug(s).  Let
> me describe.
>
> My unit test just transitions C->guile->C and returns, in rapid
> succession, in 20 threads. So, in pseudocode:
>
> SCM do_stuff(SCM a, SCM b) {
>       scm_to_utf8_string(a);
>       scm_to_int(b);
>      ... minor stuff... return scm_from_int(...);
> }
> scm_c_define_gsubr("do-things",2,0,0, do_stuff);
>
> void thing_doer(int thread_id) {
>      for (i=0; i=15000; i++)
>            char str[100];
>            sprintf(str, "(do-things foo %d)", i);
>            scm_c_catch(scm_eval_string,  str);
> }
>
> main () {
>       for (int i=1; i<15; i++)   // start 15 threads
>             std::thread(&thing_doer, i);
> }
>
> I'm guessing the above code spends maybe 90% of its time bouncing between
> guile and C. The string "(do-things foo 42)" changes each time in the loop,
> so, not sure how the compile vs. interpret tradeoff is done.  Either way,
> its relatively trivial. Likewise, the do_stuff() C routine is fairly thin;
> after decoding it's args, it doesn't do all that much (sub-microsecond of
> computing).  Based on old, old measurements, scm_eval_string really is the
> primary CPU consumer, in the 20-microseconds range. Launching 15 threads
> means that this thing is racing as fast as it can.
>
> Anyway, with guile-2.9.2, the above crashes after about 10-15 minutes,
> either with memory corruption, or with segfault.  I worried, so I retested
> with guile-2.2.4 ... which also crashes, but much much less frequently:
> seven times in 44 hours wall-clock time (so once ever 6 hours).  Which is
> still more than desired, but...OK.
>
> So where's the crash? No clue. Could be my code, could be guile. Since
> there's a big difference between guile-2.2 and guile-2.9, I'm ready to
> blame guile. I did try to run it with `valgrind --tool helgrind` and got an
> ocean of complaints about guile GC, which are probably harmless. I haven't
> tried to dig deeper yet.
>
> -- Linas
>
>
> On Thu, May 23, 2019 at 2:28 PM Andy Wingo <wingo@pobox.com> wrote:
>
>> Hi!
>>
>> On Thu 06 Dec 2018 06:21, Linas Vepstas <linasvepstas@gmail.com> writes:
>>
>> > After sending the email below, I scanned the guile-devel archives,
>> > and I see Thomas Morley talking about Lilypond performance.
>> > The example program he offers up caught my eye: nested deep
>> > in a loop is this:
>> >
>> > (eval-string "'(a b c)")
>>
>> In this case I believe Guile 2.9 / 3 should be significantly faster than
>> 2.2, because `eval' is compiled to native code rather than bytecode.  My
>> measurements showed it to be on par with the hand-optimized C
>> implementation from 1.8 and before.  Depends of course on how much the
>> expander is part of your workload, there are differences relative to
>> Guile 1.8.  Anyway, thanks for the note and I just wanted to mention
>> this point.
>>
>> Regarding Scheme -> C++ transitions, there is the possibility that this
>> too could be much faster with Guile 2.9.x given that these calls are now
>> JIT-compiled instead of interpreted.  We'll have to see.
>>
>> Cheers,
>>
>> Andy
>>
>
>
> --
> cassette tapes - analog TV - film cameras - you
>


-- 
cassette tapes - analog TV - film cameras - you

[-- Attachment #2: Type: text/html, Size: 5449 bytes --]

Re: guile-2.9.1 impressions

[Linas Vepstas]

[-- Attachment #1: Type: text/plain, Size: 4371 bytes --]

I've put in a cumulative of 36 hours guile-2.9.2 multi-threaded stress
testing on two different OS/compiler/glibc combinations, and have seen
exactly zero crashes or hangs so far.  So it's perfect. Sorry for earlier
confusion. -- linas

On Sun, May 26, 2019 at 11:40 PM Linas Vepstas <linasvepstas@gmail.com>
wrote:

> Andy,
>
> I want to temporarily, maybe permanently retract my last email. I found a
> bug(let) in the intialization of my unit test that appears to maybe account
> for all observed crashes, maybe. I'm re-verifying on multiple machines but
> this will take 24-48 hours.  Basically, it looks like guile-2.9.2 is crash
> free (for the last 6 hours) on one os/compiler/glibc combination, I have to
> cross-check on another.
>
> --linas
>
> On Sun, May 26, 2019 at 8:40 AM Linas Vepstas <linasvepstas@gmail.com>
> wrote:
>
>> Hi Andy,
>>
>> Thanks!  I just tried out the master branch of guile in git (the one
>> tagged v2.9.2). It now passes all of my unit tests.  So that's good! ...
>> More or less -- there's still some infrequent multi-threading bug(s).  Let
>> me describe.
>>
>> My unit test just transitions C->guile->C and returns, in rapid
>> succession, in 20 threads. So, in pseudocode:
>>
>> SCM do_stuff(SCM a, SCM b) {
>>       scm_to_utf8_string(a);
>>       scm_to_int(b);
>>      ... minor stuff... return scm_from_int(...);
>> }
>> scm_c_define_gsubr("do-things",2,0,0, do_stuff);
>>
>> void thing_doer(int thread_id) {
>>      for (i=0; i=15000; i++)
>>            char str[100];
>>            sprintf(str, "(do-things foo %d)", i);
>>            scm_c_catch(scm_eval_string,  str);
>> }
>>
>> main () {
>>       for (int i=1; i<15; i++)   // start 15 threads
>>             std::thread(&thing_doer, i);
>> }
>>
>> I'm guessing the above code spends maybe 90% of its time bouncing between
>> guile and C. The string "(do-things foo 42)" changes each time in the loop,
>> so, not sure how the compile vs. interpret tradeoff is done.  Either way,
>> its relatively trivial. Likewise, the do_stuff() C routine is fairly thin;
>> after decoding it's args, it doesn't do all that much (sub-microsecond of
>> computing).  Based on old, old measurements, scm_eval_string really is the
>> primary CPU consumer, in the 20-microseconds range. Launching 15 threads
>> means that this thing is racing as fast as it can.
>>
>> Anyway, with guile-2.9.2, the above crashes after about 10-15 minutes,
>> either with memory corruption, or with segfault.  I worried, so I retested
>> with guile-2.2.4 ... which also crashes, but much much less frequently:
>> seven times in 44 hours wall-clock time (so once ever 6 hours).  Which is
>> still more than desired, but...OK.
>>
>> So where's the crash? No clue. Could be my code, could be guile. Since
>> there's a big difference between guile-2.2 and guile-2.9, I'm ready to
>> blame guile. I did try to run it with `valgrind --tool helgrind` and got an
>> ocean of complaints about guile GC, which are probably harmless. I haven't
>> tried to dig deeper yet.
>>
>> -- Linas
>>
>>
>> On Thu, May 23, 2019 at 2:28 PM Andy Wingo <wingo@pobox.com> wrote:
>>
>>> Hi!
>>>
>>> On Thu 06 Dec 2018 06:21, Linas Vepstas <linasvepstas@gmail.com> writes:
>>>
>>> > After sending the email below, I scanned the guile-devel archives,
>>> > and I see Thomas Morley talking about Lilypond performance.
>>> > The example program he offers up caught my eye: nested deep
>>> > in a loop is this:
>>> >
>>> > (eval-string "'(a b c)")
>>>
>>> In this case I believe Guile 2.9 / 3 should be significantly faster than
>>> 2.2, because `eval' is compiled to native code rather than bytecode.  My
>>> measurements showed it to be on par with the hand-optimized C
>>> implementation from 1.8 and before.  Depends of course on how much the
>>> expander is part of your workload, there are differences relative to
>>> Guile 1.8.  Anyway, thanks for the note and I just wanted to mention
>>> this point.
>>>
>>> Regarding Scheme -> C++ transitions, there is the possibility that this
>>> too could be much faster with Guile 2.9.x given that these calls are now
>>> JIT-compiled instead of interpreted.  We'll have to see.
>>>
>>> Cheers,
>>>
>>> Andy
>>>
>>
>>
>> --
>> cassette tapes - analog TV - film cameras - you
>>
>
>
> --
> cassette tapes - analog TV - film cameras - you
>


-- 
cassette tapes - analog TV - film cameras - you

[-- Attachment #2: Type: text/html, Size: 6275 bytes --]