Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

Supported by

[open] Presentation time issues using canvas.image() in opensesame v27

edited December 2012 in OpenSesame

Hi,

I am experiencing some issues concerning the presentation time of pictures that are rapidly presented one after the other. I am running an attentional blink experiment which presents 17 pictures in a row, each for 100 ms.

Although sleep time between the presentation of each canvas (containing a single picture) is 100ms, the whole sequence needs 3,5-3,7s to run through (more than 200ms per picture). The problem occurs in every trial also the very first, which has led me to the conclusion that it might not be solved by deleting all canvas after each trial. Strangely enough, this problem only occurs in the newly released version 27 (but also on the development version 22), NOT however in the old version v26.

I always use the psychopy engine and preload the images in the prepare phase (thus only use the .show function 17 times using a for-loop in the run phase). It is maybe also important to note that the images are not loaded into the file pool but instead a called via their original path.

Does anyone have an idea why this happens only in the new version and or have an advice how to solve it?

Comments

  • Hi Michel,

    Would it perhaps be possible to upload your experiment? Although your explanation is very clear and obviously rules out some possibilities, it is still a bit difficult to find out what might be causing the delay without seeing the experiment.

    Best wishes,

    Lotje

  • edited December 2012

    Sure!

    The prepare phase for the path attachment is a little bit crowded/overly nested. But in a nutshell it produces a list of canvas', each loaded a single picture from a path depending on the condition and the variables defined as in the block loop.


    Prepare-phase


    path = []
    exp.canvas_pictures = range(17)
    for i in range(17):
    exp.canvas_pictures[i] = self.offline_canvas()
    # distractor and target path definition with if statements just like the neutral trial
    # neutral
    else:
    path.append(os.path.normcase(os.path.join(exp.experiment_path,'pictures','landscape/')) + trial_pictures_list[i])
    exp.canvas_pictures[i].image(path[i])
    # Save the path
    exp.set("path"+str(i+1),path[i])


    The run phase then loops through the canvas list and shows each item for 100 ms.


    Run Phase


    for img in exp.canvas_pictures:
    img.show()
    exp.sleep(100)

    If I calculate the time of just the for loop in the run phase my subjective feeling that each picture is presented too long in only the latest version of OpenSesame is confirmed. Also sometimes I get weird trials in which only the very first picture lags (presented slightly longer than the other 16). However, I can't reproduce that error at the moment.

    Thanks for the help!

    EDIT: I reduced the code to make it more readable.

  • edited 4:06AM

    Hi Michel,

    You're code looks fine, but I was wondering: How do you check the presentation time? It's probably best to store the timestamps returned by img.show() in a list, and print them out afterwards. It could very well be that presentation is indeed slow, but then we know exactly what we're talking about:

    l = []
    for img in exp.canvas_pictures:
        t = img.show()
        l.append(t)
        exp.sleep(100)
    for t in l:
        print t
    

    Btw, the reason for storing the timestamps in a list first, rather then printing them out directly, is that printing to the debug window causes a slight delay in itself.

    Cheers!

  • edited December 2012

    Hi sebastiaan,

    I actually deleted the time check lines, since I included them only for debugging reasons. My assumption was however not entirely based on the values but also on the mere perception when starting the same code in either the v26 or v27. Here is what I did to check the time:


    import time t = time.time()
    for img in exp.canvas_pictures:
    img.show()
    exp.sleep(100) elapsed = time.time() - t
    print elapsed


    I am aware that there are delays in the presentation times between trials as well as when started in different version which might be entirely due to the print function. However, the pattern appears very distinct:

    v26 - mean after 10 trials: 1850ms (around 110ms for each picture)

    v27 - mean after 10 trials: 3600ms (around 210ms for each picture)

    ...both with low variability (around 100-200ms). I might check for more trials in a row.

    This in combination with my subjective experience (which occurred before I checked the objective presentation times) gives me the impression that the timing is really not correct.

    I will quickly run with your code and update this post.


    Edit:

    Ok, now I just got these weird fluctations again. But see yourself:
    Here the times for the first 17 pictures in v26 (follow up trials are comparable):
    7583.10036611
    7699.77944124
    7816.4303005
    7933.09903912
    8049.76302854
    8166.4314878
    8283.09603595
    8399.759746
    8516.52765924
    8633.11677881
    8749.75562537
    8866.43777352
    8983.09198515
    9099.75625394
    9216.42275764
    9333.09456928
    9449.75632378


    Looks like decent ~110 ms steps.


    And for v27 the first 17:

    8816.39091002
    8933.05462007
    9049.72056504
    9166.38930367
    9283.06307087
    9399.72175235
    9516.38602113
    9633.05001055
    9749.72461584
    9866.38190049
    9983.05482959
    10099.715746
    10216.3811322
    10333.0470772
    10449.7146984
    10566.3828783
    10683.0474264


    Also, decent ~110ms in the first two trials.


    But then in the third trial:

    20916.308637
    21116.1312401
    21316.1460465
    21516.1924211
    21716.1421354
    21916.2256656
    22116.0884973
    22316.194656
    22516.1778941
    22716.2524846
    22916.1555449
    23116.0644719
    23316.1114052
    23516.1496782
    23716.0831893
    23916.1927005
    24116.1385036


    Now we got stable 200ms for each picture. Looks like some memory issue or what could be the reason why the times change all of the sudden? Note that the time have almost NO variation anymore (only for the first picture)! The same in the upcoming trials.
    Also, I rechecked with my old printing time attemps: It looks like my initial thought of having a comparable variation of 210ms in the new OpenSesame versions, was basically also exactly 200ms except for the first trial which is apparently even slower than the subsequent 16 pictures and therefore reducing the overall time to just a little bit more than 200ms per picture.
  • edited 4:06AM

    You're probably right, I'm not questioning that, but the code I posted potentially gives more insight, because it logs the timestamp for every image. Could you please run that and post the results? Perhaps you could try it with sequences of varying lengths (say with 1, 4, 8, and 16 images), to see if memory load might be an issue.

  • edited December 2012

    Short update:

    I ran it with 1,4,8,16. The pattern is always the same now. It always works fine the first 2 times I run it. But as soon as the third trial starts the presentation times start to lag. Also when I stop the script and restart it, the problem persists and presentation times directly lag in the first trial. Only a restart of the program solves the problem then.


    I just ran more thorough tests. The longer I keep on running the experiment with the lag, the slower the whole computer appears to become. After about 18-20 trials with 8 pictures, the program hardly reacts, and even if I press esc and close the program the computer works only slow. A new start of the program then quickly results in a Visual C++ Runtime Library error of opensesame.exe.

    Maybe memory overload? The latter problem btw, needs more trials to occur when I only work with 1 or 2 pictures in each trial.

  • edited 4:06AM

    Hi Michel,

    Right, I see. Indeed, there is a clear and consistent slowdown.

    The ITIs for the first trials are exactly 116.66ms, which is what you would expect given a 100ms sleep on a 60Hz monitor (where each cycle is 16.66Hz). If you want to get an ITI of 100ms, you should use a slightly shorter sleep, say 90ms. For a short discussion about this (which might not be intuitively obvious), see this post: http://www.cogsci.nl/forum/index.php?p=/discussion/comment/1054#Comment_1054

    But that's not the main issue, of course. I suspect that the memory of the graphics card fills up. Once memory is full, PsychoPy can no longer pre-load the images and a pre-load delay is added to the presentation time (I think). This could be a bug in PsychoPy/ PyOpenGL (which have been updated since the 0.26 package), it might be an issue in your experiment, or perhaps a combination of both. There haven't been any significant changes in the psycho back-end itself, since 0.26.

    You could do a number of things:

    • First check if there is something in your code that could explain why memory fills up. The most obvious candidate is the use of the global keyword, especially in combination with a canvas.
    • Switch to another back-end, if this is possible (you might rely PsychoPy-specific functions, of course).
    • Rewrite the presentation code, so that you take the time required by c.show() into account:

    [pastebin:T9JVwGCL]

    I'm not sure how keen you are to get to the bottom of this, but you could see what happens if you downgrade PsychoPy to the version that came with OpenSesame 0.26 (you can check by running modules() in the debug window). To downgrade, you can simply replace the psychopy sub-folder of OpenSesame with the folder from the PsychoPy source: http://code.google.com/p/psychopy/downloads/list

    If this resolves the issue, then we could consider reporting it to the PsychoPy developers. If it doesn't than the problem is elsewhere.

    Cheers!

  • edited December 2012

    Hey sebastiaan,

    some interesting news: First, the backend indeed solves the problem. No problems with e.g. legacy. The other interesting news is that with my code even when reduced to this bit:


    l = []
    for i in range(17):
    t = exp.canvas_pictures[i].show()
    l.append(t)
    exp.sleep(100)
    for t in l:
    print t


    ... in the run phase, the problem occurs. However when I simply copy pasted yours, the problem does not occur that much. However, there are still changes in the time. Sometimes it jumps between pictures from 100ms to 200ms (or something in between), but these jumps rarely occur! As you can see in my first post I also used a comparable loop structure like you did in my first attempt as compared to the MATLAB-like i-iteration structure I used in my last attempt. So that's probably not it (would have surprised me anyways. So it basically boils down to fluctuations in the .show time "lag".

    Also: Sure, I want to get to the bottom of this problem. So your suggestion is now to downgrade the psychopy engine and rerun the stuff in order to check whether they made some changes that caused this problem?

    Cheers, and thanks for the help Sebastiaan!


    Edit: example first three trials ( I marked the jumps) :

    first trial:
    9099.72412695 --> small jump
    9182.8746391
    9282.9186391
    9382.94783276 --> small jump
    9499.73027298
    9599.71923806
    9699.71770155
    9799.71923806
    9899.71546663
    9999.72259044
    10099.7135111
    10199.7116952
    10299.7140698
    10399.7122539
    10499.7143492
    10599.7108571
    10699.712673
    second trial:
    13516.3600402
    13616.3562687
    13716.3625545
    13816.3540338
    13916.3561291
    14016.3559894
    14116.3550116
    14216.3638116
    14316.3508211
    14416.3498433
    14516.3485862
    14616.3481672
    14716.3524973
    14816.3531957
    14916.3485862
    15016.3492846
    15216.3585037 --> bigger jump
    third trial:
    18716.3298687
    18816.1730052
    18916.2346052
    19016.2079259
    19116.2234306
    19216.241729
    19316.2583513
    19416.226364
    19516.2438243
    19616.2428465
    19716.2192402
    19816.2403322
    19916.2304148
    20016.2389354
    20116.2225925
    20216.259329
    20316.212256
  • edited 4:06AM
    However when I simply copy pasted yours, the problem does not occur that much. However, there are still changes in the time. Sometimes it jumps between pictures from 100ms to 200ms (or something in between), but these jumps rarely occur!

    Good! The script basically throttles the presentation, so that it doesn't go too fast. But when canvas.show() by itself takes longer than the intended delay, there will still be timing glitches, of course. I would definitely double check on the PC that you intend to use for actual testing to see how it goes there. If it's a very fast PC the timing might be perfect, if it's a very slow PC you might see substantial glitches.

    So your suggestion is now to downgrade the psychopy engine and rerun the stuff in order to check whether they made some changes that caused this problem?

    Yes, exactly. It's very puzzling that this problem didn't occur before (the results from 0.26 and 0.27 are from the same computer, right?), so there must be a regression somewhere.

  • edited December 2012

    Allright,

    I'll check it as soon as I got time.
    For the moment, your solution with subtracting the time needed for the show function, seems a decent temporary solution, right?
    Thanks for the support!

Sign In or Register to comment.