psychopy.org | Reference | Downloads | Github

Not getting end time some of the stimuli in my routine (displays 'None' instead of a timestamp)

Hi All!

I’m currently creating an experiment in the coder view. I’ve got a problem with the offset time of certain blocks in my trail. For my My_cross the data file states both on- and offset times of My_cross. Unfortunatly the same cannot be said for my other trial components, since the data file only prints the starting point of my Fixation_cross and my two sounds. The ‘stimilus X stopped’ column reads “None” for almost all my Fixation_cross and audio stimuli. I’ve been over my script many times, and I can’t seem to find the difference between My_cross and the other three components of my trial.

tl;dr: Stimulus stopped time is printed as ‘None’ instead of a time for 3/4 components of my trial.

Here is my code:

#!/usr/bin/env python
# -*- coding: utf-8 -*-
"""
This experiment was created using PsychoPy3 Experiment Builder (v3.2.4),
    on February 13, 2020, at 17:01
If you publish work using this script the most relevant publication is:

    Peirce J, Gray JR, Simpson S, MacAskill M, Höchenberger R, Sogo H, Kastman E, Lindeløv JK. (2019) 
        PsychoPy2: Experiments in behavior made easy Behav Res 51: 195. 
        https://doi.org/10.3758/s13428-018-01193-y

"""

from __future__ import absolute_import, division

from psychopy import locale_setup
from psychopy import prefs
from psychopy import sound, gui, visual, core, data, event, logging, clock
from psychopy.constants import (NOT_STARTED, STARTED, PLAYING, PAUSED,
                                STOPPED, FINISHED, PRESSED, RELEASED, FOREVER)

import numpy as np  # whole numpy lib is available, prepend 'np.'
from numpy import (sin, cos, tan, log, log10, pi, average,
                   sqrt, std, deg2rad, rad2deg, linspace, asarray)
from numpy.random import random, randint, normal, shuffle
import os  # handy system and path functions
import sys  # to get file system encoding

from psychopy.hardware import keyboard

# Ensure that relative paths start from the same directory as this script
_thisDir = os.path.dirname(os.path.abspath(__file__))
os.chdir(_thisDir)

# Store info about the experiment session
psychopyVersion = '3.2.4'
expName = 'Steven_exp2'  # from the Builder filename that created this script
expInfo = {'participant': '', 'session': '001'}
expInfo['date'] = data.getDateStr()  # add a simple timestamp
expInfo['expName'] = expName
expInfo['psychopyVersion'] = psychopyVersion

# Data file name stem = absolute path + name; later add .psyexp, .csv, .log, etc
filename = _thisDir + os.sep + u'data/%s_%s_%s' % (expInfo['participant'], expName, expInfo['date'])

# An ExperimentHandler isn't essential but helps with data saving
thisExp = data.ExperimentHandler(name=expName, version='',
    extraInfo=expInfo, runtimeInfo=None,
    originPath='D:\\Programs\\Psychopy_standalone\\My_experiments\\restart\\steven_exp2.py',
    savePickle=True, saveWideText=True,
    dataFileName=filename)
# save a log file for detail verbose info
logFile = logging.LogFile(filename+'.log', level=logging.DEBUG)
logging.console.setLevel(logging.WARNING)  # this outputs to the screen, not a file

endExpNow = False  # flag for 'escape' or other condition => quit the exp
frameTolerance = 0.001  # how close to onset before 'same' frame

# Start Code - component code to be run before the window creation

# Setup the Window
win = visual.Window(
    size=[1920, 1080], fullscr=True, screen=1, 
    winType='pyglet', allowGUI=False, allowStencil=False,
    monitor='testMonitor', color=[0,0,0], colorSpace='rgb',
    blendMode='avg', useFBO=True, 
    units='height')
# store frame rate of monitor if we can measure it
expInfo['frameRate'] = win.getActualFrameRate()
if expInfo['frameRate'] != None:
    frameDur = 1.0 / round(expInfo['frameRate'])
else:
    frameDur = 1.0 / 60.0  # could not measure, so guess

# create a default keyboard (e.g. to check for escape)
defaultKeyboard = keyboard.Keyboard()

