How accurate is Scalene memory tagging?

[mischif]

I want to use Scalene to find memory leaks and reduce my library's memory usage, but most of the lines that Scalene points out as having significant memory usage (especially the one identified as a potential leak) are just adding two numbers together or looping over a small list. Is this an issue others have experienced or am I doing something wrong?

I've seen this issue over multiple versions of Scalene/Python, but the profile I've attached is for Python 3.10.6/Scalene 1.5.25.
Sample profile

[Bootstrap360]

Hello @mischif,

I also have had my confidence in scalene quickly plummet after trying a simple program that should create both high CPU usage and high memory usage. But as you can see by the profile attached. The scalene profile is very confusing.

it was run with the following arguments

    target_program=/home/glen/example_threading.py
    scalene_log_filename="scalene_log.json"
    python -m scalene \
        --outfile $scalene_log_filename \
        --json \
        --cpu \
        --gpu \
        --memory \
        --reduced-profile \
        --profile-interval 120 \
        --stacks \
        --memory-leak-detector \
        --allocation-sampling-window 1048576 \
        --- \
        ${target_program}

@emeryberger it would be great if you could explain the following

1. Understanding the memory timeline. Why is the scalene profiler saying that line 20 (data = data * data) and 35: (sleep(1)) is consuming a significant amount memory? I can more understand that the numpy is allocating a new array with every multiplication, however, I really do not understand why time.sleep would be using GB of memory.
2. CPU consumption. Why is time.sleep using so much CPU usage?

See attached image

scalene_log.json.txt

[emeryberger]

The memory timeline indicates the amount of memory globally consumed at the time the line is executing. That is, it checks memory while it's running, and reports that, even if it wasn't the source of the memory consumption. The code above running a thread and sleeping while other threads are busily allocating memory, so the other threads are witnesses to this activity (since memory consumption is a global property) even if it not the cause.

This is a case we hadn't considered because we would not anticipate the use of multiple threads for compute-intensive code in Python because of the GIL, which serializes execution. It should be possible to modify Scalene to report thread-specific allocation (rather than global allocation), which would solve this problem, though I don't know how common a problem it is for the aforementioned reason.

On a minor note: I'd be interested to learn why the collecting stacks flag is set (they aren't used by the UI).

[Bootstrap360]

@emeryberger Thank you for your quick response.

Re: Memory Consumption thread tracking:

Thank you for the suggestion. I would be happy to make a PR for this improvement. If you pointed me in the right direction I could make this change.

Re: "--stacks" flag.

This is from my novel use. I was hoping to use this flag to get better transparency for a much more complex data pipeline I was profiling.

[Bootstrap360]

As a side comment @emeryberger,

Since numpy releases the GIL [https://superfastpython.com/numpy-vs-gil/], you can paralyse your computation code using threading.

from threading import Thread
from queue import Queue
import numpy as np
from time import perf_counter


class Consumer(Thread):
    def __init__(self, queue: Queue, func):
        Thread.__init__(self)
        self.queue = queue
        self.func = func

    def run(self):
        while True:
            # Get the work from the queue and expand the tuple
            args = self.queue.get()
            # check if finish
            if args is None:
                break
            try:
                self.func(args)
                self.queue.task_done()  # have to call task done for every data that is processed
            except Exception as e:
                # An exception happened in this thread
                print(e)
        self.queue.task_done()  # call task done one last time for the None


class Producer(Thread):
    def __init__(self, queue, func, count=100, num_consumers=4):
        Thread.__init__(self)
        self.queue = queue
        self.func = func
        self.count = count
        self.time = 0
        self.num_consumers = num_consumers

    def run(self):
        t0 = perf_counter()
        # create the data
        for idx in range(self.count):
            data = self.func()
            self.queue.put((idx, data))

        for i in range(self.num_consumers):
            # add None to the queue to indicate the end
            self.queue.put(None)

        # Causes the main thread to wait for the queue to finish processing all the tasks
        self.queue.join()
        t_end = perf_counter()
        self.time = t_end - t0


def produce_image():
    return np.random.randint(0, 255, (2038, 1536, 3), dtype=np.uint8)


def consume_image(data):
    idx, image = data
    # some heavy computation
    image = np.sqrt(image)


def single_producer_multi_consumer(num_consumers=4, num_images=100):
    queue = Queue()

    times = []
    num_images = 100
    num_attempts = 10
    for i in range(num_attempts):
        producer = Producer(
            queue, produce_image, num_images, num_consumers=num_consumers
        )
        consumers = [Consumer(queue, consume_image) for i in range(num_consumers)]

        producer.start()
        for consumer in consumers:
            consumer.start()

        producer.join()
        for consumer in consumers:
            consumer.join()
        times.append(producer.time)

    time_mean = np.mean(times)
    print(
        f"Mean time: {time_mean:0.2f} +/- {np.std(times):0.3f} seconds over {num_attempts} attempts using {num_consumers} consumers, for {num_images} images."
    )


def main():
    single_producer_multi_consumer(1)
    single_producer_multi_consumer(3)
    single_producer_multi_consumer(5)
    single_producer_multi_consumer(10)


if __name__ == "__main__":
    main()

python benchmarks/computation_graph.py
Mean time: 8.66 +/- 0.134 seconds over 10 attempts using 1 consumers, for 100 images.
Mean time: 3.04 +/- 0.022 seconds over 10 attempts using 3 consumers, for 100 images.
Mean time: 1.95 +/- 0.031 seconds over 10 attempts using 5 consumers, for 100 images.
Mean time: 1.87 +/- 0.125 seconds over 10 attempts using 10 consumers, for 100 images.

[Bootstrap360]

@mischif Have you tried setting the --allocation-sampling-window to a smaller value like ~ 1KB?