Linear memory increase when rerunning an Arcade program

[ttcdm]

Bug Report

System Info

Arcade 2.6.17

vendor: Intel renderer: Intel(R) HD Graphics 530 version: (4, 6) python: 3.10.4 (tags/v3.10.4:9d38120, Mar 23 2022, 23:13:41) [MSC v.1929 64 bit (AMD64)] platform: win32

Background information:

I made a platformer game in Arcade. It is ran via a PySimpleGui button in a gui, which is basically a gui with a button on it. It checks for button presses via a while loop. The entire game is housed under an if statement that's inside the while loop. i.e. while True: if button_pressed: #### Arcade code here ####

I've used a memory profiler for both the while loop of the gui and for the main() function of Arcade, and I've also produced a graph of the overall memory usage.

Memory profilers used:

• tracemalloc
• memory_profiler

The tracemalloc results are negligent from what I can observe. Commands:

• mprof run the_python_file.py
• mprof.plot

Run these in the terminal.

The lag is indicated by the delta_time property in the on_update() block. When the program is first ran, it is about 0.0166.

After failing to fix this issue, I tried reproducing this on an almost blank Arcade program, as shown below. The bug was less pronounced on the smaller program. It took many more reruns to produce a large amount of lag. In the original program, it would take about 5-6 reruns to make the game almost unplayable. With the smaller program, it would take about 20-30 reruns before reaching the same amount of lag. However, the tracemalloc (while loop) result was about the same for both. The gaps between each memory spike was beacuse I was manually pressing the button, and as the window took longer and longer to load, I zone out, and it takes me longer to realize and press the button again.

There was no noticeable lag between the button press and the window opening no matter how high the delta_time was. However, when the window opens, it is a white screen, which indicates that the program is loading, and then it turns into a black screen, which I'd assume is the background color, which means that the program has loaded. The white screen, however, is almost unseen when the program is first run, but stays longer as the number of reruns increase.

For both programs, I've extensively tried to clean up all data that was ever used, and the process is killed afterwards. I've done this by:

1. Putting all of the properties, i.e., self.property1, to None
2. Deleting all of those properties/mark them up for garbage collection, i.e., del self.property1
3. Running arcade.close_window(), arcade.clear_timings(), arcade.cleanup_texture_cache(), and arcade.exit()
4. Deleting the instance of the class in the same way
5. Running gc.collect, which is the function for manually calling garbage collection

Actual behavior:

A linear memory increase happens when I rerun an Arcade program. When I first run the game, it runs completely normally; no lag, no memory increase, etc. However, when I close the window via pressing the "X" in the top right corner of the window and press the button again, there's a tiny amount of lag. This lag then increases with each rerun of the game. The delta_time also increases with each rerun. The time it takes to load the window also takes significantly longer.

However, the memory increase is only linear from the 2nd or 3rd run onwards. The 2nd run is about 1.5 times that of the 1st, and the 3rd run is a bit more than the 2nd.

Expected behavior:

1. The memory usage of the game should stay the same after each rerun of it.
2. The delta_time should stay at about 0.0166-0.0168

Steps to reproduce/example code:

from memory_profiler import profile
from statistics import mean
class agame(arcade.Window):
    def __init__(self):
        super().__init__(720, 720, "a")
        self.hi = None#placeholder property; unused
        self.l = None

    def setup(self):
        self.x = 0
        self.l = []#list for multiple delta_time

    def on_draw(self):
        pass

    def on_close(self):
        arcade.close_window()#closing the window
        self.on_exit()#runs the on_exit() function below

    def on_exit(self):
        print(mean(self.l[2:]))#printing the average delta_time
        del self.hi#deletion of objects
        del self.x
        del self.l
        arcade.clear_timings()
        arcade.cleanup_texture_cache()
        arcade.exit()#exiting arcade

    def on_update(self, delta_time):
        self.x += 1#increment counter for each tick
        self.l.append(delta_time)#appending delta_time to a list
        if self.x > 14:#closes the game after 15 ticks
            self.on_close()

@profile
def amain1():
    window = agame()#instantiating the class
    window.setup()#running the setup function
    arcade.run()#running the main loop, i.e., on_draw and on_update()
    del window

if __name__ == "__main__":
    amain1()
del agame
del amain1
gc.collect()#garbage collection

Attached files

arcade lag bug memory profiles.txt The large floats are the average of the 3rd to last delta_time floats for each run. It starts at the third time because the first and second floats were usually very erratic and did not seem to have any correlation with any of the other runs' times nor with the other times in the current running.