# Initialize components for Routine "trial"
trialClock = core.Clock()
My_Cross = visual.ShapeStim(
    win=win, name='My_Cross', vertices='cross',
    size=(0.15, 0.15),
    ori=0, pos=(0, 0),
    lineWidth=1, lineColor=1.0, lineColorSpace='rgb',
    fillColor=1.0, fillColorSpace='rgb',
    opacity=1, depth=0.0, interpolate=True)
Fix_Cross = visual.ShapeStim(
    win=win, name='Fix_Cross', vertices='cross',
    size=(0.15, 0.15),
    ori=0, pos=(0, 0),
    lineWidth=1, lineColor=[1,1,1], lineColorSpace='rgb',
    fillColor=[1,1,1], fillColorSpace='rgb',
    opacity=1, depth=-1.0, interpolate=True)
Start_Licking = sound.Sound('440', secs=0.2, stereo=True, hamming=True,
    name='Start_Licking')
Start_Licking.setVolume(0.015)
Stop_Licking = sound.Sound('220', secs=0.2, stereo=True, hamming=True,
    name='Stop_Licking')
Stop_Licking.setVolume(0.015)
from psychopy.hardware.emulator import launchScan

#settings for launchscan
MR_settings = {
    'TR': 2.400,
    'volumes': 5,
    'sync': 't'
}

vol = launchScan(win, MR_settings, globalClock=core.Clock(), mode='Scan', esc_key='escape', wait_msg='Waiting on scanner', wait_timeout=300)

# Create some handy timers
globalClock = core.Clock()  # to track the time since experiment started
routineTimer = core.CountdownTimer()  # to track time remaining of each (non-slip) routine 

# set up handler to look after randomisation of conditions etc
Loop_all = data.TrialHandler(nReps=1, method='sequential', 
    extraInfo=expInfo, originPath=-1,
    trialList=data.importConditions('16colorconditionsrandom.xlsx'),
    seed=None, name='Loop_all')
thisExp.addLoop(Loop_all)  # add the loop to the experiment
thisLoop_all = Loop_all.trialList[0]  # so we can initialise stimuli with some values
# abbreviate parameter names if possible (e.g. rgb = thisLoop_all.rgb)
if thisLoop_all != None:
    for paramName in thisLoop_all:
        exec('{} = thisLoop_all[paramName]'.format(paramName))

