psychopy.org | Reference | Downloads | Github

Memory leak - what could _LogEntry be?

I’ve used objgraph (from https://mg.pov.lt/objgraph/) to try to locate the source of a memory leak in my code. I have objgraph.show_growth() running on each iteration of my loop and it is showing me the feedback below. ’ _LogEntry’ seems to be the main offender… does anyone know what that might be and how I might clear it to resolve the memory leak issue?

show growth…
list 37297 +37297
function 36368 +36368
dict 25299 +25299
tuple 17188 +17188
builtin_function_or_method 16684 +16684
wrapper_descriptor 8303 +8303
cell 7845 +7845
weakref 6932 +6932
c_void_p 6588 +6588
method_descriptor 6162 +6162

show growth…
_LogEntry 186 +65
wrapper_descriptor 8315 +12
c_byte_Array_6144 13 +9
c_byte_Array_4096 22 +9
getset_descriptor 5558 +8
VertexList 88 +7
dict 25305 +6
weakref 6936 +4
tuple 17191 +3
member_descriptor 2045 +3

show growth…
_LogEntry 275 +89
dict 25327 +22
c_byte_Array_6144 19 +6
c_byte_Array_4096 28 +6
c_byte_Array_2048 23 +2
VertexList 90 +2
builtin_function_or_method 16685 +1

show growth…
_LogEntry 382 +107
dict 25341 +14
c_byte_Array_4096 32 +4
c_byte_Array_6144 23 +4
c_byte_Array_2048 25 +2

show growth…
_LogEntry 477 +95
getset_descriptor 5566 +8
tuple 17197 +6
dict 25346 +5
StgDict 839 +4
weakref 6939 +3
PyCArrayType 126 +2
weakcallableproxy 126 +2
PyCPointerType 146 +2

show growth…
_LogEntry 542 +65
frame 13 +2
tuple 17198 +1
show growth…
_LogEntry 640 +98
dict 25361 +15

show growth…
_LogEntry 705 +65

show growth…
_LogEntry 773 +68
dict 25366 +5

show growth…
_LogEntry 844 +71
dict 25371 +5

show growth…
_LogEntry 912 +68
getset_descriptor 5578 +12
tuple 17206 +8
dict 25379 +8
StgDict 845 +6
weakref 6944 +5
PyCArrayType 129 +3
weakcallableproxy 129 +3
PyCPointerType 149 +3

show growth…
_LogEntry 965 +53
builtin_function_or_method 16686 +1
tuple 17207 +1

Ok so on the assumption that _LogEntry is involved in logging, I commented out anything to do with logging and sure enough the _LogEntry growth disappeared

However various other things are still leaking, and the memory usage is still ramping up. Any ideas for uncovering what’s causing the below?

show growth…
wrapper_descriptor 8315 +12
c_byte_Array_6144 13 +9
c_byte_Array_4096 22 +9
dict 25274 +7
VertexList 87 +6
getset_descriptor 5556 +4
member_descriptor 2045 +3
weakref 6939 +3
method_descriptor 6163 +1

show growth…
getset_descriptor 5564 +8
tuple 17200 +6
dict 25280 +6
StgDict 838 +4
c_byte_Array_6144 16 +3
c_byte_Array_4096 25 +3
PyCArrayType 125 +2
weakref 6941 +2
weakcallableproxy 125 +2
VertexList 89 +2

show growth…
dict 25291 +11
c_byte_Array_4096 30 +5
c_byte_Array_6144 21 +5
c_byte_Array_2048 23 +3
VertexList 90 +1

show growth…

show growth…

dict 25296 +5
getset_descriptor 5568 +4
tuple 17203 +3
StgDict 840 +2
PyCArrayType 126 +1
c_byte_Array_6144 22 +1
c_byte_Array_4096 31 +1
weakref 6942 +1
weakcallableproxy 126 +1
PyCPointerType 146 +1

show growth…

show growth…

frame 12 +1

show growth…

show growth…

show growth…

getset_descriptor 5580 +12
tuple 17212 +9
StgDict 846 +6
PyCArrayType 129 +3
weakref 6945 +3
weakcallableproxy 129 +3
PyCPointerType 149 +3

Can you post your code, or a similar example, that is showing the leaking behaviour?

Hi @djmannion - sure thing! Here’s the code…:

AP_exp_1_debugging.py (77.9 KB)

Sorry to call you in @jon and @Michael , but any idea about this…?

Ok so this is weird… on my mac’s Activity Monitor the PsychoPy memory usage still keeps on ramping up - I let it get to the point where it crashed and it was using something like 2.54 GB of memory… What’s odd is that the memory still ramped up when I just let the experiment screen run and didn’t provide any responses. When I checked the regular feedback from obj graph.show_growth() in general the growth was either nothing (mostly) or a few classes growing by a small amount (e,g. +1). As I mentioned before, none of the variables in my code is changing in size at all…

To test if the problem is just running PsychoPy on my computer I tried opening the stoop test practice experiment that I made when i first used PsychoPy, and watched for an increase in memory usage - there wasn’t an increase.

So i’m still not sure what’s causing this… any thoughts would be massively appreciated (really struggling, and it’s holding back my PhD a lot…)

OK, so you’ve isolated that it is something specific to your code, and you now have ways of tracking memory use. So to isolate it within your code, you can apply some sort of binary search. e.g. cut out the second half of your experiment (or whatever substantial aspects are feasible given your design). Does the problem persist? If so, cut down the code again. If not, start working through the other part of the code.

I think this is the bit of code that is a problem. On inspection I seem to be asking the code to collect a lot of stuff on every single frame, which is unnecessary and I’m guessing (completely intuitively) could be the source of the problem? What do you guys think? In particular I seem to be resetting text on every single frame:

score_text = visual.TextStim(win=win, name='score_text', text= score_update ,font='Arial',pos=(0.6, 0.3), height=0.1, wrapWidth=None, ori=0, color='white', colorSpace='rgb', opacity=1,depth=-2.0) 

Obviously this is a dumb thing to do, and I should update it. Is there any reason to think this might be the source of the problem? I had a chat with someone recently that said that memory usage in code was in itself a problem… I didn’t completely understand him. He was suggesting that I should do pretty much everything with functions, and that somehow this avoids memory usage - I guess that’s good advice? Looking at the code does anything jump out to you that could be the problem here. Given that the memory usage seems to be ramping up without any participant response, probably only the first layer of the loop will be of relevance (although if audio_stimulus.status == NOT_STARTED: and if t = 0.0 and key_resp_2.status == NOT_STARTED: will have run/started running).

I’m presuming that the various variable names here are intuitive, but I’m happy to describe them all/any of them, if required…:

                 while continueRoutine: 
                    old_how_many_correct = how_many_correct
                    # get current time
                    t = trialClock.getTime() 
                    score_text.setAutoDraw(False) # deletes the last score_text 
                    # the below updates the text to be used as score_text: 
                    score_update = (str(ggg) + ' melodies\nPart 1\n\nCompleted ' + str(how_many_goes) + ' / ' + str(total_conditions) + '\n' + 'Score = ' + str(how_many_correct) + '\n' + str(percent) + '%\n\nPrevious =\n' + str(is_it_correct) + '\n' + str(AP_correctAns) )
                    # the below updates the score_text:
                    score_text = visual.TextStim(win=win, name='score_text', text= score_update ,font='Arial',pos=(0.6, 0.3), height=0.1, wrapWidth=None, ori=0, color='white', colorSpace='rgb', opacity=1,depth=-2.0);
                    
                    if audio_stimulus.status == NOT_STARTED:
                        # keep track of start time/frame for later
                        audio_stimulus.tStart = t
                        audio_stimulus.frameNStart = frameN  # exact frame index
                        audio_stimulus.play()  # start the sound (it finishes automatically)
                    
                    # *key_resp_2* updates
                    if t >= 0.0 and key_resp_2.status == NOT_STARTED:
                        # keep track of start time/frame for later
                        key_resp_2.tStart = t
                        key_resp_2.frameNStart = frameN  # exact frame index
                        key_resp_2.status = STARTED
                        # keyboard checking is just starting
                        win.callOnFlip(key_resp_2.clock.reset)  # t=0 on next screen flip
                        event.clearEvents(eventType='keyboard')
                    
                    # COLLECTING THE RESPONSES:
                    if key_resp_2.status == STARTED:
                       theseKeys = event.getKeys(keyList=key_strings) # will only collect keys from those specified in key_strings, all others are banned 
                        # check for quit:
                        if "escape" in theseKeys:
                            endExpNow = True 
                            
                            ########################################
                        if len(theseKeys) > 0:  # at least one key was pressed
                            key_resp_2.keys = theseKeys[0]  # just the last key pressed
                            key_resp_2.rt = key_resp_2.clock.getTime()

                            # was this 'correct'?...............:
                            # LOOP LAYER within 'if at least one key was pressed' loop:
                            if (key_resp_2.keys == str(corrAns)) or (key_resp_2.keys == corrAns):
                                key_resp_2.corr = 1 # store that the answer was correct 
                                how_many_correct += 1 # tally that the answer was correct
                                how_many_goes +=1 # tally that 1 more go has taken place 
                                AP_correctAns = songTitle # for the purpose of on screen text..
                                is_it_correct = 'Correct:' # for the purpose of on screen text..
                                percent = int((how_many_correct/how_many_goes) * 100) # for the purpose of on screen text..
                                audio_stimulus.stop() # stop playing the audio_stimulus 
                               
                                # WARNING! With the below code I initially wanted the correct_text to show, and the incorrect text to be set to finished, however, I couldn't get the correct_text to display, so this code is currently redundant I think 
                                if t >= 0.0 and correct_text.status == NOT_STARTED:
                                    correct_text.tStart = t
                                    correct_text.frameNStart = frameN  # exact frame index
                                    correct_text.setAutoDraw(True)
                                    incorrect_text.status = FINISHED
                                
                                audio_feedback.status = FINISHED # the audio_feedback doesn't play if the response was correct    
                            else:
                                key_resp_2.corr = 0 # store that the answer was incorrect
                                how_many_goes +=1 # tally that one more go has taken place
                                AP_correctAns = songTitle # for the purpose of on screen text..
                                is_it_correct = '' # for the purpose of on screen text..
                                percent = int((how_many_correct/how_many_goes) * 100) # for the purpose of on screen text..
                                audio_stimulus.stop() # stop playing the audio_stimulus 
                                audio_feedback.tStart = t # start playing the audio_feedback 
                                audio_feedback.frameNStart = frameN  # exact frame index
                                audio_feedback.play()
                               
                               # the below code starts the on screen text saying 'INCORRECT' and sets correct_text (currently redundant anyway) to FINISHED 
                                if t >= 0.0 and incorrect_text.status == NOT_STARTED:
                                    # keep track of start time/frame for later
                                    incorrect_text.tStart = t
                                    incorrect_text.frameNStart = frameN  # exact frame index
                                    incorrect_text.setAutoDraw(True)
                                    correct_text.status = FINISHED
                            
                            #################
                            
                            
                        # The next bit of code is probably redundant, as a response must be made in the experiment 
                        if key_resp_2.keys in ['', [], None]:  # No response was made
                            key_resp_2.keys=None
                           # was no response the correct answer?!
                            if str(corrAns).lower() == 'none':
                               key_resp_2.corr = 1  # correct non-response
                            else:
                               key_resp_2.corr = 0  # failed to respond (incorrect)
                               
                        #store data for trials (TrialHandler)
                        trials.addData('key_resp_2.keys',key_resp_2.keys)
                        trials.addData('key_resp_2.corr', key_resp_2.corr)
                        if key_resp_2.keys != None:  # we had a response
                            trials.addData('key_resp_2.rt', key_resp_2.rt)

                    
                    ##########################################################
                    
                     #UPDATING THE ON SCREEN TEXT: 
                     
                    # *text_2* updates
                    if t >= 0.0 and text_2.status == NOT_STARTED:
                        # keep track of start time/frame for later
                        text_2.tStart = t
                        text_2.frameNStart = frameN  # exact frame index
                        text_2.setAutoDraw(True)
                        
                    # *score_text* updates
                    if t >= 0.0 and score_text.status == NOT_STARTED:
                        # keep track of start time/frame for later
                        score_text.tStart = t
                        score_text.frameNStart = frameN  # exact frame index
                        score_text.setAutoDraw(True)                    
                    
                   
                    if audio_feedback.status == FINISHED and correct_text.status == FINISHED or incorrect_text.status == FINISHED:
                        continueRoutine = False 
                    ##########################################
                    
                    # check if all components have finished
                    if not continueRoutine:  # a component has requested a forced-end of Routine
                        break
                    continueRoutine = False  # will revert to True if at least one component still running
                    for thisComponent in trialComponents:
                        if hasattr(thisComponent, "status") and thisComponent.status != FINISHED:
                            continueRoutine = True
                            break  # at least one component has not yet finished
                    
                    # check for quit (the Esc key)
                    if endExpNow or event.getKeys(keyList=["escape"]):
                        thisExp.saveAsWideText(filename+'.csv')
                        # added the save to excel file bit into the escape bit, to make sure it saves the data. 
                        core.quit()
                    # refresh the screen
                    if continueRoutine:  # don't flip if this routine is over or we'll get a blank screen
                        win.flip()

Thoughts? Thanks! :slight_smile:

For a start, you shouldn’t re-create a stimulus on every frame. This takes a lot of time (if not memory). You should create your score_text variable just once, and then in your drawing loop, you just update its properties as required. e.g.

score_text.text = score_update

Now there is a known underlying memory leak in a library that we rely on (pyglet) in precisely this situation (rapidly updating the text value of a text stimulus). This might be what you are encountering. I know @jon is at work on developing a new text stimulus that would avoid this limitation in pyglet and hopefully that won’t be too far away.

2 Likes

Thanks!