Logtalk method calls performance optimization

While playing with Logtalk, is seems my program was longer to execute with Logtalk object versus plain Prolog. I did a benchmark comparing the execution of the simple predicate in plain Prolog with the logtalk object encapsulation equivalent below :

%%
% plain prolog predicate
plain_prolog_simple :-
  fail.

%%
% object encapsulation
:- object(logtalk_obj).

    :- public([simple/0]).
    simple :-
      fail.

:- end_object.

Here’s what I get :

?- benchmark(plain_prolog_simple).

Number of repetitions: 500000
Total time calls: 0.33799099922180176 seconds
Average time per call: 6.759819984436035e-7 seconds
Number of calls per second: 1479329.3346604244
true.

?- benchmark(logtalk_obj::simple).

Number of repetitions: 500000
Total time calls: 2.950408935546875 seconds
Average time per call: 5.90081787109375e-6 seconds
Number of calls per second: 169468.0333888435
true.

We can see logtalk_obj::simple call is slower than plain_prolog_simple call. I use SWI Prolog as backend, I tried to set some log talk flags, without success.

Edit : We can find benchmark code samples to https://github.com/koryonik/logtalk-experiments/tree/master/benchmarks

What's wrong ? Why this performance diff? How to optimize Logtalk method calls ?

Solution

In a nutshell, you're benchmarking the Logtalk compilation of the ::/2 goal at the top-level INTERPRETER. That's a classic benchmarking error. Goals at the top-level, being it plain Prolog goals, module explicitly-qualified predicate goals, or message sending goals are always going to be interpreted, i.e. compiled on the fly.

You get performance close to plain Prolog for message sending goals in compiled source files, which is the most common scenario. See the benchmarks example in the Logtalk distribution for a benchmarking solution that avoids the above trap.

The performance gap (between plain Prolog and Logtalk goals) depend on the chosen backend Prolog compiler. The gap is negligible with mature Prolog VMs (e.g. SICStus Prolog or ECLiPSe) when static binding is possible. Some Prolog VMs (e.g. SWI-Prolog) lack some optimizations that can make the gap bigger, specially in tight loops, however.

P.S. Logtalk comes out-of-box with a settings configuration for development, not for performance. See in particular the documentation on the optimize flag, which should be turned on for static binding optimizations.

UPDATE

Starting from the code in your repository, and assuming SWI-Prolog as backend compiler, try:

----- code.lgt -----
% plain prolog predicate
plain_prolog_simple :-
  fail.

% object encapsulation
:- object(logtalk_obj).

    :- public(simple/0).
    simple :-
      fail.

:- end_object.
--------------------

----- bench.lgt -----
% load the SWI-Prolog "statistics" library
:- use_module(library(statistics)).   

:- object(bench).

    :- public(bench/0).
    bench :-
        write('Plain Prolog goal:'), nl,
        prolog_statistics:time({plain_prolog_simple}).
    bench :-
        write('Logtalk goal:'), nl,
        prolog_statistics:time(logtalk_obj::simple).
    bench.

:- end_object.
---------------------

Save both files and then startup Logtalk:

$ swilgt
...
?- set_logtalk_flag(optimize, on).
true.

?- {code, bench}.
% [ /Users/pmoura/Desktop/bench/code.lgt loaded ]
% (0 warnings)
% [ /Users/pmoura/Desktop/bench/bench.lgt loaded ]
% (0 warnings)
true.

?- bench::bench.
Plain Prolog goal:
% 2 inferences, 0.000 CPU in 0.000 seconds (69% CPU, 125000 Lips)
Logtalk goal:
% 2 inferences, 0.000 CPU in 0.000 seconds (70% CPU, 285714 Lips)
true.

The time/1 predicate is a meta-predicate. The Logtalk compiler uses the meta-predicate property to compile the time/1 argument. The {}/1 control construct is a Logtalk compiler bypass. It ensures that its argument is called as-is in the plain Prolog database.