for thisLoop_all in Loop_all:
    currentLoop = Loop_all
    # abbreviate parameter names if possible (e.g. rgb = thisLoop_all.rgb)
    if thisLoop_all != None:
        for paramName in thisLoop_all:
            exec('{} = thisLoop_all[paramName]'.format(paramName))
    
    # ------Prepare to start Routine "trial"-------
    routineTimer.add(30.000000)
    # update component parameters for each repeat
    My_Cross.setFillColor(cross_color)
    My_Cross.setLineColor(cross_color)
    Start_Licking.setSound('440', secs=0.2, hamming=True)
    Start_Licking.setVolume(0.015, log=False)
    Stop_Licking.setSound('220', secs=0.2, hamming=True)
    Stop_Licking.setVolume(0.015, log=False)
    # keep track of which components have finished
    trialComponents = [My_Cross, Fix_Cross, Start_Licking, Stop_Licking]
    for thisComponent in trialComponents:
        thisComponent.tStart = None
        thisComponent.tStop = None
        thisComponent.tStartRefresh = None
        thisComponent.tStopRefresh = None
        if hasattr(thisComponent, 'status'):
            thisComponent.status = NOT_STARTED
    # reset timers
    t = 0
    _timeToFirstFrame = win.getFutureFlipTime(clock="now")
    trialClock.reset(-_timeToFirstFrame)  # t0 is time of first possible flip
    frameN = -1
    continueRoutine = True
    
    # -------Run Routine "trial"-------
    while continueRoutine and routineTimer.getTime() > 0:
        # get current time
        t = trialClock.getTime()
        tThisFlip = win.getFutureFlipTime(clock=trialClock)
        tThisFlipGlobal = win.getFutureFlipTime(clock=None)
        frameN = frameN + 1  # number of completed frames (so 0 is the first frame)
        # update/draw components on each frame
        
        # *My_Cross* updates
        if My_Cross.status == NOT_STARTED and tThisFlip >= 0.0-frameTolerance:
            # keep track of start time/frame for later
            My_Cross.frameNStart = frameN  # exact frame index
            My_Cross.tStart = t  # local t and not account for scr refresh
            My_Cross.tStartRefresh = tThisFlipGlobal  # on global time
            win.timeOnFlip(My_Cross, 'tStartRefresh')  # time at next scr refresh
            My_Cross.setAutoDraw(True)
        if My_Cross.status == STARTED:
            # is it time to stop? (based on local clock)
            if tThisFlip > 5.0-frameTolerance:
                # keep track of stop time/frame for later
                My_Cross.tStop = t  # not accounting for scr refresh
                My_Cross.frameNStop = frameN  # exact frame index
                win.timeOnFlip(My_Cross, 'tStopRefresh')  # time at next scr refresh
                My_Cross.setAutoDraw(False)
        
        # *Fix_Cross* updates
        if Fix_Cross.status == NOT_STARTED and tThisFlip >= 5.0-frameTolerance:
            # keep track of start time/frame for later
            Fix_Cross.frameNStart = frameN  # exact frame index
            Fix_Cross.tStart = t  # local t and not account for scr refresh
            Fix_Cross.tStartRefresh = tThisFlipGlobal  # on global time
            win.timeOnFlip(Fix_Cross, 'tStartRefresh')  # time at next scr refresh
            Fix_Cross.setAutoDraw(True)
        if Fix_Cross.status == STARTED:
            # is it time to stop? (based on local clock)
            if tThisFlip > 30.0-frameTolerance:
                # keep track of stop time/frame for later
                Fix_Cross.tStop = t  # not accounting for scr refresh
                Fix_Cross.frameNStop = frameN  # exact frame index
                win.timeOnFlip(Fix_Cross, 'tStopRefresh')  # time at next scr refresh
                Fix_Cross.setAutoDraw(False)
        # start/stop Start_Licking
        if Start_Licking.status == NOT_STARTED and tThisFlip >= 10-frameTolerance:
            # keep track of start time/frame for later
            Start_Licking.frameNStart = frameN  # exact frame index
            Start_Licking.tStart = t  # local t and not account for scr refresh
            Start_Licking.tStartRefresh = tThisFlipGlobal  # on global time
            Start_Licking.play(when=win)  # sync with win flip
        if Start_Licking.status == STARTED:
            # is it time to stop? (based on global clock, using actual start)
            if tThisFlipGlobal > Start_Licking.tStartRefresh + 0.2-frameTolerance:
                # keep track of stop time/frame for later
                Start_Licking.tStop = t  # not accounting for scr refresh
                Start_Licking.frameNStop = frameN  # exact frame index
                win.timeOnFlip(Start_Licking, 'tStopRefresh')  # time at next scr refresh
                Start_Licking.stop()
        # start/stop Stop_Licking
        if Stop_Licking.status == NOT_STARTED and tThisFlip >= 15-frameTolerance:
            # keep track of start time/frame for later
            Stop_Licking.frameNStart = frameN  # exact frame index
            Stop_Licking.tStart = t  # local t and not account for scr refresh
            Stop_Licking.tStartRefresh = tThisFlipGlobal  # on global time
            Stop_Licking.play(when=win)  # sync with win flip
        if Stop_Licking.status == STARTED:
            # is it time to stop? (based on global clock, using actual start)
            if tThisFlipGlobal > Stop_Licking.tStartRefresh + 0.2-frameTolerance:
                # keep track of stop time/frame for later
                Stop_Licking.tStop = t  # not accounting for scr refresh
                Stop_Licking.frameNStop = frameN  # exact frame index
                win.timeOnFlip(Stop_Licking, 'tStopRefresh')  # time at next scr refresh
                Stop_Licking.stop()
        
        # check for quit (typically the Esc key)
        if endExpNow or defaultKeyboard.getKeys(keyList=["escape"]):
            core.quit()
        
        # 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
        
        # refresh the screen
        if continueRoutine:  # don't flip if this routine is over or we'll get a blank screen
            win.flip()
    
    # -------Ending Routine "trial"-------
    for thisComponent in trialComponents:
        if hasattr(thisComponent, "setAutoDraw"):
            thisComponent.setAutoDraw(False)
    Loop_all.addData('My_Cross.started', My_Cross.tStartRefresh)
    Loop_all.addData('My_Cross.stopped', My_Cross.tStopRefresh)
    Loop_all.addData('Fix_Cross.started', Fix_Cross.tStartRefresh)
    Loop_all.addData('Fix_Cross.stopped', Fix_Cross.tStopRefresh)
    Start_Licking.stop()  # ensure sound has stopped at end of routine
    Loop_all.addData('Start_Licking.started', Start_Licking.tStartRefresh)
    Loop_all.addData('Start_Licking.stopped', Start_Licking.tStopRefresh)
    Stop_Licking.stop()  # ensure sound has stopped at end of routine
    Loop_all.addData('Stop_Licking.started', Stop_Licking.tStartRefresh)
    Loop_all.addData('Stop_Licking.stopped', Stop_Licking.tStopRefresh)
    thisExp.nextEntry()
    