[ttcdm]

Sorry, I accidentally pressed ctrl+enter and posted the issue. I'm not done documeting. I also accidentally pressed the "close issue with comment" button accidentally as well because I thought that it was a toggle between closing and reopening the comment, which makes no sense, and there is also a blazingly obvious dropdown button to the right of it.

[ttcdm]

Done documenting.

[einarf]

That could be either from arcade or pyglet. That being said. arcade 3.0 dev is like 9 months past 2.6 with pretty heavy development. We're also using a stable verison of pyglet in 3.0. Earlier versions are using pyglet 2.0 pre-release.

Still we should probably run check this in current 3.0.

You can also grab latest 3.0dev from pypi and see.

[ttcdm]

So I tried using the dev versions, and they were 3.0.0.dev19 and 2.7.1.dev11. They both ran fine during the first run, but when I tried to rerun it, it raised a shared context error within pyglet and it occured at the main() function (amain1()).

Run Result:

C:\Users\Titus\AppData\Local\Programs\Python\Python310\python.exe C:/Users/Titus/Downloads/pp5_dirty_Copy.py
0.017170561537988342
Filename: C:\Users\Titus\Downloads\pp5_dirty_Copy.py

### vvv 1st run vvv ###

Line #    Mem usage    Increment  Occurrences   Line Contents
=============================================================
   477    105.6 MiB    105.6 MiB           1           @profile
   478                                                 def amain1():
   479    127.8 MiB     22.1 MiB           1               window = agame()#instantiating the class
   480    127.8 MiB      0.0 MiB           1               window.setup()#running the setup function
   481    127.5 MiB     -0.2 MiB           1               arcade.run()#running the main loop, i.e., on_draw and on_update()
   482    127.5 MiB      0.0 MiB           1               del window

### vvv 2nd run vvv ###

