Set logging interval to decrease size of bin file

[wigging]

I'm using Memray to profile the memory usage of a long running Python program. The bin file is several gigabytes and I'm starting to run out of storage space. I think if I set the logging interval to a longer duration, it would decrease the size of the bin file. But the run command does not have any options for setting the logging interval. How can set the logging interval and/or decrease the size of the bin file?

[pablogsal]

We are working on reducing the file size by implementing compression and other optimizations, so in some time you can expect quite a substantial reduction of the file size.

Regarding the request, I think it makes sense. We can add a flag to the command line to control the logging interval 👍

[pablogsal]

Assuming that you are running some version of this:

https://github.com/pybamm-team/liionpack/blob/main/examples/basic_16p2s.py

I gave it a try and I am not seeing any problems:

Writing profile results into memray-basic_16p2s.py.441634.bin
Memray WARNING: Correcting symbol for aligned_alloc from 0x7ffae643cbe0 to 0x7ffae6ce1000
2022-05-18 18:45:14,625 - [NOTICE] netlist_utils.setup_circuit(333): Circuit created
2022-05-18 18:45:14 - [NOTICE] netlist_utils.setup_circuit(333): Circuit created
2022-05-18 18:45:14,643 - [NOTICE] solvers.check_current_function(285): Parameter: Current function [A] has been set to input
2022-05-18 18:45:14 - [NOTICE] solvers.check_current_function(285): Parameter: Current function [A] has been set to input
2022-05-18 18:45:15,691 - [NOTICE] solvers.solve(206): Starting step solve
2022-05-18 18:45:15 - [NOTICE] solvers.solve(206): Starting step solve
Stepping simulation: 100%|████████████████████████████████████████████████████████████████████| 631/631 [00:18<00:00, 33.78it/s]
2022-05-18 18:45:34,372 - [NOTICE] solvers.solve(258): Step solve finished
2022-05-18 18:45:34 - [NOTICE] solvers.solve(258): Step solve finished
2022-05-18 18:45:34,372 - [NOTICE] solvers.solve(273): Total stepping time 18.681s
2022-05-18 18:45:34 - [NOTICE] solvers.solve(273): Total stepping time 18.681s
2022-05-18 18:45:34,373 - [NOTICE] solvers.solve(276): Time per step 0.03s
2022-05-18 18:45:34 - [NOTICE] solvers.solve(276): Time per step 0.03s
[memray] Successfully generated profile results.

You can now generate reports from the stored allocation records.
Some example commands to generate reports:

/tmp/test/venv/bin/python3.9 -m memray flamegraph memray-basic_16p2s.py.441634.bin

memray stats memray-lel.py.441634.bin
📏 Total allocations:
        131127

📦 Total memory allocated:
        305.044MB

📊 Histogram of allocation size:
        min: 1.000B
        -------------------------------------------
        < 5.000B   :   49 ▇
        < 32.000B  : 1079 ▇▇▇▇
        < 181.000B : 2839 ▇▇▇▇▇▇▇▇▇
        < 1.000KB  : 8632 ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇
        < 5.656KB  : 6502 ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇
        < 31.999KB :  865 ▇▇▇
        < 181.019KB:  108 ▇
        < 1.000MB  :  401 ▇▇
        < 5.657MB  :   15 ▇
        <=32.000MB :    7 ▇
        -------------------------------------------
        max: 32.000MB

📂 Allocator type distribution:
         MALLOC: 19557
         REALLOC: 684
         MMAP: 191
         CALLOC: 65

🥇 Top 5 largest allocating locations (by size):
        - dot:<__array_function__ internals>:180 -> 32.000MB
        - spsolve:/tmp/test/venv/lib/python3.9/site-packages/scipy/sparse/linalg/_dsolve/linsolve.py:203 -> 32.000MB
        - __init__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/tkinter/__init__.py:2572 -> 17.942MB
        - get:/tmp/test/venv/lib/python3.9/site-packages/casadi/casadi.py:6354 -> 14.583MB
        - _horzcat:/tmp/test/venv/lib/python3.9/site-packages/casadi/casadi.py:20190 -> 14.583MB

🥇 Top 5 largest allocating locations (by number of allocations):
        - __init__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/tkinter/__init__.py:2572 -> 16311
        - load_default_certs:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/ssl.py:575 -> 10438
        - __init__:/tmp/test/venv/lib/python3.9/site-packages/pybamm/solvers/solution.py:93 -> 6044
        - __new__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/ssl.py:483 -> 3631
        - __init__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/ctypes/__init__.py:374 -> 3511

[pablogsal]

I also run a version with Np=32 and Ns=20 which I suppose is what you are running with pack_32p20s:

 memray run -fo /tmp/lel.bin lel.py