# completed 1 repeats of 'Loop_all'

# get names of stimulus parameters
if Loop_all.trialList in ([], [None], None):
    params = []
else:
    params = Loop_all.trialList[0].keys()
# save data for this loop
Loop_all.saveAsExcel(filename + '.xlsx', sheetName='Loop_all',
    stimOut=params,
    dataOut=['n','all_mean','all_std', 'all_raw'])

# Flip one final time so any remaining win.callOnFlip() 
# and win.timeOnFlip() tasks get executed before quitting
win.flip()

# these shouldn't be strictly necessary (should auto-save)
thisExp.saveAsWideText(filename+'.csv')
thisExp.saveAsPickle(filename)
logging.flush()
# make sure everything is closed down
thisExp.abort()  # or data files will save again on exit
win.close()
core.quit()

Also, here is the data output that I can find in my files:
csv:


txt:

1.5566 	INFO 	Loaded monitor calibration from ['2019_11_12 12:27', '2019_11_12 16:01']
2.4339 	EXP 	Created window1 = Window(allowGUI=False, allowStencil=False, args=UNKNOWN, autoLog=True, bitsMode=UNKNOWN, blendMode='avg', color=array([0., 0., 0.]), colorSpace='rgb', fullscr=<method-wrapper '__getattribute__' of attributeSetter object at 0x000001919EFBC8D0>, gamma=None, gammaErrorPolicy='raise', kwargs=UNKNOWN, lms=UNKNOWN, monitor=<psychopy.monitors.calibTools.Monitor object at 0x000001919F0007F0>, multiSample=False, name='window1', numSamples=2, pos=[0.0, 0.0], screen=1, size=array([1920, 1080]), stereo=False, units='height', useFBO=True, useRetina=False, viewOri=0.0, viewPos=None, viewScale=None, waitBlanking=True, winType='pyglet')
2.4339 	EXP 	window1: recordFrameIntervals = False
2.6039 	EXP 	window1: recordFrameIntervals = True
2.6511 	WARNING 	t of last frame was 19.62ms (=1/50)
2.6737 	WARNING 	t of last frame was 22.63ms (=1/44)
2.7541 	WARNING 	t of last frame was 21.26ms (=1/47)
2.9167 	DEBUG 	Screen (1) actual frame rate measured at 61.59
2.9168 	EXP 	window1: recordFrameIntervals = False
3.7836 	EXP 	Created My_Cross = ShapeStim(__class__=<class 'psychopy.visual.shape.ShapeStim'>, autoDraw=False, autoLog=True, closeShape=True, contrast=1.0, depth=0.0, fillColor=array([1., 1., 1.]), fillColorSpace='rgb', interpolate=True, lineColor=array([1., 1., 1.]), lineColorSpace='rgb', lineWidth=1, name='My_Cross', opacity=1.0, ori=array(0.), pos=array([0., 0.]), size=array([0.15, 0.15]), units='height', vertices=ndarray(...), win=Window(...), windingRule=None)
3.7850 	EXP 	Created Fix_Cross = ShapeStim(__class__=<class 'psychopy.visual.shape.ShapeStim'>, autoDraw=False, autoLog=True, closeShape=True, contrast=1.0, depth=-1.0, fillColor=array([1., 1., 1.]), fillColorSpace='rgb', interpolate=True, lineColor=array([1., 1., 1.]), lineColorSpace='rgb', lineWidth=1, name='Fix_Cross', opacity=1.0, ori=array(0.), pos=array([0., 0.]), size=array([0.15, 0.15]), units='height', vertices=ndarray(...), win=Window(...), windingRule=None)
3.8002 	EXP 	Sound Start_Licking set volume 0.015
3.8004 	EXP 	Sound Stop_Licking set volume 0.015
3.8015 	EXP 	launchScan: vol: 5  TR: 2.400s  skip: 0  sync: 't'
3.8930 	EXP 	window1: mouseVisible = False
4.5488 	DATA 	Keypress: t
4.5490 	EXP 	launchScan: start of scan
4.5801 	DEBUG 	Read Excel file with pandas: 16colorconditionsrandom.xlsx
4.5819 	DEBUG 	Clearing unnamed columns from 16colorconditionsrandom.xlsx
4.5823 	EXP 	Imported 16colorconditionsrandom.xlsx as conditions, 16 conditions, 1 params
4.5826 	EXP 	Created sequence: sequential, trialTypes=16, nReps=1, seed=None
4.5828 	EXP 	New trial (rep=0, index=0): OrderedDict([('cross_color', 'Red')])
4.6221 	EXP 	My_Cross: fillColor = 'Red (named)'
4.6221 	EXP 	My_Cross: lineColor = 'Red (named)'
4.6221 	EXP 	My_Cross: autoDraw = True
9.5976 	EXP 	My_Cross: autoDraw = False
9.5976 	EXP 	Fix_Cross: autoDraw = True
34.5735 	EXP 	New trial (rep=0, index=1): OrderedDict([('cross_color', 'Green')])
34.5912 	EXP 	My_Cross: autoDraw = False
34.5912 	EXP 	Fix_Cross: autoDraw = False
34.5912 	EXP 	My_Cross: fillColor = 'Green (named)'
34.5912 	EXP 	My_Cross: lineColor = 'Green (named)'
34.5912 	EXP 	My_Cross: autoDraw = True
39.5705 	EXP 	My_Cross: autoDraw = False
39.5705 	EXP 	Fix_Cross: autoDraw = True
64.5562 	EXP 	New trial (rep=0, index=2): OrderedDict([('cross_color', 'Green')])
64.5805 	EXP 	Fix_Cross: autoDraw = False
64.5805 	EXP 	My_Cross: autoDraw = False
64.5805 	EXP 	Fix_Cross: autoDraw = False
64.5805 	EXP 	My_Cross: fillColor = 'Green (named)'
64.5805 	EXP 	My_Cross: lineColor = 'Green (named)'
64.5805 	EXP 	My_Cross: autoDraw = True
69.5506 	EXP 	My_Cross: autoDraw = False
69.5506 	EXP 	Fix_Cross: autoDraw = True
94.5330 	EXP 	New trial (rep=0, index=3): OrderedDict([('cross_color', 'Green')])
94.5494 	EXP 	Fix_Cross: autoDraw = False
94.5494 	EXP 	My_Cross: autoDraw = False
94.5494 	EXP 	Fix_Cross: autoDraw = False
94.5494 	EXP 	My_Cross: fillColor = 'Green (named)'
94.5494 	EXP 	My_Cross: lineColor = 'Green (named)'
94.5494 	EXP 	My_Cross: autoDraw = True
99.5276 	EXP 	My_Cross: autoDraw = False
99.5276 	EXP 	Fix_Cross: autoDraw = True
124.5267 	EXP 	New trial (rep=0, index=4): OrderedDict([('cross_color', 'Red')])
124.5422 	EXP 	Fix_Cross: autoDraw = False
124.5422 	EXP 	My_Cross: autoDraw = False
124.5422 	EXP 	Fix_Cross: autoDraw = False
124.5422 	EXP 	My_Cross: fillColor = 'Red (named)'
124.5422 	EXP 	My_Cross: lineColor = 'Red (named)'
124.5422 	EXP 	My_Cross: autoDraw = True
129.5248 	EXP 	My_Cross: autoDraw = False
129.5248 	EXP 	Fix_Cross: autoDraw = True
154.5166 	EXP 	New trial (rep=0, index=5): OrderedDict([('cross_color', 'Red')])
154.5334 	EXP 	Fix_Cross: autoDraw = False
154.5334 	EXP 	My_Cross: autoDraw = False
154.5334 	EXP 	Fix_Cross: autoDraw = False
154.5334 	EXP 	My_Cross: fillColor = 'Red (named)'
154.5334 	EXP 	My_Cross: lineColor = 'Red (named)'
154.5334 	EXP 	My_Cross: autoDraw = True
159.5170 	EXP 	My_Cross: autoDraw = False
159.5170 	EXP 	Fix_Cross: autoDraw = True
184.5065 	EXP 	New trial (rep=0, index=6): OrderedDict([('cross_color', 'Green')])
184.5271 	EXP 	Fix_Cross: autoDraw = False
184.5271 	EXP 	My_Cross: autoDraw = False
184.5271 	EXP 	Fix_Cross: autoDraw = False
184.5271 	EXP 	My_Cross: fillColor = 'Green (named)'
184.5271 	EXP 	My_Cross: lineColor = 'Green (named)'
184.5271 	EXP 	My_Cross: autoDraw = True
189.5042 	EXP 	My_Cross: autoDraw = False
189.5042 	EXP 	Fix_Cross: autoDraw = True
214.4939 	EXP 	New trial (rep=0, index=7): OrderedDict([('cross_color', 'Green')])
214.5123 	EXP 	Fix_Cross: autoDraw = False
214.5123 	EXP 	My_Cross: autoDraw = False
214.5123 	EXP 	Fix_Cross: autoDraw = False
214.5123 	EXP 	My_Cross: fillColor = 'Green (named)'
214.5123 	EXP 	My_Cross: lineColor = 'Green (named)'
214.5123 	EXP 	My_Cross: autoDraw = True
219.4928 	EXP 	My_Cross: autoDraw = False
219.4928 	EXP 	Fix_Cross: autoDraw = True
235.6936 	DATA 	Keypress: escape
235.6948 	DATA 	Keypress: quoteleft
235.9497 	EXP 	window1: mouseVisible = True
235.9499 	DEBUG 	Saving data for Steven_exp2 ExperimentHandler
235.9612 	INFO 	saved data to D:\Programs\Psychopy_standalone\My_experiments\restart\data/_Steven_exp2_2020_Feb_13_1726.psydat
235.9709 	INFO 	saved data to 'D:\\Programs\\Psychopy_standalone\\My_experiments\\restart\\data/_Steven_exp2_2020_Feb_13_1726.csv'