Traceback (most recent call last):
  File "C:\Users\Titus\Downloads\pp5_dirty_Copy.py", line 485, in <module>
    amain1()
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\memory_profiler.py", line 1188, in wrapper
    val = prof(func)(*args, **kwargs)
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\memory_profiler.py", line 761, in f
    return func(*args, **kwds)
  File "C:\Users\Titus\Downloads\pp5_dirty_Copy.py", line 479, in amain1
    window = agame()#instantiating the class
  File "C:\Users\Titus\Downloads\pp5_dirty_Copy.py", line 446, in __init__
    super().__init__(720, 720, "a")
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\arcade\application.py", line 143, in __init__
    super().__init__(width=width, height=height, caption=title,
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\pyglet\window\win32\__init__.py", line 104, in __init__
    super(Win32Window, self).__init__(*args, **kwargs)
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\pyglet\window\__init__.py", line 578, in __init__
    self._create()
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\arcade\application.py", line 751, in _create
    super()._create()
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\pyglet\window\win32\__init__.py", line 258, in _create
    self.context.attach(self.canvas)
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\pyglet\gl\win32.py", line 255, in attach
    super(Win32ARBContext, self).attach(canvas)
  File "C:\Users\Titus\AppData\Local\Programs\Python\Python310\lib\site-packages\pyglet\gl\win32.py", line 202, in attach
    raise gl.ContextException('Unable to share contexts.')
pyglet.gl.ContextException: Unable to share contexts.

Process finished with exit code 1

[einarf]

Pyglet version

import gc
import pyglet

class Test(pyglet.window.Window):
    def __init__(self):
        super().__init__(100, 100, "Test")
        self.frame = 0

    def on_draw(self):
        print(" -> on_draw", id(self))

    def on_update(self, delta_time):
        self.frame += 1
        print(" -> on_update", id(self))
        if self.frame == 3:
            self.close()

def main():
    for i in range(20):
        print(i)
        window = Test()
        print("--- New window", id(window))
        pyglet.clock.schedule_interval(window.on_update, 1/60)
        pyglet.app.run()
        del window
        gc.collect()

if __name__ == "__main__":
    main()

[ttcdm]

Yea so I tested it, and after printing out the delta times, the delta times still increase. Also, the amount of cycles/frames increases by three for each run, which leads me to think: are the programs being stacked on top of each other for every rerunning of the program? Slightly modified code:

        import pyglet

        class Test(pyglet.window.Window):
            def __init__(self):
                super().__init__(100, 100, "Test")
                self.frame = 0

            def on_draw(self):
                #print(" -> on_draw", id(self))
                pass

            def on_update(self, delta_time):
                self.frame += 1
                #print(" -> on_update", id(self))
                print(" -> ", delta_time)#edited here
                if self.frame == 3:
                    self.close()

        def main():
            for i in range(20):
                print(i)
                window = Test()
                #print("--- New window", id(window))
                pyglet.clock.schedule_interval(window.on_update, 1 / 60)
                pyglet.app.run()
                del window
                gc.collect()

        if __name__ == "__main__":
            main()

Run results delta_times pyglet.txt

[einarf]

We figured out it's the pyglet.clock.Clock that keeps references to window. Not entirely sure how to fix this yet. There are several issue related to opening several windows that needs to be resolved in pyglet.

[einarf]

Making your own default clock is one way to solve the issue it seems

def main():
    for i in range(20):
        print(i)
        new_clock = pyglet.clock.Clock()
        pyglet.clock.set_default(new_clock)
        window = Test()
        print("--- New window", id(window))
        pyglet.clock.schedule_interval(window.on_update, 1/60)
        pyglet.app.run()
        del window
        gc.collect()

It's something that needs to be resolved in pyglet.

[einarf]

Discussion on the pyglet discord here: https://discord.com/channels/438622377094414346/698692808948711435/1088199401987641484

This should really be converted into a pyglet issue.

[ttcdm]

I noticed that you never unscheduled the clock, and that caused the # of frames per run to increase by three, like I said before. However, when I did pyglet.clock.unschedule(window.on_update), the # of frames did not increase per run. It stayed at three.

def main():
    for i in range(20):
        print(i)
        window = Test()
        #print("--- New window", id(window))
        pyglet.clock.schedule_interval(window.on_update, 1 / 60)
        pyglet.app.run()
        pyglet.clock.unschedule(window.on_update)### HERE
        del window
        gc.collect()

Pyglet version

import gc
import pyglet

class Test(pyglet.window.Window):
    def __init__(self):
        super().__init__(100, 100, "Test")
        self.frame = 0

    def on_draw(self):
        print(" -> on_draw", id(self))

    def on_update(self, delta_time):
        self.frame += 1
        print(" -> on_update", id(self))
        if self.frame == 3:
            self.close()

def main():
    for i in range(20):
        print(i)
        window = Test()
        print("--- New window", id(window))
        pyglet.clock.schedule_interval(window.on_update, 1/60)
        pyglet.app.run()
        del window
        gc.collect()

if __name__ == "__main__":
    main()

However, when I did it in this program, it got stuck on the 2nd run (1st rerun). It seemed to be stuck a loop with the pyglet.app.run() function. But, when I removed it, the pyglet.app.run() function was still stuck in a loop, but the # of frames were increasing.

Making your own default clock is one way to solve the issue it seems

def main():
    for i in range(20):
        print(i)
        new_clock = pyglet.clock.Clock()
        pyglet.clock.set_default(new_clock)
        window = Test()
        print("--- New window", id(window))
        pyglet.clock.schedule_interval(window.on_update, 1/60)
        pyglet.app.run()
        del window
        gc.collect()

It's something that needs to be resolved in pyglet.

Code: pyglet1.txt Run result without unschedule: pyglet1 run result.txt

Lastly, I'm not in the pyglet discord server. Would you mind sending me the link?

[einarf]

https://discord.gg/QXyegWe https://discord.gg/ZjGDqMp

[ttcdm]

The rest of the comments are on the pyglet discord server. The issue has been fixed with

        def main():
            nclock = pyglet.clock.Clock()
            pyglet.clock.set_default(nclock)
            pyglet.app.event_loop.clock = nclock
            window = game()
            pyglet.clock.schedule_interval(window.on_update, 1 / 60)
            window.setup()
            arcade.run()
            pyglet.clock.unschedule(window.on_update)

Furthermore, for the issue with calling self.close() and the methods that do the same function, it has been fixed with

            def on_close(self):
                print(mean(self.lll))#print avg of delta_time list
                arcade.close_window()

            def on_update(self, delta_time):
                self.aaa += 1#frame counter
                self.lll.append(delta_time)#appending delta_time to list of delta_time
                if self.aaa > 15:
                    self.on_close()
                    return#must return or else on_update() will continue to run through, and the subsequent lines will try to call the already closed window. one workaround is to place this block at the very end of on_update() because there's nothing to run after that
                ### rest of on_update() code