Missing events in the mwk2 file

Support
1

Hi Chris,

I am currently missing a lot of events in my mwk2 files. During the session, the behavioural window shows at least 1700 trials, but when i extract the data i only see around 500 events. The file size is also a lot smaller than before; running this experiment before would yield around 1.8GB of data for the duration of the session (2 hours with eye tracking info).
Any idea to what can cause this and how to test it?

Cheers,
Beshoy

2

Hi Beshoy,

Some questions:

  1. Are you extracting data using Python or MATLAB?
  2. When you say you “see around 500 events”, do you mean the whole file contains only 500 events, or there are only 500 events for a particular variable?
  3. You said around 1.8GB of data is typical. What is the size of the MWK2 file?

Thanks,
Chris

3

Hi Chris,

Let me start from the last question. The file I get now is around 500MB. It’s not the overall events nor necessarily for one events. What I meant is that if I have 1000 trials, i only find the data for 500 of that. Sorry for the confusion. Finally, I am using Matlab.

Cheers,
Beshoy

4

Hi Beshoy,

Thanks for the additional info.

What exactly are you counting to arrive at 500 trials? Are you looking at assignments to a particular variable?

Is it possible that some part of your analysis script assumes that getEvents returns events ordered by time (which isn’t true for MWK2 files)?

Chris

5

Hi Chris,
For example, I have a variable that’s assigned at the beginning and end of each trial (start and exit states) to make data extraction easier. That gives the smaller number. Aside from this, when I check the success, failure variables that are used in the behavioural window, I also find the total number to be a fraction from the trials during the experiment.

Cheers,
Beshoy

6

Hi Beshoy,

Would it be possible for you to share the MWK2 file with me (via Dropbox, maybe?) If so, can you also tell me the name of the variable you assign at the beginning and end of each trial?

Thanks,
Chris

7

Hi Chris,

Sorry for the late reply; I didn’t have access to the files. I checked the time stamps of one variable (the stim updates for example) and I found that the elapsed time between the first and last event is roughly 30 minutes or so. From the experiment file I attached, you can see that the streaming started around 14:40 and the stopped at 16:30 (file last modified).
Below is the link for the file (let me know if it doesn’t work). The variable is “afcc_onset_trial”; it’s assigned to 0 after fixation of the animal and to 1 at the exit state. There are trials with fixation break which aren’t counted in the behavioural window during the experiment and that I can exclude from my data after extraction by looking at the variable “fix_break”.
https://newcastle-my.sharepoint.com/:u:/g/personal/nba41_newcastle_ac_uk/EYcFBTcxXy5CkIt5bxKLmKABNXqa6CFxrrk6UY12fivbKw?e=Oqr1zf

Cheers,
Beshoy

8

Hi Beshoy,

Thanks for sharing the file. I’m looking at it now.

Chris

9

Hi Chris,

Thanks for this. I have updated mworks to the latest nightly version and had another session today. I split the data into two files each for about an hour long. I again looked at the stim updates time stamps and found the same issue. One file ran for an hour and only found timestamps for 22 minutes and the other ran for an hour and a half and found timestamps for 26 minutes.

Cheers,
Beshoy

10

Hi Beshoy,

Looking at the data file you shared, I see a gap of about 72 minutes between the RESERVED_TERMINATION_CODE event (the final event written to the file before it’s closed) and the preceding event. This suggests that the MWorks thread responsible for writing events to the data file stopped receiving new events at some point, but did not otherwise fail (since it was still able to write the termination event). I’m trying to understand how this could be the case.

A few more questions:

  • Are you seeing any error messages in the MWorks console while your experiments are running? (There were none in the data file.)
  • Are you using any custom core plugins (e.g. for I/O devices or stimuli)? If yes, have you re-compiled them against the version of MWorks you’re running (always required when you upgrade MWorks)?

Thanks,
Chris

11

Hi Chris,

Thanks for the reply. I do get a warning and it’s related to the eyelink plugin if I understand correctly; here it is:
WARNING: Scheduled task (/Users/cstawarz/Documents/mworks_buildbot/worker/build_for_macos/build/plugins/core/EyeLink1000/Eyelink.cpp:342: eye_tracker) falling behind, dropping 28 scheduled executions (priority = 2, interval = 1000, task = 0x600ed3ebcda0)

The IO devices that I am using are the ones for Eyelink adn NIDAQ; how can I recomplie them?

Cheers,
Beshoy

12

Hi Beshoy,

I don’t think the EyeLink warning is relevant.