Writing profile results into /tmp/lel.bin
Memray WARNING: Correcting symbol for aligned_alloc from 0x7f844da3cbe0 to 0x7f844e3c4000
2022-05-18 18:49:12,197 - [NOTICE] netlist_utils.setup_circuit(333): Circuit created
2022-05-18 18:49:12 - [NOTICE] netlist_utils.setup_circuit(333): Circuit created
2022-05-18 18:49:12,214 - [NOTICE] solvers.check_current_function(285): Parameter: Current function [A] has been set to input
2022-05-18 18:49:12 - [NOTICE] solvers.check_current_function(285): Parameter: Current function [A] has been set to input
2022-05-18 18:49:13,373 - [NOTICE] solvers.solve(206): Starting step solve
2022-05-18 18:49:13 - [NOTICE] solvers.solve(206): Starting step solve
Stepping simulation: 100%|████████████████████████████████████████████████████████████████████| 631/631 [02:02<00:00,  5.14it/s]
2022-05-18 18:51:16,192 - [NOTICE] solvers.solve(258): Step solve finished
2022-05-18 18:51:16 - [NOTICE] solvers.solve(258): Step solve finished
2022-05-18 18:51:16,193 - [NOTICE] solvers.solve(273): Total stepping time 122.819s
2022-05-18 18:51:16 - [NOTICE] solvers.solve(273): Total stepping time 122.819s
2022-05-18 18:51:16,193 - [NOTICE] solvers.solve(276): Time per step 0.195s
2022-05-18 18:51:16 - [NOTICE] solvers.solve(276): Time per step 0.195s
[memray] Successfully generated profile results.

You can now generate reports from the stored allocation records.
Some example commands to generate reports:

/tmp/test/venv/bin/python3.9 -m memray flamegraph /tmp/lel.bin

memray stats /tmp/lel.bin
📏 Total allocations:
        175389

📦 Total memory allocated:
        384.577MB

📊 Histogram of allocation size:
        min: 1.000B
        -------------------------------------------
        < 5.000B   :   40 ▇
        < 32.000B  :  495 ▇▇
        < 181.000B :  803 ▇▇▇
        < 1.000KB  : 7626 ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇
        < 5.656KB  : 6315 ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇
        < 31.999KB :  825 ▇▇▇
        < 181.019KB:  112 ▇
        < 1.000MB  :  453 ▇▇
        < 5.657MB  :   13 ▇
        <=32.000MB :   11 ▇
        -------------------------------------------
        max: 32.000MB

📂 Allocator type distribution:
         MALLOC: 15663
         REALLOC: 720
         MMAP: 237
         CALLOC: 73

🥇 Top 5 largest allocating locations (by size):
        - dot:<__array_function__ internals>:180 -> 32.000MB
        - spsolve:/tmp/test/venv/lib/python3.9/site-packages/scipy/sparse/linalg/_dsolve/linsolve.py:203 -> 32.000MB
        - recache:/tmp/test/venv/lib/python3.9/site-packages/matplotlib/lines.py:686 -> 28.931MB
        - recache:/tmp/test/venv/lib/python3.9/site-packages/matplotlib/lines.py:661 -> 28.885MB
        - __init__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/tkinter/__init__.py:2572 -> 17.942MB

🥇 Top 5 largest allocating locations (by number of allocations):
        - __init__:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/tkinter/__init__.py:2572 -> 16311
        - load_default_certs:/home/pablogsal/.pyenv/versions/3.9.10/lib/python3.9/ssl.py:575 -> 10438
        - _wrapit:/tmp/test/venv/lib/python3.9/site-packages/numpy/core/fromnumeric.py:43 -> 8983
        - __init__:/tmp/test/venv/lib/python3.9/site-packages/matplotlib/transforms.py:1914 -> 6023
        - recache:/tmp/test/venv/lib/python3.9/site-packages/matplotlib/lines.py:685 -> 6001

[pablogsal]

Here is the file records btw:

memray parse /tmp/lel.bin | cut -d " " -f 1 | sort | uniq -c

147008401 ALLOCATION
10210193 CONTEXT_SWITCH
  24869 FRAME_ID
4313736 FRAME_POP
9039549 FRAME_PUSH
      1 HEADER
  13086 MEMORY_RECORD

[wigging]

I had some old bin files taking up disk space. This was causing me to run out of storage when using Memray. I deleted the old bin files and everything is working fine now.

The table below compares the storage size of the bin file generated from Memray v1.0.3 (Run 1) and v1.1.0 (Run 2). The bin size from v1.1.0 is much smaller at 1.7 GB compared to the previous version which generated a 24 GB bin file. Thank you for the update to reduce the file size.

Run	Cores	Solver	Total memory	Bin size
1	20	casadi	374 MB	24.0 GB
2	20	casadi	356 MB	1.7 GB

[godlygeek]

Aha! We were just wondering if it might be that. I've opened #116 about the bus error, we'll see if that can be fixed without murdering performance.