If anyone help with finding the cause, because this feels quite random…

Thx in advance!!

Steven

1 Like

This is caused by the stimulus actually ending after the trial has nominally ended (a visual stimulus gets removed from the screen on the first refresh of the next routine starting, which is technically on the next loop). I found a way to handle this and so I think that the new version 2020.1 should be showing you the offset times. If you don’t want to updat then the workaround is to have another component that lasts very slightly longer than the one for which you desperately need the timestamps.

Showing or not showing those offset times has no impact on actual timing though, it’s just the rporting

1 Like

Oh, I say this, but if you’re using a script rather than the Builder interface then upgrading won’t help. The update gave Builder a new way to generate the code that can handle tagging the times, but it doesn’t change the hbehaviour of existing code in a script

Hi @jon , just curious here. I’m using the builder (v2020.1.2) and this seems to still be an issue. All my .stopped values are None (for lines, visual and text). All of them are terminated by a click (using the built-in option to end the routine) or by a custom python code snippet that checks on every frame whether the correct click was pressed (left or right).
I’m recording rt using a python inserted code so is not a big deal, but if it is solved it would ease my mind see fewer None values in the output data :sweat_smile:.

Dear @jon, I am also experiencing the same issue with None values for .stopped events, and the likely related issue of .rt events being 0. Had described these as problems 1. and 2. in this older post from February.