By “custom plugins”, I meant plugins that aren’t included in the nightly build, which you built and/or installed yourself. I presume you’re just using the EyeLink and NIDAQ plugins that came with the nightly build, correct? If so, then those are always up to date.

I asked about custom plugins, because using a plugin compiled for an old MWorks build with a newer MWorks build can lead to memory corruption. The symptoms of that are usually quite obvious (e.g. the server crashes, or the plugin fails to load), but I wanted to check.

Chris

13

Hi Chris,

Aha, I get it now. Yes, i used the one provided; we had one custom plugin for a DAQ in the past but we moved away from this ages ago.

Cheers,
Beshoy

14

Hi Beshoy,

Some more questions:

  • Is your MWorks data file directory ($HOME/Documents/MWorks/Data) located on a local drive, i.e. internal or attached via USB or Thunderbolt? Or is it on a network-attached drive (presumably mapped in to your home directory via a symbolic link)?

  • The time stamps in your event file indicate that MWServer had been running for over 13 days. Is that correct? If so, that’s impressive :slight_smile:

  • In the MWorks data directory, are there any -journal files associated with the data files that are missing events (e.g. run1.mwk2-journal for run1.mwk2)? Normally, these should be present only when the data file is open and removed when it’s closed.

Thanks,
Chris

15

Also, on the machine running the MWServer instance that’s generating the incomplete data files, can you run the following command in Terminal and send me the output?

system_profiler SPSoftwareDataType SPHardwareDataType SPDisplaysDataType SPStorageDataType

Thanks,
Chris

16

Hi Chris,

It’s the directory that you described, we didn’t change the default one. Instead, we copy the files afterwards. As the computer is always running, we don’t really have a reason for disconnecting the server. I will try closing the connection and seeing what happens; maybe some funny business is causing this issue :slight_smile: .

I saw the journal file you describe and indeed it disappears once the connection is closed. I have also attached the output of the terminal command.

Cheers,
Beshoy

17

Attachment: Terminal_Saved_Output.txt (2.76 KB)

18

Hi Beshoy,

As the computer is always running, we don’t really have a reason for disconnecting the server. I will try closing the connection and seeing what happens; maybe some funny business is causing this issue :slight_smile: .

I mostly asked as a sanity check. Also, while there’s no reason that you shouldn’t be able to run MWServer for that long, I’d never seen it done before, hence my interest.

In any case, I don’t think this issue could be related to the length of time MWServer has been running, because you just reproduced it with the latest night build. One question: Did you observe the data loss on the first run after launching MWServer? Or did it only begin after several runs?

I have also attached the output of the terminal command.

Thanks for that. The only thing that catches my eye there is that your iMac is running macOS 10.14 (aka 10.14.0) rather than 10.14.4. Apple’s scant release notes don’t note any bug fixes that seem relevant to this problem. However, just to cover all the bases, could you try upgrading to 10.14.4?

Also, have you observed the data loss problem on any other machines?

On my end, I tried running a long data collection on my Mac Pro, using a slightly-modified version of the RSVPDemo experiment that ships with MWorks. I ran for over an hour, ultimately generating over 800MB of data. During the run, the MWK2 file steadily grew in size, and later analysis didn’t reveal any missing events. This is only one data point, of course, but it at least establishes that things work as intended some of the time.

As a next step, I’m going to prepare a special build of MWorks that does detailed logging of what’s happening in the data-file writing code. I’ll then run this on all of my test machines, and I’ll ask you to install and run it on your iMac. Hopefully this will provide some insight in to the issue.

Thanks,
Chris

19

Hi Beshoy,

As a next step, I’m going to prepare a special build of MWorks that does detailed logging of what’s happening in the data-file writing code.

This is done. You can grab the installer at

This build is identical to the current nightly, except that it logs details of the event-file writing process to the file /tmp/mwserver_event_file_log.txt .

Can you please install this build on the machine that’s had data loss and try running your experiment with it? If you observe the data loss again, please send me the log file mentioned above.

On my end, I’m about an hour into running this build on my three test Mac’s, and I haven’t seen any problems so far.

Thanks,
Chris

20

On my end, I’m about an hour into running this build on my three test Mac’s, and I haven’t seen any problems so far.

I just stopped this test. After running for over four hours, all three Mac’s had generated MWK2 files over 2GB in size. Right up to the point when I stopped the experiment, the event files were steadily growing. The logs indicated no problems whatsoever – just a steady stream of events successfully written.

Chris