search

SWI-Prolog / issues

Dummy repository for issue tracking
7 stars 3 forks source link

V8.0.1 memory management - excessive gc #85

Closed ridgeworks closed 5 years ago

ridgeworks commented 5 years ago

SWI-Prolog 8.0.1 on MacOS 10.13.4

I have a benchmark that takes approximately 33 secs to run on v7.6.4 and 715 secs on v8.0.1. In the latter case 675 secs is garbage collection (vs. 8.6 secs on v7.6.4). v8.0.1 does ~340,000 collections and ~100,000 global stack shifts vs. 3400 and 0 on v7.6.4. I've attached before and after statistics for details.

I know memory configuration has changed in 8.0.1 (single stack limit) but the only thing I've configured is:

set_prolog_stack(global,min_free(8196)),

Can that explain what I'm observing?

% V8.0.1
%
% Started at Wed Jan 30 11:18:12 2019
% 734.730 seconds cpu time for 109,140,296 inferences
% 7,785 atoms, 4,307 functors, 3,193 predicates, 60 modules, 134,751 VM-codes
% 
%                     Limit   Allocated      In use
% Local  stack:           -       20 Kb    2,192  b
% Global stack:           -      508 Kb      292 Kb
% Trail  stack:           -       30 Kb   10,464  b
%        Total:    1,024 Mb      558 Kb      304 Kb
% 
% 344,146 garbage collections gained 2,378,106,080 bytes in 676.904 seconds.
% 2 clause garbage collections gained 83 clauses in 0.000 seconds.
% Stack shifts: 500 local, 95,594 global, 509,794 trail in 9.346 seconds
% 2 threads, 1 finished threads used 1.553 seconds

% Started at Wed Jan 30 11:18:12 2019
% 1452.930 seconds cpu time for 196,722,923 inferences
% 7,786 atoms, 4,307 functors, 3,186 predicates, 60 modules, 134,751 VM-codes
% 
%                     Limit   Allocated      In use
% Local  stack:           -       20 Kb    1,920  b
% Global stack:           -      508 Kb      276 Kb
% Trail  stack:           -      254 Kb       32 Kb
%        Total:    1,024 Mb      782 Kb      309 Kb
% 
% 682,931 garbage collections gained 4,303,078,392 bytes in 1355.175 seconds.
% 2 clause garbage collections gained 83 clauses in 0.000 seconds.
% Stack shifts: 920 local, 191,157 global, 1,016,808 trail in 18.751 seconds
% 2 threads, 1 finished threads used 1.553 seconds

% V7.6.4
%
% Started at Wed Jan 30 11:06:23 2019
% 84.130 seconds cpu time for 178,389,446 inferences
% 9,424 atoms, 4,136 functors, 2,971 predicates, 58 modules, 151,179 VM-codes
% 
%                        Limit    Allocated       In use
% Local  stack:    268,435,456       61,440        2,216 Bytes
% Global stack:    268,435,456    1,044,464       14,888 Bytes
% Trail  stack:    268,435,456       14,328        4,872 Bytes
% 
% 7,336 garbage collections gained 3,893,396,384 bytes in 16.944 seconds.
% 4 clause garbage collections gained 111 clauses in 0.000 seconds.
% Stack shifts: 8 local, 8 global, 21 trail in 0.001 seconds
% 2 threads, 1 finished threads used 1.162 seconds

% Started at Wed Jan 30 11:06:23 2019
% 118.020 seconds cpu time for 265,633,661 inferences
% 9,424 atoms, 4,136 functors, 2,971 predicates, 58 modules, 151,179 VM-codes
% 
%                        Limit    Allocated       In use
% Local  stack:    268,435,456       61,440        1,944 Bytes
% Global stack:    268,435,456    1,044,464      886,104 Bytes
% Trail  stack:    268,435,456      522,232      140,616 Bytes
% 
% 10,718 garbage collections gained 5,801,040,248 bytes in 25.371 seconds.
% 4 clause garbage collections gained 111 clauses in 0.000 seconds.
% Stack shifts: 8 local, 8 global, 26 trail in 0.001 seconds
% 2 threads, 1 finished threads used 1.162 seconds
JanWielemaker commented 5 years ago

Good to know, but it is hard to comment without the benchmark. There is no significant change to the shift/gc policies. Things may work out differently though as the exact sizes vary. It is still on my agenda to consider a more dynamic scheduling mechanism.

So, please share the benchmark. Can be private, but I prefer public if that is possible.

ridgeworks commented 5 years ago

I've extracted the relevant test and attached it to this comment. As with my previous issue it requires the clpBNR module at https://github.com/ridgeworks/clpBNR_pl . Steps:

  1. Consult clpBNR.pl
  2. Consult HeatX_BM.txt (attached)
  3. Execute the query in comments at the head of this file.

HeatX_BM.txt

JanWielemaker commented 5 years ago

Thanks. The issue seems mostly related to being a too aggressive on GC after an exception. After some changes I now get 14.1 sec without and 12.2 sec with optimization (-O). (Intel NUC with i7-5557U running Ubuntu 18.04)

Need to investigate a little more before I trust this enough to publish.

ridgeworks commented 5 years ago

Very good. Yes I am generating a fair number of exceptions.

You probably already know this but it first occurred in v7.7.14. Also when the stack limits in statistics/1 started being output output as '-'.

I'm trundling along on a 10 year old Mac Pro (2.26 Ghz. Xeon), so execution times won't be quite as impressive as yours.

On Jan 31, 2019, at 4:19 PM, Jan Wielemaker notifications@github.com wrote:

Thanks. The issue seems mostly related to being a too aggressive on GC after an exception. After some changes I now get 14.1 sec without and 12.2 sec with optimization (-O). (Intel NUC with i7-5557U running Ubuntu 18.04)

Need to investigate a little more before I trust this enough to publish.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/SWI-Prolog/issues/issues/85#issuecomment-459510445, or mute the thread https://github.com/notifications/unsubscribe-auth/AG5UwUSTiYqRfDyMRCnWR3Qy08ECP3XBks5vI138gaJpZM4aa0ir.

JanWielemaker commented 5 years ago

For the record, the vital commit is SWI-Prolog/swipl-devel@d6a646a6cdc48667a137e43fecbb975f89973716

JanWielemaker commented 5 years ago

Pushed the fixes to swipl-devel.git. Bit too early for the stable branch, but I'm fairly confident this improves things a lot for programs handling many exceptions as part of their normal processing.

ridgeworks commented 5 years ago

Thanks for resolving this so quickly. No rush, but any idea when this might make it into a development release? (I don't normally track those but I will in this case.)

On Feb 1, 2019, at 12:17 PM, Jan Wielemaker notifications@github.com wrote:

Pushed the fixes to swipl-devel.git. Bit too early for the stable branch, but I'm fairly confident this improves things a lot for programs handling many exceptions as part of their normal processing.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/SWI-Prolog/issues/issues/85#issuecomment-459797370, or mute the thread https://github.com/notifications/unsubscribe-auth/AG5Uwd4DDCG431310z_oq5QTAWA8vtmEks5vJHaegaJpZM4aa0ir.

JanWielemaker commented 5 years ago

Quite likely the coming week.