Understanding profiler

General
1

I’m making a (toy for now) programming language with DCG based parser and evaluator.
(code is at GitHub - tatut/elf-lang: Elf Helper programming language)

I’m trying to keep the evaluation as free of backtracking as possible. So everything is evaluated once and has 1 possible answer.

I was profiling one program in this language and saw that there were huge amounts of “Redos”.

image
image965×210 37.2 KB

I then added fail trace to eval_methods/5 and saw lots of failures:

 T [130 +0.0ms] Fail: elf:eval_methods(9, [], _141646, [...ctx...], _141648)

In a part that should always match the first clause:

eval_methods(In, [], In) --> [].
eval_methods(In, [M|Methods], Out) -->
    eval_method(In, M, Intermediate),
    { ! }, % commit to this method call result (don't leave choicepoints around)
    eval_methods(Intermediate, Methods, Out).

Is there a way to add breakpoint for a clause in the gtrace tool only when the clause fails?
Or what would be the best way to find out the root cause of a particular failure.

2

In SWI-Prolog for lists it its better to rely on first argument
indexing than on multi-argument index. Jan W. always
reorders, like in the maplist implementation:

maplist(Goal, List) :-
  maplist_(List, Goal).

maplist_([], _).
maplist_([Elem|Tail], Goal) :-
      call(Goal, Elem),
      maplist_(Tail, Goal).

The reason is multiargument indexes are created lazily
and before the system decides to have a multi-argument index,
there will be choice points.

2 Likes
3

Thanks, that simple reordering actually sped up little bit.

4

The default (“classic”) settings of the profiler has some incorrect port counts. Some work was done a while ago to fix this but some of the documentation is still sitting in a PR (Draft updated doc for profiler by ridgeworks · Pull Request #1144 · SWI-Prolog/swipl-devel · GitHub).

In any case, if you want accurate port counts include ports(true) in the option list of profile/2 .

1 Like
5

Adding ports(true) makes the redos almost completely disappear. I guess it makes sense, looking at that discussion, since the evaluator is very very highly recursive code.

6

Although the profiler gives some insight in non-determinism, the primary tool for inspecting (un)wanted non-determinism is the graphical debugger. Put a spy point on the predicate you want to investigate and ‘s’(kip) over it. Now the top-right window shows both the call stack and open choice points. You can click on any of the choice frames to see which clause succeeded and left a choice point.

You can also step through some code and see the choice points come and go. It is typically a good idea to avoid the creation of a choice point (for example by ensuring clause indexing does its job) or get rid of them using -> or ! as soon as possible.

SWI-Prolog specific tools for creating deterministic and safe code are the single sided unification (SSU, using Head => Body) and the :- det(name/arity) declaration. Finally, there is $/0, which acts as !/0, but also declares that the remainder of the clause must succeed deterministically. These tools raise exceptions if anything does not behave as you had it in mind, making debugging a lot easier.

The profiler notably hints at poor clause indexing. Such predicates will show up with a relatively high percentage of the CPU time for the number of calls. And, of course, it points at expensive built-in predicates. It can also give some hint about garbage costs by (1) showing the percentage of the time in GC while (2), the predicates that invoke GC the most often are the predicates that create most (global stack) data (not necessarily garbage).

3 Likes