This is the classical Prolog stack garbage collector. That is not related.
I’ve tried garbage_collect_clauses
and garbage_collect_atoms
as well. Neither one improves the timing of the query (or takes any noticeable time by itself).
Could you get the output of calling statistics/0 after the inferencing, so we can check the number of clause garbage collections.
I should mention that the dynamic facts are not asserted in the match_toplevel
query we are running here but rather in a preparatory step (executing a bunch of assertz
queries) that we trigger from our application. That preparatory step does not seem to be any slower with --signals=false
.
Still, in case it could be useful, here’s the output before and after the query and then after running garbage_collect_clauses
. This is from the middle of my current debugging session and the particular point in the application has already run thousands of queries before, which is why there have been so many collections already.
statistics.
% Started at Fri Oct 13 15:04:20 2023
% 300.494 seconds cpu time for 9,242,462 inferences
% 7,291 atoms, 5,463 functors, 3,465 predicates, 47 modules, 11,818,360 VM-codes
%
% Limit Allocated In use
% Local stack: - 500 Kb 307 Kb
% Global stack: - 256 Kb 237 Kb
% Trail stack: - 34 Kb 360 b
% Total: 1,024 Mb 790 Kb 545 Kb
%
% 72 garbage collections gained 104,678,712 bytes in 0.038 seconds.
% 2 atom garbage collections gained 33,574 atoms in 0.010 seconds.
% 1,556 clause garbage collections gained 165,548 clauses in 0.091 seconds.
% Stack shifts: 6 local, 10 global, 33 trail in 0.008 seconds
true.
profile(findall([A,B,C,K,I],match_toplevel(fwd,A,B,C,K,I),B)).
[..] % output omitted
statistics.
% Started at Fri Oct 13 15:04:20 2023
% 300.783 seconds cpu time for 9,249,342 inferences
% 7,291 atoms, 5,463 functors, 3,465 predicates, 47 modules, 11,818,383 VM-codes
%
% Limit Allocated In use
% Local stack: - 500 Kb 307 Kb
% Global stack: - 512 Kb 300 Kb
% Trail stack: - 34 Kb 360 b
% Total: 1,024 Mb 1,046 Kb 607 Kb
%
% 72 garbage collections gained 104,678,712 bytes in 0.038 seconds.
% 2 atom garbage collections gained 33,574 atoms in 0.010 seconds.
% 1,556 clause garbage collections gained 165,548 clauses in 0.091 seconds.
% Stack shifts: 6 local, 11 global, 36 trail in 0.009 seconds
true.
garbage_collect_clauses.
true.
statistics.
% Started at Fri Oct 13 15:04:20 2023
% 300.787 seconds cpu time for 9,251,247 inferences
% 7,291 atoms, 5,463 functors, 3,465 predicates, 47 modules, 11,818,396 VM-codes
%
% Limit Allocated In use
% Local stack: - 500 Kb 307 Kb
% Global stack: - 512 Kb 320 Kb
% Trail stack: - 34 Kb 360 b
% Total: 1,024 Mb 1,046 Kb 627 Kb
%
% 72 garbage collections gained 104,678,712 bytes in 0.038 seconds.
% 2 atom garbage collections gained 33,574 atoms in 0.010 seconds.
% 1,558 clause garbage collections gained 165,550 clauses in 0.092 seconds.
% Stack shifts: 6 local, 11 global, 38 trail in 0.009 seconds
true.
Might get hard to debug if I can’t reproduce this.
I understand. I will try to come up with a bit of C code that initialises the interpreter and loads our definitions and puts the system in the same state that I am observing with --signals=false
.
I am also setting things up so that I can compare the embedded interpreter with and without --signals=no
(instead of comparing embedded versus the swipl
binary) to get a better, more direct comparison. This could help with interpreting the output of statistics
which probably won’t mean anything without a direct comparison, I think. Although I am not sure statistics
is going to help us much more.