time in eyetribe not synchronized with libtime

[dimitri-ognibene]

Hi,
in an experiment we have a loop visualizing a video but the time between eyetribe log and the libtime is not aligned.

    tracker.log("before start  %d" % t0)
    scr.screen.append(mov)
    tracker.start_recording()
    libtime.pause(800)
    tracker.log("actual start  %d" % libtime.get_time())
    mov.play()

    timeout = libtime.get_time() + 2000

    while libtime.get_time() < timeout:#mov.status != -1: 
        disp.fill(screen=scr)
        disp.show()

    tracker.log("end of video  %d" % libtime.get_time())
    mov.stop()
    libtime.pause(400)
    t2 = libtime.get_time()
    stop_tracking(k, t2)

analysing the messages we get that the difference between the time in the tracker and the time inserted using libtime.getime is about 600ms over 2000ms.

See:

MSG | 2018-06-25 | 20:54:34.075 | 944516699 | message: actual start |   | 34936

MSG | 2018-06-25 | 20:54:35.458 | 944518082 | message: end of video |   | 36991

944518082-944516699=1383
36991-34936=2055

This is a huge difference.
It works perfectly in dummy mode.

Actually if I check the difference between the first and the last trial the difference is not so high (1% instead of 30%)

MSG | 2018-06-25 | 20:54:25.751 | 944508375 | message: |   | before | start |   | 26476 |  

MSG | 2018-06-25 | 20:56:34.146 | 944636770 | message: |   | stimulus | offline | at | 156249 |  

944636770-944508375=128395
156249-2647=129773

Any suggestion?

[dariakv]

Hi! I have the same issue. Anybody knows why this difference in time is happening?

[dimitri-ognibene]

Actually checking the difference between the two type of time stamps I found that they agree when logging is off while it get gradually off inside the logging phase.

e.g. in the previous code the interval between two calls of:
tracker.log("before start %d" % t0)
is the same in both eyetribe and libtime clocks.

MSG | 2018-06-26 | 15:17:21.315 | 1010683939 | message: |   | before | start |   | 26691 |  
MSG | 2018-06-26 | 15:17:29.939 | 1010692563 | message: | | before | start |   | 35322 |

1010692563-1010683939=8624
35322-26691=8631

Instead the difference between the two type of timestamps :
tracker.log("before start %d" % t0)
and
tracker.log("actual start %d" % libtime.get_time())
As well as that between:
tracker.log("before start %d" % t0)
and
tracker.log("end of video %d" % libtime.get_time())
change (but do not compensate each other.. they have actually a similar shape as the clocks were off by a factor.

Are eyetribe clock and libtime clock re-synchronized at the end of the logging?

[esdalmaijer]

Hi both,

Thanks for the issue report, and the thorough debugging! I have a few questions which should help narrow down the issue:

1. Are you using the current code from GitHub? I would like to stress that in this case, it is very important that you do.

2. Could you report the time stamps of the samples surrounding both messages?

3. What kind of system are you using? (OS, make, processor, and Python version would be very useful.)

4. What back-end are you using? PsychoPy or PyGame?

The reasons behind these questions: In its default setting, PyTribe uses Threads rather than Processes, meaning that the samples are streamed from the tracker in one Thread and logged in another. In the past, on some systems we've noticed issues where the buffer was written to file slower than samples were coming in, resulting in a delay in sample-to-buffer writing. Various improvements happened, and those issues were resolved.

However, your issue seems slightly different: Current logging timestamps are based on the Python clock, whereas samples are based on the EyeTribe clock (which, as far as I can tell, is actually the PC clock, so it seems the EyeTribe Server is time-stamping samples when they come in). Hence, the two timestamps that you are comparing should come from the same clock.

There are two reasons I can think of why your timestamps might be uncoupled: The first is that you're using an older version of the code (where the message logging timestamp was coupled to the most recent sample), and the second is that somehow time.time() (used by PyTribe) doesn't map onto time.clock (used in PyGaze's PyGame back-end on Windows but not other systems) or psychopy.core.getTime (used in PyGaze's PsychoPy back-end).

[esdalmaijer]

Hi @dimitri-ognibene, I see you've closed the issue. Does that mean you solved the issue? Would you mind sharing what did it?

[dimitri-ognibene]

sorry I don't know what happened. I did not intend/realized I closed the issue (actually I was on the bus without internet connection in the last hour).
Thanks

[dariakv]

Hi, thank you so much for your suggestions! We installed new libraries and now the error is minimal. But I have data from 28 participants collected with old libraries, where the time of python and eyetribe was desynchronized. Is there a way to save my data?

[dimitri-ognibene]

Thanks a lot!
For me also updating the code libraries solved the problem.

The weird thing is that with the same libraries another experiment (also involving videos but not audio)
In both I was using Mov videos..
Now that the new libraries are installed is a bit difficult to go back and find what was the actual issue

[esdalmaijer]

@dariakv Very good question, and the answer depends greatly on how you implemented your logging, and what version of PyGaze / PyTribe you used. Unfortunately, I wouldn't actually be able to tell you, given I know about neither. This is obviously not what you'd like to hear, but the main lessen here is to always double-check your data before you start testing participants. Sorry!

[Nimaa4u]

Hello Guys,

I am doing a research with Tobii pro glasses 2. I have problem with synchronization of data (eye movement and flight data). I have a stream of flight data and I can add timestamp based on time of my computer, I was thinking to do the same, but there is a problem. It is not clear whether Tobii uses my computers' time or not. Please let me know if anybody had this problem?

[esdalmaijer]

Hi @Nimaa4u,

In general, I would avoid trying to sync data based on timestamps, because independent clocks can drift in sometimes unpredictable ways. A better way is to write triggers into data files when particular events happen, so that you can align your data to said events.

PyGaze allows for this with the EyeTracker class' log methods (this writes a string to the gaze data file). If you can write similar events to your flight data, that would tremendously help you with syncing the two datasets.

Good luck!
Edwin