I am using Psychopy as a python package and I am trying to update coordinates of 300 elements in ElementArray stimulus:
stim.xys = newXYs # newXYs is a 300 x 2 numpy array
Updating the coordinates takes ca. 16 ms as measured by %timeit (15.9 ms ± 186 µs per loop (mean ± std. dev. of 7 runs, 100 loops each)). I am wondering has anyone done some benchmarking and, if so, what would be the expected duration of updating xys?
NB - I noticed that, in the xys function in the elementarray.py method definition, the new attribute is written into self._dict_[‘xys’] and a flag is set to self._needVertexUpdate. The actual vertex update is, however, executed in self.draw() function which I did not call when doing benchmarking.
I tend to find a massive difference depending on whether autoLog is set; with autoLog=True, it can be 5-10 ms, whereas with autoLog=False it is 5-10 µs.
Disabling autolLog makes a huge difference. The new duration is 209 µs ± 3.53 µs per loop (mean ± std. dev. of 7 runs, 1000 loops each) relative to the original 16 ms. Thanks for pointing this out.
However, I am somewhat concerned about the autoLog feature on its own. It appears to slow down things dramatically - if my calculations are correct, the command is ca 70 times slower with autoLog than without. So far, I never made use of autoLog, so I am not quite certain how critical this feature is. From my perspective, it might be worth considering of the default option being autoLog=False, and having people intentionally enable it. Would be nice to hear what @jon has to say about it.
I think autolog is a useful feature for most users - if you forget to track some piece of data then it will most likely be stored for you anyway (with timing info so you can debug the study). If we set it off by default then it doesn’t do its job.
What we need to do is work out why it’s taking so much time. That shouldn’t be the case. Logging was deliberately constructed to be fast - e.g. it doesn’t write anything to disk until the end of the study, or an explicit flush() call.
It probably means that the logging call is trying to store too much info (like converting all the xy positions to text rather than just saying “XY has changed”?)
OK, yes, this all seems to be due to numpy converting to a string during the logging call. Interestingly this is no problem for v small arrays, but it grows with size and with dimensions:
>>> import timeit
>>> N = 1000
>>> timeit.timeit('a.__repr__()',setup='import numpy; a = numpy.random.random([2,2])', number=N)/N
9.960579872131347e-05
>>> timeit.timeit('a.__repr__()',setup='import numpy; a = numpy.random.random([20])', number=N)/N
0.00020077669620513917
>>> timeit.timeit('a.__repr__()',setup='import numpy; a = numpy.random.random([200])', number=N)/N
0.0014037796020507812
>>> timeit.timeit('a.__repr__()',setup='import numpy; a = numpy.random.random([2,500])', number=N)/N
0.0068386316299438475
So I think a reasonable compromise of speed and data safety is to check whether the new value (XYs here, but could be anything) is a numpy array bigger than 2x2 and, if so, log it simply as value of type(value).
Wow, I actually ran an experiment where this was a problem. I was surprised how slow everything was so I rendered frames to a texture prior to presentation. This seems to fix the issue. I suggest also looking at the code the sets element colors too (if you haven’t already).
I suggest also looking at the code the sets element colors too (if you haven’t already).
The same logAttrib should be called for XYs, colors, sizes, and all other attributes. So the fix I’ve provided should already work for any time a numpy array is used as a value being set.