Embedded Scryer memory leak mitigations, experiments, and results

[jjtolton]

Using the following Python script, I wanted to see what the consequences of Scryer memory growth were before, during, and after cleanup of the WAM. I was really happy with the results.

Script

import threading
import json
def memgrowth(stop_event: threading.Event):
    source = """
:- use_module(library(lists)).
:- use_module(library(dcgs)).
:- use_module(library(iso_ext)).

string --> [].
string --> [S], string, { member(S, "abcdefghijklmnopqrstuvwxyz01234567890") }.
            """
    print("############## START ##############")
    print()
    print("Initial Stats")
    t0 = time.time()
    stats_initial=measure_memory_stats()
    print("#################")
    with ScryerMachine(source) as wam:
        print("WAM started")
        stats_wam=measure_memory_stats()
        print("#################")
        with wam.lazy_eval_context("phrase(string, Ls), partial_string(Ls, _, _).") as query:
            while not stop_event.is_set():
                next(query)
            print("Final memory stats")
            stats_middle=measure_memory_stats()
            print("####################")
    print("GC memory stats")
    stats_end=measure_memory_stats()
    print("########### END ##########")

    
    return json.dumps(
    {
         'stats_initial': stats_initial,
         'stats_wam': stats_wam,
         'stats_middle': stats_middle,
         'stats_end': stats_end,
         'timems': time.time() - t0
        },
        indent=2
    )

import os
import psutil

def measure_memory_stats():
    pid = os.getpid()
    process = psutil.Process(pid)
    memory_info = process.memory_info()
    print(f"Memory usage of PID {pid}:")
    rss_mb = memory_info.rss / (1024 * 1024)
    print(f"  RSS: {rss_mb :.2f} MB")  # Resident Set Size
    vms_mb = memory_info.vms / (1024 * 1024)
    print(f"  VSS: {vms_mb :.2f} MB")  # Virtual Memory Size
    return {'rss_mb': rss_mb, 'vms_mb': vms_mb}

def memory_test():
    stop_event = threading.Event()
    t = threading.Thread(target=memgrowth, args=(stop_event,))
    input("Record starting memory and press 'any' key to continue.")
    t.start()
    input("Press press 'any' key to terminate thread.")
    stop_event.set()
    input("Record stopping memory and press 'any' key to quit.")


if __name__ == '__main__':
    print(memory_test())
    memory_test()
    memory_test()

Results from testing embedded Scryer instantiating multiple WAMs and then allowing them to be GC'd, I am very happy with the results:

Console Output:

Record starting memory and press 'any' key to continue.
############## START ##############Press press 'any' key to terminate thread.

Initial Stats
Memory usage of PID 1379281:
  RSS: 19.87 MB
  VSS: 125.49 MB
#################
WAM started
Memory usage of PID 1379281:
  RSS: 36.04 MB
  VSS: 137.55 MB
#################

Record stopping memory and press 'any' key to quit.Final memory stats
Memory usage of PID 1379281:
  RSS: 61.30 MB
  VSS: 137.55 MB
####################
GC memory stats
Memory usage of PID 1379281:
  RSS: 38.95 MB
  VSS: 125.49 MB
########### END ##########

None
Record starting memory and press 'any' key to continue.
############## START ##############Press press 'any' key to terminate thread.

Initial Stats
Memory usage of PID 1379281:
  RSS: 38.70 MB
  VSS: 125.49 MB
#################
WAM started
Memory usage of PID 1379281:
  RSS: 42.03 MB
  VSS: 125.49 MB
#################


Record stopping memory and press 'any' key to quit.Record starting memory and press 'any' key to continue.Final memory stats
Memory usage of PID 1379281:
  RSS: 86.08 MB
  VSS: 125.49 MB
####################
GC memory stats
Memory usage of PID 1379281:
  RSS: 42.36 MB
  VSS: 125.49 MB
########### END ##########

############## START ##############Press press 'any' key to terminate thread.

Initial Stats
Memory usage of PID 1379281:
  RSS: 41.92 MB
  VSS: 125.49 MB
#################

Record stopping memory and press 'any' key to quit.WAM started
Memory usage of PID 1379281:
  RSS: 42.43 MB
  VSS: 125.49 MB
#################
Final memory stats
Memory usage of PID 1379281:
  RSS: 42.43 MB
  VSS: 125.49 MB
####################
GC memory stats
Memory usage of PID 1379281:
  RSS: 42.43 MB
  VSS: 125.49 MB
########### END ##########

Results

Metric	Explanation	Run 1	Run 2	Run 3
Initial RSS (MB)	Before instantiating WAM	19.87	38.70	41.92
WAM RSS (MB)	After instantiating WAM and loading source, before running query	36.04	42.03	42.43
Final RSS (MB)	After running query, before GC WAM	61.30	86.08	42.43
GC RSS (MB)	After GC'ing WAM	38.95	42.36	42.43
Time	Duration of experiment	~30m	~4h	~5s

Final memory scores mean, "memory usage just before GC'ing the WAM", and GC means memory AFTER GC'ing the WAM. (please refer to the source code if this explanation is confusing)

The great news from my perspective is that even within the same parent process, spawning and GC'ing WAMs is a very effective technique at managing memory. I will continue you to do more tests, I am curious how much that final GC number would continue to rise, but there are many many reasons that could account for the small different in memory size.

To me this indicates any insinuation that Scryer should not be used because of "memory leaks" is an extremely silly argument -- the results are pretty conclusive that even in the worst case the memory growth is not extremely significant and cycling the WAM clears it out easily. The difficulty of implementing this pattern should be no harder for an average developer than making a REST API call.

Obviously GC will be wonderful when it happens, but it's already looking pretty wonderful, even in the worst case scenario!

[bakaq]

This is fine for the embedded use case (where the host language controls the world) if you can always just use a new machine for every query, but if it's Prolog controlling the world there is no easy way to clean the atom table (and therefore partial strings) yet apart from restarting the whole process. This also adds a bunch of latency of creating a whole machine for each query.

[jjtolton]

Yes indeed, that's exactly the scenario I was testing for, because I need to know what happens when I put it in a video game 😀

I'm not at all worried about the query latency, there are plenty of techniques to get around that, such as maintaining a pool of WAM workers that get regenerated and managed in a different thread and provided to the query thread by a thread-safe queue.

[triska]

Scryer should not be used because of "memory leaks" is an extremely silly argument

Scryer is indeed perfectly well suited for many different usage modes and applications. The issue is: Scryer cannot be exhaustively tested due its memory leaks! For example, the following leaks memory, but should not leak memory:

?- repeat, N #= 2^100, number_chars(N, Cs), false.

A key performance attraction of Prolog is that memory can be quickly reclaimed on backtracking, even without GC! The above case should reclaim the allocated memory, and no GC is needed for that.

Memory reclamation on backtracking is a necessary condition to run exhaustive tests.

EDIT: Please check out the newly available rebis-dev development branch which addresses these issues, see also the announcement: #2569!