diff --git a/.github/workflows/run_tests.yml b/.github/workflows/run_tests.yml new file mode 100644 index 0000000..0f91c18 --- /dev/null +++ b/.github/workflows/run_tests.yml @@ -0,0 +1,32 @@ +name: Example + +on: [push] + +jobs: + build: + name: memory-profiler + runs-on: ubuntu-latest + strategy: + matrix: + python-version: + - "3.11" + - "3.12" + + steps: + - uses: actions/checkout@v4 + + - name: Install uv + uses: astral-sh/setup-uv@v2 + with: + # Install a specific version of uv. + version: "0.4.2" + + - name: Set up Python ${{ matrix.python-version }} + run: uv python install ${{ matrix.python-version }} + + - name: Install the project + run: uv sync --all-extras --dev + + - name: Run tests + # For example, using `pytest` + run: uv run pytest rendering_tools/tests diff --git a/.gitignore b/.gitignore index 82f9275..3bb231a 100644 --- a/.gitignore +++ b/.gitignore @@ -1,3 +1,7 @@ +# Image and video files in the rendering_tools folder +rendering_tools/*.png +rendering_tools/*.mp4 + # Byte-compiled / optimized / DLL files __pycache__/ *.py[cod] diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml new file mode 100644 index 0000000..83fb859 --- /dev/null +++ b/.pre-commit-config.yaml @@ -0,0 +1,13 @@ +repos: + - repo: https://github.com/charliermarsh/ruff-pre-commit + rev: v0.1.3 + hooks: + - id: ruff + - id: ruff-format + - repo: https://github.com/codespell-project/codespell + rev: v2.2.6 + hooks: + - id: codespell + name: Spellcheck for changed files (codespell) + additional_dependencies: + - tomli diff --git a/examples/README.md b/examples/README.md index 31cd295..a6e54e9 100644 --- a/examples/README.md +++ b/examples/README.md @@ -1,16 +1,26 @@ # Examples -## Generate a dump log +## Generate a memory dump -In `examples`: +In the `examples` folder: + +For MicroPython on the unix port (run in a container): ```bash -docker run -ti --rm -v $(pwd):/code -w /code micropython/unix micropython -X heapsize=500000 -c "import mip; mip.install('logging'); import example1" | tee dump.log +docker run -ti --rm -v $(pwd):/code -w /code micropython/unix micropython -X heapsize=500000 -c "import mip; mip.install('logging'); mip.install('mem_dump'); import example1" | tee dump_unix.log ``` -**TODO** Remember to also install `mem_dump.py` when it's available on github. +On a device: -- Currently, all lines preceeding the first '@@@' need to be deleted. +```bash +mpremote mip install logging # Only needed once +mpremote mip install mem_dump +mpremote mount . exec "import example1" | tee dump_device.log +``` + +**TODO:** The *install mem_dump* lines above will need to be updated when this +library is published. In the meantime, `mem_dump.py` should be copied to the +filesystem. ## Generate images @@ -19,4 +29,4 @@ In `rendering_tools`: ```bash uv run mem_usage_render.py ../examples/dump.log ffmpeg -r 10 -f image2 -s 2100x1252 -i image_%04d.png -vcodec libx264 -crf 25 -pix_fmt yuv420p mem_usage.mp4 -``` \ No newline at end of file +``` diff --git a/examples/example1.py b/examples/example1.py new file mode 100644 index 0000000..5109b5a --- /dev/null +++ b/examples/example1.py @@ -0,0 +1,73 @@ +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 + +# Create an async program with a number of tasks: +# +# 1) allocate large blocks +# 2) de-allocate blocks, call gc.collect +# 3) profile + +import asyncio +import time +import logging +import gc + +import mem_dump + +logging.basicConfig(level=logging.INFO) +log = logging.getLogger("MemTest") + +_MEMORY = [] + + +class SimpleTimer: + """A simple class that, when called, will return True if the time since + it's creation has expired.""" + + def __init__(self, seconds): + self.start = int(time.time()) + self.seconds = seconds + + def __call__(self) -> bool: + return (int(time.time()) - self.start) > self.seconds + + +async def allocate_task(finished, size_alloc=5_000, interval_ms=100): + while not finished(): + log.info(f"Allocating {size_alloc} bytes") + _MEMORY.append(bytearray(size_alloc)) + await asyncio.sleep_ms(interval_ms) + + +async def release_task(finished, interval_ms=2_000): + while not finished(): + log.info("Freeing half of the allocated bytearrays") + + del _MEMORY[: len(_MEMORY) // 2] + gc.collect() + + await asyncio.sleep_ms(interval_ms) + + +async def main(): + # Start the mem_dump async task + await mem_dump.start_async() + + log.info("Begin Example 1") + log.info( + "Periodically, allocate bytearray blocks and store them in a list. " + "At a slower interval, delete half of the list recover the memory." + ) + + # Run the example for ten seconds + timer = SimpleTimer(10) + + # Start allocating and deleting memory + await asyncio.gather(allocate_task(timer), release_task(timer)) + + log.info("End Example 1") + + +asyncio.run(main()) diff --git a/mem_dump.py b/mem_dump.py index 8a939cf..861b0f7 100644 --- a/mem_dump.py +++ b/mem_dump.py @@ -1,9 +1,15 @@ +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 + import time import micropython _MEM_DUMP_PERIOD_MS = 350 _FIRST = True + def mem_dump(_): global _FIRST if _FIRST: @@ -19,6 +25,7 @@ def mem_dump(_): def start_timer(period_ms=_MEM_DUMP_PERIOD_MS): from machine import Timer + # Start a timer to periodically dump the heap. Timer(period=period_ms, callback=mem_dump) diff --git a/pyproject.toml b/pyproject.toml new file mode 100644 index 0000000..91a2694 --- /dev/null +++ b/pyproject.toml @@ -0,0 +1,15 @@ +[project] +name = "micropython-memory-profiler" +version = "0.1.0" +description = "A memory profiler for use with MicroPython" +readme = "rendering_tools/README.md" +requires-python = ">=3.11" +dependencies = [ + "pycairo>=1.26.1", + "pytest>=8.3.2", +] + +[tool.pytest.ini_options] +pythonpath = [ + "rendering_tools" +] \ No newline at end of file diff --git a/rendering_tools/README.md b/rendering_tools/README.md index e69de29..7099734 100644 --- a/rendering_tools/README.md +++ b/rendering_tools/README.md @@ -0,0 +1 @@ +# rendering_tools \ No newline at end of file diff --git a/rendering_tools/__init__.py b/rendering_tools/__init__.py index e69de29..25d016d 100644 --- a/rendering_tools/__init__.py +++ b/rendering_tools/__init__.py @@ -0,0 +1,5 @@ +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 +# diff --git a/rendering_tools/mem_usage_parser/__init__.py b/rendering_tools/mem_usage_parser/__init__.py index fc32b13..25d016d 100644 --- a/rendering_tools/mem_usage_parser/__init__.py +++ b/rendering_tools/mem_usage_parser/__init__.py @@ -1 +1,5 @@ -from .frame_parser import Capture, LogFrame, DummyFrame, HeapFrame \ No newline at end of file +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 +# diff --git a/rendering_tools/mem_usage_parser/frame_parser.py b/rendering_tools/mem_usage_parser/frame_parser.py index 7359375..704c455 100644 --- a/rendering_tools/mem_usage_parser/frame_parser.py +++ b/rendering_tools/mem_usage_parser/frame_parser.py @@ -1,7 +1,12 @@ - +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 +# import re + class Capture: def __init__(self): self.title = "" @@ -43,30 +48,20 @@ def __init__(self, timestamp_ms, heap): # convert body to something prettier def gen(heap: list[str]): - addr = 0 - for entry in heap: if entry.find("lines all free") != -1: m = re.search(r"\((\d+) lines all free", entry) for _ in range(int(m.group(1))): yield "." * 64 - #addr += 1024 - addr += 0x800 else: - #print(f"entry {entry[:5]}, {addr=}") - #assert int(entry[:5], 16) == addr - assert int(entry[:8], 16) == addr - #print(f"entry2: {entry[10:]}") - #yield entry[7:] - yield entry[10:] # The contents of the memory representation - - #addr += 1024 - addr += 0x800 + yield entry[10:] # The contents of the memory representation + while True: yield "" # There is an optional 'mem' line # eg "mem: total=74627, current=42583, peak=42639" + # If present, ensure it's included to find the top of the heap output. start_of_mem = 4 # The start of the memory dump starts on this line if heap[0].startswith("mem:"): start_of_mem += 1 @@ -81,7 +76,6 @@ def gen(heap: list[str]): entry += next(g) if not entry: break - addr = len(body) * 1024 * MULT - #body.append("{:05x}: ".format(addr) + entry) + addr = len(body) * 0x400 * MULT body.append("{:08x}: ".format(addr) + entry) self.heap = header + body diff --git a/rendering_tools/mem_usage_render.py b/rendering_tools/mem_usage_render.py index cd519b4..9ececf4 100644 --- a/rendering_tools/mem_usage_render.py +++ b/rendering_tools/mem_usage_render.py @@ -1,19 +1,12 @@ +# MIT license; Copyright (c) 2024, Planet Innovation +# SPDX-License-Identifier: MIT +# 436 Elgar Road, Box Hill, 3128, VIC, Australia +# Phone: +61 3 9945 7510 +# + """ Convert a device log containing periodic micropython.mem_info(1) into a set of images suitable to make a video. - -A capture should be made first by running mem_usage_main.py on the device. For -example: - - $ pyboard.py mem_usage_main.py | tee > mem_usage.log - -Then run this script to convert the log to a sequence of PNG images: - - $ python mem_usage_render.py mem_usage.log - -Video can then be made with (replace -s size with actual size of images): - - ffmpeg -r 10 -f image2 -s 2100x1252 -i image_%04d.png -vcodec libx264 -crf 25 -pix_fmt yuv420p mem_usage.mp4 """ import re @@ -27,6 +20,7 @@ COLOUR_TEXT_PLAIN = (0, 0, 0) COLOUR_TEXT_CHANGED = (1, 0, 0) + def parse_capture(filename): capture = Capture() rtc_offset = None @@ -40,7 +34,7 @@ def parse_capture(filename): if line.startswith("@@@ v"): # Title line capture.title = line[4:] - #print("title:", capture.title) + # print("title:", capture.title) elif line.startswith("@@@ ") and line.find(" (") != -1: # Timestamp *and* datetime line _, timestamp_ms, datetime = line.split(None, 2) @@ -51,7 +45,6 @@ def parse_capture(filename): rtc_offset = ( ((hr * 60 + mn) * 60 + sc) * 1000 + us // 1000 - timestamp_ms ) - #print("timestamp_ms:", timestamp_ms, "rtc_offset:", rtc_offset) elif line.startswith("@@@ "): # Line with (only) a timestamp. The *frame*, which includes # the memory and heap information, follows this line and @@ -67,15 +60,10 @@ def parse_capture(filename): heap.append(line) if rtc_offset is None: rtc_offset = capture.frames[-1].timestamp_ms - timestamp_ms + 200 - #print(heap[:5]) - #print(heap[6:]) frame = HeapFrame(rtc_offset + timestamp_ms, heap) else: # LogFrame, use the timestamp if it's available - #print("match timestamp") - #print(line) m = re.match(r"20\d\d-\d\d-\d\d (\d\d):(\d\d):(\d\d),(\d\d\d) ", line) - print('log') timestamp_ms = None if m: hr = int(m.group(1)) @@ -84,7 +72,6 @@ def parse_capture(filename): ms = int(m.group(4)) timestamp_ms = ((hr * 60 + mn) * 60 + sc) * 1000 + ms elif len(capture.frames) > 0: - print(len(capture.frames)) timestamp_ms = capture.frames[-1].timestamp_ms + 10 if timestamp_ms: frame = LogFrame(timestamp_ms, line) @@ -92,10 +79,8 @@ def parse_capture(filename): # We can't create LogFrames before recording a # timestamp. So drop any log text until the first # HeapFrame is found. - print(f"drop: {line}") frame = None if frame: - print("add capture") capture.add_frame(frame, rtc_offset) return capture diff --git a/rendering_tools/pyproject.toml b/rendering_tools/pyproject.toml deleted file mode 100644 index bc2c467..0000000 --- a/rendering_tools/pyproject.toml +++ /dev/null @@ -1,15 +0,0 @@ -[project] -name = "rendering-tools" -version = "0.1.0" -description = "Add your description here" -readme = "README.md" -requires-python = ">=3.12" -dependencies = [ - "pycairo>=1.26.1", - "pytest>=8.3.2", -] - -[tool.pytest.ini_options] -pythonpath = [ - "." -] \ No newline at end of file diff --git a/rendering_tools/tests/frame_parser_test.py b/rendering_tools/tests/frame_parser_test.py index 3ae5837..2862622 100644 --- a/rendering_tools/tests/frame_parser_test.py +++ b/rendering_tools/tests/frame_parser_test.py @@ -1,14 +1,17 @@ - from mem_usage_parser.frame_parser import HeapFrame + class TestHeapFrame: def test_unix(self): heap = [ - "mem: total=74627, current=42583, peak=42639" - "stack: 7312 out of 80000" - "GC: total: 2072832, used: 48160, free: 2024672" - " No. of 1-blocks: 680, 2-blocks: 80, max blk sz: 91, max free sz: 63271" - "GC memory layout; from 7f3795121f00:" + "mem: total=74627, current=42583, peak=42639", + "stack: 7312 out of 80000", + "GC: total: 2072832, used: 48160, free: 2024672", + " No. of 1-blocks: 680, 2-blocks: 80, max blk sz: 91, max free sz: 63271", + "GC memory layout; from 7f3795121f00:", + "00000000: MDhh=hhLhhSh===h========hhhBMDhBShThSBBMDh==BShBDBDBBBhBhBBBBh==", + "00000800: =h===T==B==BBBTB=BBBT=B=h=h========MDShhSh========hhShMhShh==hhS", + "@@@", ] frame = HeapFrame(1234, heap) print("test unix") @@ -16,10 +19,9 @@ def test_unix(self): def test_device(self): heap = [ - "stack: 668 out of 15360" - "GC: total: 152512, used: 1264, free: 151248", + "stack: 668 out of 15360" "GC: total: 152512, used: 1264, free: 151248", " No. of 1-blocks: 24, 2-blocks: 3, max blk sz: 18, max free sz: 9440", - "GC memory layout; from 20006c30:" + "GC memory layout; from 20006c30:", ] frame = HeapFrame(4321, heap) print("test device") @@ -29,5 +31,96 @@ def test_device(self): # Other tests # - Ensure blank lines are stripped -# - Ensure LogFrames are generated for inital lines (preceeding @@@ lines) -# - Check each of the frame types \ No newline at end of file +# - Ensure LogFrames are generated for initial lines (preceding @@@ lines) +# - Check each of the frame types + + +two_frames = """ +Installing logging (latest) from https://micropython.org/pi/v2 to /root/.micropython/lib +Copying: /root/.micropython/lib/logging.mpy +Done +INFO:MemTest:Begin Example 1 +INFO:MemTest:Periodically, allocate bytearray blocks and store them in a list. At a slower interval, delete half of the list recover the memory. +@@@ 45828774 (2024, 9, 10, 12, 5, 42, 1, 254) +@@@ 45828774 +mem: total=77932, current=44073, peak=44073 +stack: 7328 out of 80000 +GC: total: 296448, used: 49920, free: 246528 + No. of 1-blocks: 695, 2-blocks: 83, max blk sz: 91, max free sz: 7704 +GC memory layout; from 7f2951dbdde0: +00000000: MDhh=hhLhhSh===h========hhhBMDhBShThSBBMDh==BShBDBDBBBhBhBBBBh== +00000800: =h===T==B==BBBTB=BBBT=B=h=h========MDShhSh========hhShMhShh==hhS +00001000: SDSh=BMDBShhhh==ShDhShLhh=LLhShSh=LhT=AhDhh===================== +00001800: ================================================================ +00002000: =====h=============TSSSh=hhLhShShShShhSSLhShShSh=SSLhShSh=Shh=SS +00002800: LhShShShhShSLhShShShh=SSLhShSh=ShhSSSLhShShhSSLhShShShhSSLLhShSh +00003000: Shh=SSLhShShh====hShShhShhShSh==hSh=ShShhhSSSh=hhThh=hSSTDBMDhDS +00003800: h=hhALhShShShLhShShLhT=AhDhh==================================== +00004000: ======================================================h========= +00004800: ====TSSSh=hhLhShShShShhSSLhShShSh=SSLhShSh=Shh=SSLhShShShhShSLhS +00005000: hShShh=SSLhShSh=Shh=SSLhShShhSSLhShShShhShSSLhShShhSSLhShShh==== +00005800: hh=h==SShT==hShSShhThShhShSShhThShhSh===hhhBTT=Dh=BDBDhTh===BDhT +00006000: h===hhhTB=BBBBBhh=hh==h===DSShhh===h===BBBBBBBBhhh===BTh=B=BhBDB +00006800: BBBBhhh=h====TB=BBhhh=hDDBBBBh===h====hhh===============Bh===Sh= +00007000: h=====h==============hSShDTh======hh====h===========h===h===h=== +00007800: ===h===h==hh===h============================h=Sh====hhh========= +00008000: ==============h=========h==hhh=h=hhhhhhhhhhhh=hh=hhhh=hhh=hh=hhh +00008800: hh=hh=hhhh=hh==hhh==h===h=hhhhhhhh===hhhhhhhhhhhh===hhhhhhh=hhhh +00009000: hhhhhhhhhhhh=hhhh====hhh==DBDBBh=DBTB=BBBBDh===BBBBBBBBBT==hBTh= +00009800: ==h===B=hTBBh==h===DhBTB=hh=hTh===BDBTB=BBBh==h===DBTB=BBBBBBBBD +0000a000: hB=BBh===TB=h========B==hhhh===hBBTTh==================hhhB=BDBB +0000a800: Lh=h====hLhLhhhh=LhhhTh=hh=Th=hTh=h=hhh===Th===h===h=h========h= +0000b000: ==hh=Thhh=h==h=hh=hh=h======h==h=hMFhDBFFFDShh===h==hSFFFDh===== +0000b800: =========h==Sh====h====ShTBBTh=DhTDhBhh=h===h===h=h============= +0000c000: =====hhBh=BLhh=h=T==hT==........................................ + (119 lines all free) +00048000: ................................................ +@@@ +INFO:MemTest:Allocating 5000 bytes +INFO:MemTest:Freeing half of the allocated bytearrays +INFO:MemTest:Allocating 5000 bytes +INFO:MemTest:Allocating 5000 bytes +INFO:MemTest:Allocating 5000 bytes +@@@ 45829127 +mem: total=102737, current=66214, peak=66358 +stack: 7328 out of 80000 +GC: total: 296448, used: 46112, free: 250336 + No. of 1-blocks: 324, 2-blocks: 56, max blk sz: 157, max free sz: 7209 +GC memory layout; from 7f2951dbdde0: +00000000: MDhh=hhLhhSh===h========hhhBMDhFShShhBBMDShAFShFDBDBBBhBhBBBBh== +00000800: =h===FDSB==BBBSB=BBBh=B=h=h========MDh=hFh========hhSSMhShAFh==F +00001000: ShSAFBMDFShhhDh==SDSShLhh=Lh==================================== +00001800: ================================================================ +00002000: ========================================================h=h=h... +00002800: ..FFFDh==Sh=h=S................................................. +00003000: .........................hShS...h.......................TDBMDh.. +00003800: ..h......................D...................................... +00004000: ................................................................ +00004800: ....................Sh.......Sh.......Sh...Sh......Sh..Sh......S +00005000: h..Sh......Sh...Sh......Sh.......Sh..Sh..h....Sh.......Sh..h==== +00005800: ...h==.........................................Dh=.D.Dh.h===.Dh. +00006000: h===hhh.B=BBB.Bh..hh==h===DSShh....h===BBBBBBBBhhh===B.h=B=Bh.DB +00006800: BBBBhhh=h====.B=BBhhh=hDDBBBBh===h====..h===============.h===Sh= +00007000: h=====h==============.SShD.h======hh====h===========h===h===h=== +00007800: ===h===h==hh===h============================h=S................. +00008000: ........................h==......h.h.h.h.h.....h=.h.h=.....h=.h. +00008800: ....h=.h.h=.h==.........h=.h.h.h.h===.h.h.h.h.h.h===.h.h..h=.h.h +00009000: .h.h.h.h.h.h=.h.h====..h==D.D.Bh=DB.B=BBB.Dh===BBBBBBBBB...hB.h= +00009800: ==h===B=h..Bh==h===DhB.B=hh=h.h===.DB.B=B.Bh==h===DB.B=BBBBBBBBD +0000a000: hB=BBh===.B=h========B==hhhh===..B..h==================...B=.DBB +0000a800: .h=h====hLhLhh.h=Lhhh.h=hh=.h=hTh=h=h.h===Th===h===h=h========.. +0000b000: ..h..Thh..h==h=hh=hh=h======h==h=hM.hD.......h===............... +0000b800: ........................h.B..h=DhTDhBhh=h===h===h=h============= +0000c000: =====hhBh=.Lhh=h=............A.hF...............h=============== +0000c800: ================================================================ +0000d000: ================================================================ +0000d800: =============h================================================== +0000e000: ================================================================ +0000e800: ==========================================h===================== +0000f000: ================================================================ +0000f800: ================================================================ +00010000: =======......................................................... + (111 lines all free) +00048000: ................................................ +@@@ +"""