search

olivierfriard / BORIS

Behavioral Observation Research Interactive Software
http://www.boris.unito.it
GNU General Public License v3.0
170 stars 34 forks source link

Video Playback becomes Desynchronised #607

Open erolley-parnell opened 1 year ago

erolley-parnell commented 1 year ago

Indicate the version of BORIS Version 8.16 (2023-03-23)

Describe the bug When I am attempting to rewind the playback of multiple media files (that are the same length), the rewind only restarts the file in media file number 1, the others are not restarted and pressing play results in desynchronised video playback.

To Reproduce Steps to reproduce the behavior:

  1. Open an existing observation
  2. Press play and let a few frames play (1x speed)
  3. Press the rewind button
  4. Only video in Player number 1 has restarted

The behaviour is inconsistent and will occassionally restart all players. And the issue occurs regardless of the playback speed.

Expected behavior The desired behaviour is that the rewind and the jump forward or jump backwards move all video players by the same amount.

Desktop:

Boris.log file

14:07:38,516  core l.158 INFO BORIS started
14:07:38,516  core l.159 INFO BORIS version 8.16 release date: 2023-03-23
14:07:38,525  core l.160 INFO Operating system: Windows 10 10.0.19045
14:07:38,525  core l.161 INFO CPU: AMD64 Intel64 Family 6 Model 158 Stepping 13, GenuineIntel
14:07:38,525  core l.162 INFO Python 3.11.2 (64-bit)
14:07:38,525  core l.163 INFO Qt 5.15.2 - PyQt 5.15.9
14:07:38,657  core l.167 INFO Memory (RAM)  Total: 16111.33 Mb  Free: 7253.82 Mb
14:07:39,701  utilities l.1020 DEBUG test ffmpeg path output: b'ffmpeg version 5.1.2-full_build-www.gyan.dev Copyright (c) 2000-2022 the FFmpeg developers\r\nbuilt with gcc 12.1.0 (Rev2, Built by MSYS2 project)\r\nconfiguration: --enable-gpl --enable-version3 --enable-static --disable-w32threads --disable-autodetect --enable-fontconfig --enable-iconv --enable-gnutls --enable-libxml2 --enable-gmp --enable-bzlib --enable-lzma --enable-libsnappy --enable-zlib --enable-librist --enable-libsrt --enable-libssh --enable-libzmq --enable-avisynth --enable-libbluray --enable-libcaca --enable-sdl2 --enable-libaribb24 --enable-libdav1d --enable-libdavs2 --enable-libuavs3d --enable-libzvbi --enable-librav1e --enable-libsvtav1 --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs2 --enable-libxvid --enable-libaom --enable-libjxl --enable-libopenjpeg --enable-libvpx --enable-mediafoundation --enable-libass --enable-frei0r --enable-libfreetype --enable-libfribidi --enable-liblensfun --enable-libvidstab --enable-libvmaf --enable-libzimg --enable-amf --enable-cuda-llvm --enable-cuvid --enable-ffnvcodec --enable-nvdec --enable-nvenc --enable-d3d11va --enable-dxva2 --enable-libmfx --enable-libshaderc --enable-vulkan --enable-libplacebo --enable-opencl --enable-libcdio --enable-libgme --enable-libmodplug --enable-libopenmpt --enable-libopencore-amrwb --enable-libmp3lame --enable-libshine --enable-libtheora --enable-libtwolame --enable-libvo-amrwbenc --enable-libilbc --enable-libgsm --enable-libopencore-amrnb --enable-libopus --enable-libspeex --enable-libvorbis --enable-ladspa --enable-libbs2b --enable-libflite --enable-libmysofa --enable-librubberband --enable-libsoxr --enable-chromaprint\r\nlibavutil      57. 28.100 / 57. 28.100\r\nlibavcodec     59. 37.100 / 59. 37.100\r\nlibavformat    59. 27.100 / 59. 27.100\r\nlibavdevice    59.  7.100 / 59.  7.100\r\nlibavfilter     8. 44.100 /  8. 44.100\r\nlibswscale      6.  7.100 /  6.  7.100\r\nlibswresample   4.  7.100 /  4.  7.100\r\nlibpostproc    56.  6.100 / 56.  6.100\r\n'
14:07:39,701  utilities l.1021 DEBUG test ffmpeg path error: b''
14:07:40,71  menu_options l.52 DEBUG function: menu_options
14:07:40,72  menu_options l.203 DEBUG function: menu_options finished
14:07:40,73  config_file l.45 DEBUG read config file: C:\Users\eroll\.boris
14:07:40,79  config_file l.68 DEBUG restore geometry
14:07:40,83  config_file l.79 DEBUG saved state: b'\x00\x00\x00\xff\x00\x00\x00\x00\xfd\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\xfd\x00\x00\x00\xe2\xfc\x02\x00\x00\x00\x01\xfb\x00\x00\x00\x14\x00d\x00w\x00E\x00t\x00h\x00o\x00g\x00r\x00a\x00m\x01\x00\x00\x03y\x00\x00\x00\xe2\x00\x00\x00o\x00\xff\xff\xff\x00\x00\x00\x01\x00\x00\x04\xda\x00\x00\x00\xe2\xfc\x02\x00\x00\x00\x01\xfc\x00\x00\x03y\x00\x00\x00\xe2\x00\x00\x00o\x00\xff\xff\xff\xfc\x01\x00\x00\x00\x02\xfb\x00\x00\x00\x10\x00d\x00w\x00E\x00v\x00e\x00n\x00t\x00s\x01\x00\x00\x02\xa6\x00\x00\x02?\x00\x00\x00Y\x00\xff\xff\xff\xfb\x00\x00\x00\x14\x00d\x00w\x00S\x00u\x00b\x00j\x00e\x00c\x00t\x00s\x01\x00\x00\x04\xe9\x00\x00\x02\x97\x00\x00\x00Y\x00\xff\xff\xff\x00\x00\x00\x02\x00\x00\x07\x80\x00\x00\x03>\xfc\x01\x00\x00\x00\x03\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x001\x01\x00\x00\x00\x00\x00\x00\x02}\x00\x00\x00<\x00\xff\xff\xff\xfc\x00\x00\x02\x81\x00\x00\x02~\x00\x00\x00<\x00\xff\xff\xff\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x002\x01\x00\x00\x007\x00\x00\x01\xb9\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x003\x01\x00\x00\x01\xf4\x00\x00\x01\x81\x00\x00\x005\x00\xff\xff\xff\xfc\x00\x00\x05\x03\x00\x00\x02}\x00\x00\x00<\x00\xff\xff\xff\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x004\x01\x00\x00\x007\x00\x00\x01\xb8\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x005\x01\x00\x00\x01\xf3\x00\x00\x01\x82\x00\x00\x005\x00\xff\xff\xff\x00\x00\x01\xa1\x00\x00\x00\xe2\x00\x00\x00\x04\x00\x00\x00\x04\x00\x00\x00\x08\x00\x00\x00\x08\xfc\x00\x00\x00\x01\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x0e\x00t\x00o\x00o\x00l\x00B\x00a\x00r\x01\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\x00\x00\x00\x00'
14:07:40,83  config_file l.87 DEBUG time format: hh:mm:ss
14:07:40,83  config_file l.95 DEBUG Time/fast_forward_speed: 10
14:07:40,83  config_file l.103 DEBUG Time/Repositioning_time_offset: 0
14:07:40,83  config_file l.111 DEBUG Time/play_rate_step: 0.1
14:07:40,83  config_file l.125 DEBUG Autosave: 3
14:07:40,84  config_file l.135 DEBUG behavioural_strings_separator: |
14:07:40,84  config_file l.143 DEBUG close_the_same_current_event: False
14:07:40,84  config_file l.151 DEBUG confirm_sound: False
14:07:40,84  config_file l.158 DEBUG alert_nosubject: True
14:07:40,84  config_file l.164 DEBUG beep_every: 0
14:07:40,84  config_file l.171 DEBUG tracking_cursor_above_event: False
14:07:40,84  config_file l.193 DEBUG check_for_new_version: True
14:07:40,84  config_file l.202 DEBUG pause_before_addevent: False
14:07:40,84  config_file l.210 DEBUG last_check_for_new_version: None
14:07:40,84  config_file l.219 DEBUG ffmpeg_cache_dir: 
14:07:40,84  config_file l.300 INFO read recent projects
14:07:40,85  core l.4870 DEBUG args: []
14:08:58,541  project_functions l.1210 DEBUG open project: C:\Users\eroll\[***]\BORIS\Stage 1 Video Annotation.boris
14:08:58,542  core l.2570 DEBUG initialize new project...
14:08:58,547  menu_options l.52 DEBUG function: menu_options
14:08:58,547  menu_options l.203 DEBUG function: menu_options finished
14:09:06,22  core l.2102 DEBUG function: display statusbar info: 230215-1542
14:09:06,22  observation_operations l.1057 DEBUG media_info: {'length': {'Temp Video Folder\\230215-1542\\vid_cam0_sess0.avi': 11.498708, 'Temp Video Folder\\230215-1542\\vid_cam1_sess0.avi': 11.498708, 'Temp Video Folder\\230215-1542\\vid_cam2_sess0.avi': 11.498708, 'Temp Video Folder\\230215-1542\\vid_cam3_sess0.avi': 11.498708, 'Temp Video Folder\\230215-1542\\vid_cam4_sess0.avi': 11.498708}, 'fps': {'Temp Video Folder\\230215-1542\\vid_cam0_sess0.avi': 178.02, 'Temp Video Folder\\230215-1542\\vid_cam1_sess0.avi': 178.02, 'Temp Video Folder\\230215-1542\\vid_cam2_sess0.avi': 178.02, 'Temp Video Folder\\230215-1542\\vid_cam3_sess0.avi': 178.02, 'Temp Video Folder\\230215-1542\\vid_cam4_sess0.avi': 178.02}, 'hasVideo': {'Temp Video Folder\\230215-1542\\vid_cam0_sess0.avi': True, 'Temp Video Folder\\230215-1542\\vid_cam1_sess0.avi': True, 'Temp Video Folder\\230215-1542\\vid_cam2_sess0.avi': True, 'Temp Video Folder\\230215-1542\\vid_cam3_sess0.avi': True, 'Temp Video Folder\\230215-1542\\vid_cam4_sess0.avi': True}, 'hasAudio': {'Temp Video Folder\\230215-1542\\vid_cam0_sess0.avi': False, 'Temp Video Folder\\230215-1542\\vid_cam1_sess0.avi': False, 'Temp Video Folder\\230215-1542\\vid_cam2_sess0.avi': False, 'Temp Video Folder\\230215-1542\\vid_cam3_sess0.avi': False, 'Temp Video Folder\\230215-1542\\vid_cam4_sess0.avi': False}, 'offset': {}}
14:09:06,22  observation_operations l.1255 DEBUG function: initialize new observation for media file(s)
14:09:06,104  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam1_sess0.avi
14:09:06,104  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam1_sess0.avi
14:09:06,181  observation_operations l.1419 DEBUG Running on Windows VM: False
14:09:06,381  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1856x102+0+0 (frame: 1856x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1856x102+0+100 (frame: 1856x102+0+100) margins: 0, 0, 0, 0)
14:09:06,477  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam2_sess0.avi
14:09:06,477  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam2_sess0.avi
14:09:06,537  observation_operations l.1419 DEBUG Running on Windows VM: False
14:09:06,603  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1792x102+0+0 (frame: 1792x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1792x102+0+100 (frame: 1792x102+0+100) margins: 0, 0, 0, 0)
14:09:06,689  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam0_sess0.avi
14:09:06,689  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam0_sess0.avi
14:09:06,748  observation_operations l.1419 DEBUG Running on Windows VM: False
14:09:06,820  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1728x102+0+0 (frame: 1728x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1728x102+0+100 (frame: 1728x102+0+100) margins: 0, 0, 0, 0)
14:09:06,888  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam3_sess0.avi
14:09:06,888  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam3_sess0.avi
14:09:06,948  observation_operations l.1419 DEBUG Running on Windows VM: False
14:09:07,31  core l.1372 DEBUG paused? False
14:09:07,151  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam4_sess0.avi
14:09:07,151  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam4_sess0.avi
14:09:07,210  observation_operations l.1419 DEBUG Running on Windows VM: False
14:09:07,289  core l.1372 DEBUG paused? False
14:09:07,300  menu_options l.52 DEBUG function: menu_options
14:09:07,308  menu_options l.203 DEBUG function: menu_options finished
14:09:07,309  core l.2102 DEBUG function: display statusbar info: 230215-1542
14:09:07,309  video_operations l.200 DEBUG play rate: 1.000
QWindowsWindow::setGeometry: Unable to set geometry 637x808+0+0 (frame: 637x808+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 637x808+0+100 (frame: 637x808+0+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 638x419+0+0 (frame: 638x419+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 638x419+641+100 (frame: 638x419+641+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 638x363+0+0 (frame: 638x363+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 638x363+641+545 (frame: 638x363+641+545) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 637x418+0+0 (frame: 637x418+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 637x418+1283+100 (frame: 637x418+1283+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 637x364+0+0 (frame: 637x364+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 637x364+1283+544 (frame: 637x364+1283+544) margins: 0, 0, 0, 0)
14:09:07,367  core l.1372 DEBUG paused? False
14:09:07,368  core l.1372 DEBUG paused? False
14:09:07,368  core l.1372 DEBUG paused? False
14:09:07,368  core l.1372 DEBUG paused? False
14:09:07,377  core l.1908 DEBUG begin load events from obs: 230215-1542
14:09:07,386  core l.1967 DEBUG end load events from obs
14:09:07,387  menu_options l.52 DEBUG function: menu_options
14:09:07,387  menu_options l.203 DEBUG function: menu_options finished
14:10:00,248  core l.4796 DEBUG Reset activated
14:10:00,249  core l.1372 DEBUG paused? False
14:10:00,265  core l.1372 DEBUG paused? False
14:10:00,265  core l.1372 DEBUG paused? False
14:10:00,266  core l.1372 DEBUG paused? False
14:10:00,266  core l.1372 DEBUG paused? False
14:10:05,580  video_operations l.200 DEBUG play rate: 0.900
14:10:05,984  video_operations l.200 DEBUG play rate: 0.800
14:10:06,390  video_operations l.200 DEBUG play rate: 0.700
14:10:07,365  core l.4796 DEBUG Reset activated
14:10:07,366  core l.1372 DEBUG paused? False
14:10:07,380  core l.1372 DEBUG paused? False
14:10:07,380  core l.1372 DEBUG paused? False
14:10:07,381  core l.1372 DEBUG paused? False
14:10:07,381  core l.1372 DEBUG paused? False
14:10:12,788  core l.4796 DEBUG Reset activated
14:10:12,788  core l.1372 DEBUG paused? False
14:10:40,84  core l.1554 INFO autosave project
14:10:40,84  core l.2970 DEBUG function: save project activated
14:10:40,84  core l.2971 DEBUG Project file name: C:\Users\eroll\[***]\BORIS\Stage 1 Video Annotation.boris
14:10:40,84  core l.2851 DEBUG init save_project_json function C:\Users\eroll\[***]\BORIS\Stage 1 Video Annotation.boris
14:10:40,86  core l.2887 DEBUG end save_project_json function
olivierfriard commented 1 year ago

Hi, can you send me info on your video file? You can use Tool > Media file > Media file info

erolley-parnell commented 1 year ago 
MPV information
Video format: ffv1
Number of media in media list: 1
Current time position: 0.0
duration: 11.498708
FPS: 178.02000427246094
Video size: 720x540
Aspect ratio: 1.333

ffprobe analysis
File path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam1_sess0.avi

Duration: 11.498708 seconds (00:00:11.499)
Resolution: 720x540
Number of frames: 2047
Bitrate: 139.7 Mb 
FPS: 178.02
Has video: True
Has audio: False
File size: 200.8 Mb
Video codec: FFmpeg video codec #1
Audio codec: None

Total duration: 11.498 (00:00:11.498)

MPV information
Video format: ffv1
Number of media in media list: 1
Current time position: 0.0
duration: 11.498708
FPS: 178.02000427246094
Video size: 720x540
Aspect ratio: 1.333

ffprobe analysis
File path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam2_sess0.avi

Duration: 11.498708 seconds (00:00:11.499)
Resolution: 720x540
Number of frames: 2047
Bitrate: 150.6 Mb 
FPS: 178.02
Has video: True
Has audio: False
File size: 216.4 Mb
Video codec: FFmpeg video codec #1
Audio codec: None

Total duration: 11.498 (00:00:11.498)

MPV information
Video format: ffv1
Number of media in media list: 1
Current time position: 0.0
duration: 11.498708
FPS: 178.02000427246094
Video size: 720x540
Aspect ratio: 1.333

ffprobe analysis
File path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam0_sess0.avi

Duration: 11.498708 seconds (00:00:11.499)
Resolution: 720x540
Number of frames: 2047
Bitrate: 215.2 Mb 
FPS: 178.02
Has video: True
Has audio: False
File size: 309.2 Mb
Video codec: FFmpeg video codec #1
Audio codec: None

Total duration: 11.498 (00:00:11.498)

MPV information
Video format: ffv1
Number of media in media list: 1
Current time position: 0.0
duration: 11.498708
FPS: 178.02000427246094
Video size: 720x540
Aspect ratio: 1.333

ffprobe analysis
File path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam3_sess0.avi

Duration: 11.498708 seconds (00:00:11.499)
Resolution: 720x540
Number of frames: 2047
Bitrate: 172.8 Mb 
FPS: 178.02
Has video: True
Has audio: False
File size: 248.3 Mb
Video codec: FFmpeg video codec #1
Audio codec: None

Total duration: 11.498 (00:00:11.498)

MPV information
Video format: ffv1
Number of media in media list: 1
Current time position: 0.0
duration: 11.498708
FPS: 178.02000427246094
Video size: 720x540
Aspect ratio: 1.333

ffprobe analysis
File path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam4_sess0.avi

Duration: 11.498708 seconds (00:00:11.499)
Resolution: 720x540
Number of frames: 2047
Bitrate: 174.7 Mb 
FPS: 178.02
Has video: True
Has audio: False
File size: 251.1 Mb
Video codec: FFmpeg video codec #1
Audio codec: None

Total duration: 11.498 (00:00:11.498)
olivierfriard commented 1 year ago

Is it possible to obtain a sample of these videos in order to reproduce the issue?

erolley-parnell commented 1 year ago

I've just sent the videos via WeTransfer to your unito email address.

erolley-parnell commented 1 year ago

So as per your email I changed to a lower bitrate for the videos, and the problem persists. I used the re-encoding provided by BORIS and reduced the bitrate by a huge margin (to the point where the videos are not actually usable, but for testing purposes). Here is the log file:

11:56:42,151  core l.158 INFO BORIS started
11:56:42,152  core l.159 INFO BORIS version 8.16 release date: 2023-03-23
11:56:42,174  core l.160 INFO Operating system: Windows 10 10.0.19045
11:56:42,174  core l.161 INFO CPU: AMD64 Intel64 Family 6 Model 158 Stepping 13, GenuineIntel
11:56:42,175  core l.162 INFO Python 3.11.2 (64-bit)
11:56:42,175  core l.163 INFO Qt 5.15.2 - PyQt 5.15.9
11:56:42,444  core l.167 INFO Memory (RAM)  Total: 16111.33 Mb  Free: 6931.11 Mb
11:56:43,598  utilities l.1020 DEBUG test ffmpeg path output: b'ffmpeg version 5.1.2-full_build-www.gyan.dev Copyright (c) 2000-2022 the FFmpeg developers\r\nbuilt with gcc 12.1.0 (Rev2, Built by MSYS2 project)\r\nconfiguration: --enable-gpl --enable-version3 --enable-static --disable-w32threads --disable-autodetect --enable-fontconfig --enable-iconv --enable-gnutls --enable-libxml2 --enable-gmp --enable-bzlib --enable-lzma --enable-libsnappy --enable-zlib --enable-librist --enable-libsrt --enable-libssh --enable-libzmq --enable-avisynth --enable-libbluray --enable-libcaca --enable-sdl2 --enable-libaribb24 --enable-libdav1d --enable-libdavs2 --enable-libuavs3d --enable-libzvbi --enable-librav1e --enable-libsvtav1 --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs2 --enable-libxvid --enable-libaom --enable-libjxl --enable-libopenjpeg --enable-libvpx --enable-mediafoundation --enable-libass --enable-frei0r --enable-libfreetype --enable-libfribidi --enable-liblensfun --enable-libvidstab --enable-libvmaf --enable-libzimg --enable-amf --enable-cuda-llvm --enable-cuvid --enable-ffnvcodec --enable-nvdec --enable-nvenc --enable-d3d11va --enable-dxva2 --enable-libmfx --enable-libshaderc --enable-vulkan --enable-libplacebo --enable-opencl --enable-libcdio --enable-libgme --enable-libmodplug --enable-libopenmpt --enable-libopencore-amrwb --enable-libmp3lame --enable-libshine --enable-libtheora --enable-libtwolame --enable-libvo-amrwbenc --enable-libilbc --enable-libgsm --enable-libopencore-amrnb --enable-libopus --enable-libspeex --enable-libvorbis --enable-ladspa --enable-libbs2b --enable-libflite --enable-libmysofa --enable-librubberband --enable-libsoxr --enable-chromaprint\r\nlibavutil      57. 28.100 / 57. 28.100\r\nlibavcodec     59. 37.100 / 59. 37.100\r\nlibavformat    59. 27.100 / 59. 27.100\r\nlibavdevice    59.  7.100 / 59.  7.100\r\nlibavfilter     8. 44.100 /  8. 44.100\r\nlibswscale      6.  7.100 /  6.  7.100\r\nlibswresample   4.  7.100 /  4.  7.100\r\nlibpostproc    56.  6.100 / 56.  6.100\r\n'
11:56:43,598  utilities l.1021 DEBUG test ffmpeg path error: b''
11:56:45,117  menu_options l.52 DEBUG function: menu_options
11:56:45,117  menu_options l.203 DEBUG function: menu_options finished
11:56:45,120  config_file l.45 DEBUG read config file: C:\Users\eroll\.boris
11:56:45,129  config_file l.68 DEBUG restore geometry
11:56:45,139  config_file l.79 DEBUG saved state: b'\x00\x00\x00\xff\x00\x00\x00\x00\xfd\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\xfd\x00\x00\x01/\xfc\x02\x00\x00\x00\x01\xfb\x00\x00\x00\x14\x00d\x00w\x00E\x00t\x00h\x00o\x00g\x00r\x00a\x00m\x01\x00\x00\x03,\x00\x00\x01/\x00\x00\x00o\x00\xff\xff\xff\x00\x00\x00\x01\x00\x00\x04\xda\x00\x00\x01/\xfc\x02\x00\x00\x00\x01\xfc\x00\x00\x03,\x00\x00\x01/\x00\x00\x00o\x00\xff\xff\xff\xfc\x01\x00\x00\x00\x02\xfb\x00\x00\x00\x10\x00d\x00w\x00E\x00v\x00e\x00n\x00t\x00s\x01\x00\x00\x02\xa6\x00\x00\x02?\x00\x00\x00Y\x00\xff\xff\xff\xfb\x00\x00\x00\x14\x00d\x00w\x00S\x00u\x00b\x00j\x00e\x00c\x00t\x00s\x01\x00\x00\x04\xe9\x00\x00\x02\x97\x00\x00\x00Y\x00\xff\xff\xff\x00\x00\x00\x02\x00\x00\x07\x80\x00\x00\x02\xf1\xfc\x01\x00\x00\x00\x03\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x001\x01\x00\x00\x00\x00\x00\x00\x04}\x00\x00\x00<\x00\xff\xff\xff\xfc\x00\x00\x04\x81\x00\x00\x01~\x00\x00\x00<\x00\xff\xff\xff\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x002\x01\x00\x00\x007\x00\x00\x01\x8f\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x003\x01\x00\x00\x01\xca\x00\x00\x01^\x00\x00\x005\x00\xff\xff\xff\xfc\x00\x00\x06\x03\x00\x00\x01}\x00\x00\x00<\x00\xff\xff\xff\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x004\x01\x00\x00\x007\x00\x00\x01\x8e\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x005\x01\x00\x00\x01\xc9\x00\x00\x01_\x00\x00\x005\x00\xff\xff\xff\x00\x00\x01\xa1\x00\x00\x01/\x00\x00\x00\x04\x00\x00\x00\x04\x00\x00\x00\x08\x00\x00\x00\x08\xfc\x00\x00\x00\x01\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x0e\x00t\x00o\x00o\x00l\x00B\x00a\x00r\x01\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\x00\x00\x00\x00'
11:56:45,139  config_file l.87 DEBUG time format: hh:mm:ss
11:56:45,139  config_file l.95 DEBUG Time/fast_forward_speed: 10
11:56:45,139  config_file l.103 DEBUG Time/Repositioning_time_offset: 0
11:56:45,139  config_file l.111 DEBUG Time/play_rate_step: 0.1
11:56:45,140  config_file l.125 DEBUG Autosave: 3
11:56:45,140  config_file l.135 DEBUG behavioural_strings_separator: |
11:56:45,140  config_file l.143 DEBUG close_the_same_current_event: False
11:56:45,140  config_file l.151 DEBUG confirm_sound: False
11:56:45,140  config_file l.158 DEBUG alert_nosubject: True
11:56:45,140  config_file l.164 DEBUG beep_every: 0
11:56:45,140  config_file l.171 DEBUG tracking_cursor_above_event: False
11:56:45,140  config_file l.193 DEBUG check_for_new_version: True
11:56:45,140  config_file l.202 DEBUG pause_before_addevent: False
11:56:45,141  config_file l.210 DEBUG last_check_for_new_version: None
11:56:45,141  config_file l.219 DEBUG ffmpeg_cache_dir: 
11:56:45,141  config_file l.300 INFO read recent projects
11:56:45,143  core l.4870 DEBUG args: []
11:56:52,393  project_functions l.1210 DEBUG open project: C:\Users\eroll\[***]\BORIS\Stage 1 Video Annotation.boris
11:56:52,395  core l.2570 DEBUG initialize new project...
11:56:52,404  menu_options l.52 DEBUG function: menu_options
11:56:52,405  menu_options l.203 DEBUG function: menu_options finished
11:56:56,742  observation_operations l.162 DEBUG open observation
11:56:59,100  observation_operations l.198 DEBUG load observation
11:56:59,101  observation_operations l.1255 DEBUG function: initialize new observation for media file(s)
11:56:59,306  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam1_sess0.avi.re-encoded.720px.100000k.avi
11:56:59,307  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam1_sess0.avi.re-encoded.720px.100000k.avi
11:56:59,443  observation_operations l.1419 DEBUG Running on Windows VM: False
11:56:59,812  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1856x102+0+0 (frame: 1856x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1856x102+0+100 (frame: 1856x102+0+100) margins: 0, 0, 0, 0)
11:56:59,939  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam2_sess0.avi.re-encoded.720px.100000k.avi
11:56:59,940  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam2_sess0.avi.re-encoded.720px.100000k.avi
11:57:00,49  observation_operations l.1419 DEBUG Running on Windows VM: False
11:57:00,155  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1792x102+0+0 (frame: 1792x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1792x102+0+100 (frame: 1792x102+0+100) margins: 0, 0, 0, 0)
11:57:00,400  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam0_sess0.avi.re-encoded.720px.100000k.avi
11:57:00,401  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam0_sess0.avi.re-encoded.720px.100000k.avi
11:57:00,505  observation_operations l.1419 DEBUG Running on Windows VM: False
11:57:00,598  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1728x102+0+0 (frame: 1728x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1728x102+0+100 (frame: 1728x102+0+100) margins: 0, 0, 0, 0)
11:57:00,741  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam3_sess0.avi.re-encoded.720px.100000k.avi
11:57:00,742  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam3_sess0.avi.re-encoded.720px.100000k.avi
11:57:00,852  observation_operations l.1419 DEBUG Running on Windows VM: False
11:57:00,952  core l.1372 DEBUG paused? False
11:57:01,81  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam4_sess0.avi.re-encoded.720px.100000k.avi
11:57:01,82  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam4_sess0.avi.re-encoded.720px.100000k.avi
11:57:01,204  observation_operations l.1419 DEBUG Running on Windows VM: False
11:57:01,307  core l.1372 DEBUG paused? False
11:57:01,312  menu_options l.52 DEBUG function: menu_options
11:57:01,315  menu_options l.203 DEBUG function: menu_options finished
11:57:01,316  core l.2102 DEBUG function: display statusbar info: 230215-1542
11:57:01,317  video_operations l.200 DEBUG play rate: 1.000
QWindowsWindow::setGeometry: Unable to set geometry 1149x731+0+0 (frame: 1149x731+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 1149x731+0+100 (frame: 1149x731+0+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 382x377+0+0 (frame: 382x377+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 382x377+1153+100 (frame: 382x377+1153+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 382x328+0+0 (frame: 382x328+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 382x328+1153+503 (frame: 382x328+1153+503) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 381x376+0+0 (frame: 381x376+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 381x376+1539+100 (frame: 381x376+1539+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 381x329+0+0 (frame: 381x329+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY3". Resulting geometry: 381x329+1539+502 (frame: 381x329+1539+502) margins: 0, 0, 0, 0)
11:57:01,449  core l.1372 DEBUG paused? False
11:57:01,449  core l.1372 DEBUG paused? False
11:57:01,449  core l.1372 DEBUG paused? False
11:57:01,450  core l.1372 DEBUG paused? False
11:57:01,474  core l.1908 DEBUG begin load events from obs: 230215-1542
11:57:01,485  core l.1967 DEBUG end load events from obs
11:57:01,485  menu_options l.52 DEBUG function: menu_options
11:57:01,485  menu_options l.203 DEBUG function: menu_options finished
11:57:01,485  observation_operations l.249 DEBUG end load observation
11:57:07,43  core l.4796 DEBUG Reset activated
11:57:07,45  core l.1372 DEBUG paused? False
11:57:07,78  core l.1372 DEBUG paused? False
11:57:07,79  core l.1372 DEBUG paused? False
11:57:07,80  core l.1372 DEBUG paused? False
11:57:07,82  core l.1372 DEBUG paused? False
11:57:09,102  core l.4796 DEBUG Reset activated
11:57:09,105  core l.1372 DEBUG paused? False
11:57:13,12  core l.4796 DEBUG Reset activated
11:57:13,14  core l.1372 DEBUG paused? False
11:57:13,18  core l.1372 DEBUG paused? False
11:57:13,18  core l.1372 DEBUG paused? False
11:57:13,19  core l.1372 DEBUG paused? False
11:57:13,20  core l.1372 DEBUG paused? False
11:57:15,899  core l.4796 DEBUG Reset activated
11:57:15,901  core l.1372 DEBUG paused? False
11:57:15,935  core l.1372 DEBUG paused? False
11:57:15,936  core l.1372 DEBUG paused? False
11:57:15,937  core l.1372 DEBUG paused? False
11:57:15,937  core l.1372 DEBUG paused? False
11:57:21,29  core l.4796 DEBUG Reset activated
11:57:21,30  core l.1372 DEBUG paused? False
olivierfriard commented 1 year ago

What is your computer model? CPU, RAM etc

During the observation with 5 players are you able to use the Pause button? Are you able to use the frame-by-frame mode?

erolley-parnell commented 1 year ago

Computer Model: Dell XPS 15 7590 Processor Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz, 2400 Mhz, 8 Core(s), 16 Logical Processor(s) 16 GB RAM, Intel UHD Graphics 630, and NVIDIA GeForce GTX 1650

I can play and pause fine, and move frame by frame just fine at different play rates. All videos play and pause as expected, and the frame by frame changes the videos in all players, as expected.

However I've just found something odd: Using jump forwards or jump backwards can desynchronise the video, and it varies based on play speed. Depending on the play speed, only the video in player 1 jumps forward or backwards. The issue only starts below x0.3 rate: play rate = x0.3 or x0.2, only the video in player number 1 jumps forward for the first "Jump", then all catch up on the second "Jump Forward" or "Jump Backward". play rate = x0.1, only the video in player number 1 moves for the first 3 clicks of "Jump Forward" or "Jump Backward", then on the fourth click, all videos resynchronise.

When clicking play on videos that are desynchronised, they continue to play at the same rate from their offset positions.

While I'm not sure if the two are related, I've included the log file of this odd behaviour.


11:39:57,99  core l.158 INFO BORIS started
11:39:57,100  core l.159 INFO BORIS version 8.16 release date: 2023-03-23
11:39:57,110  core l.160 INFO Operating system: Windows 10 10.0.19045
11:39:57,111  core l.161 INFO CPU: AMD64 Intel64 Family 6 Model 158 Stepping 13, GenuineIntel
11:39:57,111  core l.162 INFO Python 3.11.2 (64-bit)
11:39:57,111  core l.163 INFO Qt 5.15.2 - PyQt 5.15.9
11:39:57,221  core l.167 INFO Memory (RAM)  Total: 16111.33 Mb  Free: 7346.25 Mb
11:39:58,267  utilities l.1020 DEBUG test ffmpeg path output: b'ffmpeg version 5.1.2-full_build-www.gyan.dev Copyright (c) 2000-2022 the FFmpeg developers\r\nbuilt with gcc 12.1.0 (Rev2, Built by MSYS2 project)\r\nconfiguration: --enable-gpl --enable-version3 --enable-static --disable-w32threads --disable-autodetect --enable-fontconfig --enable-iconv --enable-gnutls --enable-libxml2 --enable-gmp --enable-bzlib --enable-lzma --enable-libsnappy --enable-zlib --enable-librist --enable-libsrt --enable-libssh --enable-libzmq --enable-avisynth --enable-libbluray --enable-libcaca --enable-sdl2 --enable-libaribb24 --enable-libdav1d --enable-libdavs2 --enable-libuavs3d --enable-libzvbi --enable-librav1e --enable-libsvtav1 --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs2 --enable-libxvid --enable-libaom --enable-libjxl --enable-libopenjpeg --enable-libvpx --enable-mediafoundation --enable-libass --enable-frei0r --enable-libfreetype --enable-libfribidi --enable-liblensfun --enable-libvidstab --enable-libvmaf --enable-libzimg --enable-amf --enable-cuda-llvm --enable-cuvid --enable-ffnvcodec --enable-nvdec --enable-nvenc --enable-d3d11va --enable-dxva2 --enable-libmfx --enable-libshaderc --enable-vulkan --enable-libplacebo --enable-opencl --enable-libcdio --enable-libgme --enable-libmodplug --enable-libopenmpt --enable-libopencore-amrwb --enable-libmp3lame --enable-libshine --enable-libtheora --enable-libtwolame --enable-libvo-amrwbenc --enable-libilbc --enable-libgsm --enable-libopencore-amrnb --enable-libopus --enable-libspeex --enable-libvorbis --enable-ladspa --enable-libbs2b --enable-libflite --enable-libmysofa --enable-librubberband --enable-libsoxr --enable-chromaprint\r\nlibavutil      57. 28.100 / 57. 28.100\r\nlibavcodec     59. 37.100 / 59. 37.100\r\nlibavformat    59. 27.100 / 59. 27.100\r\nlibavdevice    59.  7.100 / 59.  7.100\r\nlibavfilter     8. 44.100 /  8. 44.100\r\nlibswscale      6.  7.100 /  6.  7.100\r\nlibswresample   4.  7.100 /  4.  7.100\r\nlibpostproc    56.  6.100 / 56.  6.100\r\n'
11:39:58,267  utilities l.1021 DEBUG test ffmpeg path error: b''
11:39:58,623  menu_options l.52 DEBUG function: menu_options
11:39:58,623  menu_options l.203 DEBUG function: menu_options finished
11:39:58,625  config_file l.45 DEBUG read config file: C:\Users\eroll\.boris
11:39:58,626  config_file l.68 DEBUG restore geometry
11:39:58,632  config_file l.79 DEBUG saved state: b'\x00\x00\x00\xff\x00\x00\x00\x00\xfd\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x01\x12\x00\x00\x00\xe2\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x14\x00d\x00w\x00E\x00t\x00h\x00o\x00g\x00r\x00a\x00m\x01\x00\x00\x03y\x00\x00\x00o\x00\x00\x00o\x00\xff\xff\xff\xfb\x00\x00\x00\x14\x00d\x00w\x00S\x00u\x00b\x00j\x00e\x00c\x00t\x00s\x01\x00\x00\x03\xec\x00\x00\x00o\x00\x00\x00o\x00\xff\xff\xff\x00\x00\x00\x01\x00\x00\x01\x12\x00\x00\x00\xe2\xfc\x02\x00\x00\x00\x01\xfb\x00\x00\x00\x10\x00d\x00w\x00E\x00v\x00e\x00n\x00t\x00s\x01\x00\x00\x03y\x00\x00\x00\xe2\x00\x00\x00o\x00\xff\xff\xff\x00\x00\x00\x02\x00\x00\x07\x80\x00\x00\x03>\xfc\x01\x00\x00\x00\x04\xfc\x00\x00\x00\x00\x00\x00\x01\x85\x00\x00\x00<\x00\xff\xff\xff\xfc\x02\x00\x00\x00\x02\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x001\x01\x00\x00\x007\x00\x00\x01\xa0\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x002\x01\x00\x00\x01\xdb\x00\x00\x01\x9a\x00\x00\x005\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x005\x01\x00\x00\x01\x89\x00\x00\x02\x1c\x00\x00\x00<\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x003\x01\x00\x00\x03\xa9\x00\x00\x02`\x00\x00\x00<\x00\xff\xff\xff\xfb\x00\x00\x00\x0e\x00p\x00l\x00a\x00y\x00e\x00r\x004\x01\x00\x00\x06\r\x00\x00\x01s\x00\x00\x00<\x00\xff\xff\xff\x00\x00\x05T\x00\x00\x00\xe2\x00\x00\x00\x04\x00\x00\x00\x04\x00\x00\x00\x08\x00\x00\x00\x08\xfc\x00\x00\x00\x01\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x0e\x00t\x00o\x00o\x00l\x00B\x00a\x00r\x01\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\x00\x00\x00\x00'
11:39:58,632  config_file l.87 DEBUG time format: hh:mm:ss
11:39:58,632  config_file l.95 DEBUG Time/fast_forward_speed: 3
11:39:58,632  config_file l.103 DEBUG Time/Repositioning_time_offset: 0
11:39:58,632  config_file l.111 DEBUG Time/play_rate_step: 0.1
11:39:58,632  config_file l.125 DEBUG Autosave: 3
11:39:58,632  config_file l.135 DEBUG behavioural_strings_separator: |
11:39:58,632  config_file l.143 DEBUG close_the_same_current_event: False
11:39:58,632  config_file l.151 DEBUG confirm_sound: False
11:39:58,632  config_file l.158 DEBUG alert_nosubject: True
11:39:58,632  config_file l.164 DEBUG beep_every: 0
11:39:58,632  config_file l.171 DEBUG tracking_cursor_above_event: False
11:39:58,632  config_file l.193 DEBUG check_for_new_version: True
11:39:58,632  config_file l.202 DEBUG pause_before_addevent: False
11:39:58,633  config_file l.210 DEBUG last_check_for_new_version: None
11:39:58,633  config_file l.219 DEBUG ffmpeg_cache_dir: 
11:39:58,633  config_file l.300 INFO read recent projects
11:39:58,634  core l.4870 DEBUG args: []
11:40:06,363  project_functions l.1210 DEBUG open project: C:\Users\eroll\[***]\BORIS\Stage 1 Video Annotation.boris
11:40:06,364  core l.2570 DEBUG initialize new project...
11:40:06,368  menu_options l.52 DEBUG function: menu_options
11:40:06,368  menu_options l.203 DEBUG function: menu_options finished
11:40:08,117  observation_operations l.162 DEBUG open observation
11:40:10,638  observation_operations l.198 DEBUG load observation
11:40:10,638  observation_operations l.1255 DEBUG function: initialize new observation for media file(s)
11:40:10,715  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam1_sess0.avi.re-encoded.720px.100000000k.avi
11:40:10,715  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam1_sess0.avi.re-encoded.720px.100000000k.avi
11:40:10,787  observation_operations l.1419 DEBUG Running on Windows VM: False
11:40:10,973  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1856x102+0+0 (frame: 1856x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 1856x102+0+100 (frame: 1856x102+0+100) margins: 0, 0, 0, 0)
11:40:11,27  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam2_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,27  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam2_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,86  observation_operations l.1419 DEBUG Running on Windows VM: False
11:40:11,141  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1792x102+0+0 (frame: 1792x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 1792x102+0+100 (frame: 1792x102+0+100) margins: 0, 0, 0, 0)
11:40:11,192  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam0_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,192  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam0_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,250  observation_operations l.1419 DEBUG Running on Windows VM: False
11:40:11,305  core l.1372 DEBUG paused? False
QWindowsWindow::setGeometry: Unable to set geometry 1728x102+0+0 (frame: 1728x102+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 1728x102+0+100 (frame: 1728x102+0+100) margins: 0, 0, 0, 0)
11:40:11,361  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam3_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,362  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam3_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,423  observation_operations l.1419 DEBUG Running on Windows VM: False
11:40:11,480  core l.1372 DEBUG paused? False
11:40:11,536  observation_operations l.1358 DEBUG media file: Temp Video Folder\230215-1542\vid_cam4_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,537  observation_operations l.1362 DEBUG media_full_path: C:\Users\eroll\[***]\BORIS\Temp Video Folder\230215-1542\vid_cam4_sess0.avi.re-encoded.720px.100000000k.avi
11:40:11,594  observation_operations l.1419 DEBUG Running on Windows VM: False
11:40:11,651  core l.1372 DEBUG paused? False
11:40:11,656  menu_options l.52 DEBUG function: menu_options
11:40:11,659  menu_options l.203 DEBUG function: menu_options finished
11:40:11,660  core l.2102 DEBUG function: display statusbar info: 230215-1542
11:40:11,660  video_operations l.200 DEBUG play rate: 1.000
QWindowsWindow::setGeometry: Unable to set geometry 389x394+0+0 (frame: 389x394+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 389x394+0+100 (frame: 389x394+0+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 389x388+0+0 (frame: 389x388+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 389x388+0+520 (frame: 389x388+0+520) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 540x808+0+0 (frame: 540x808+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 540x808+393+100 (frame: 540x808+393+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 608x808+0+0 (frame: 608x808+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 608x808+937+100 (frame: 608x808+937+100) margins: 0, 0, 0, 0)
QWindowsWindow::setGeometry: Unable to set geometry 371x808+0+0 (frame: 371x808+0+0) on QWidgetWindow/"QWidgetClassWindow" on "\\.\DISPLAY2". Resulting geometry: 371x808+1549+100 (frame: 371x808+1549+100) margins: 0, 0, 0, 0)
11:40:11,721  core l.1372 DEBUG paused? False
11:40:11,721  core l.1372 DEBUG paused? False
11:40:11,721  core l.1372 DEBUG paused? False
11:40:11,722  core l.1372 DEBUG paused? False
11:40:11,753  core l.1908 DEBUG begin load events from obs: 230215-1542
11:40:11,758  core l.1967 DEBUG end load events from obs
11:40:11,758  menu_options l.52 DEBUG function: menu_options
11:40:11,758  menu_options l.203 DEBUG function: menu_options finished
11:40:11,758  observation_operations l.249 DEBUG end load observation
11:40:20,319  core l.4764 DEBUG function: jumpForward_activated
11:40:20,319  core l.1372 DEBUG paused? False
11:40:20,324  core l.1372 DEBUG paused? False
11:40:20,324  core l.1372 DEBUG paused? False
11:40:20,325  core l.1372 DEBUG paused? False
11:40:20,326  core l.1372 DEBUG paused? False
11:40:22,712  video_operations l.200 DEBUG play rate: 0.900
11:40:23,252  video_operations l.200 DEBUG play rate: 0.800
11:40:24,16  video_operations l.200 DEBUG play rate: 0.700
11:40:24,692  video_operations l.200 DEBUG play rate: 0.600
11:40:25,180  video_operations l.200 DEBUG play rate: 0.500
11:40:28,470  core l.4764 DEBUG function: jumpForward_activated
11:40:28,470  core l.1372 DEBUG paused? False
11:40:28,475  core l.1372 DEBUG paused? False
11:40:28,475  core l.1372 DEBUG paused? False
11:40:28,476  core l.1372 DEBUG paused? False
11:40:28,476  core l.1372 DEBUG paused? False
11:40:29,162  core l.4764 DEBUG function: jumpForward_activated
11:40:29,162  core l.1372 DEBUG paused? False
11:40:29,166  core l.1372 DEBUG paused? False
11:40:29,166  core l.1372 DEBUG paused? False
11:40:29,167  core l.1372 DEBUG paused? False
11:40:29,168  core l.1372 DEBUG paused? False
11:40:30,152  video_operations l.200 DEBUG play rate: 0.400
11:40:30,939  video_operations l.200 DEBUG play rate: 0.300
11:40:36,430  core l.4764 DEBUG function: jumpForward_activated
11:40:36,430  core l.1372 DEBUG paused? False
11:40:37,328  core l.4764 DEBUG function: jumpForward_activated
11:40:37,328  core l.1372 DEBUG paused? False
11:40:37,335  core l.1372 DEBUG paused? False
11:40:37,335  core l.1372 DEBUG paused? False
11:40:37,335  core l.1372 DEBUG paused? False
11:40:37,336  core l.1372 DEBUG paused? False
11:40:40,360  video_operations l.200 DEBUG play rate: 0.200
11:40:41,806  video_operations l.200 DEBUG play rate: 0.100
11:40:44,410  video_operations l.200 DEBUG play rate: 0.200
11:40:47,575  core l.1372 DEBUG paused? False
11:40:48,505  core l.1372 DEBUG paused? False
11:40:48,509  core l.1372 DEBUG paused? False
11:40:48,510  core l.1372 DEBUG paused? False
11:40:48,510  core l.1372 DEBUG paused? False
11:40:48,511  core l.1372 DEBUG paused? False
11:40:49,503  core l.1372 DEBUG paused? False
11:40:50,320  core l.1372 DEBUG paused? False
11:40:50,324  core l.1372 DEBUG paused? False
11:40:50,324  core l.1372 DEBUG paused? False
11:40:50,325  core l.1372 DEBUG paused? False
11:40:50,325  core l.1372 DEBUG paused? False
11:40:52,533  video_operations l.200 DEBUG play rate: 0.100
11:40:53,530  core l.1372 DEBUG paused? False
11:40:54,265  core l.1372 DEBUG paused? False
11:40:54,887  core l.1372 DEBUG paused? False
11:40:55,585  core l.1372 DEBUG paused? False
11:40:55,588  core l.1372 DEBUG paused? False
11:40:55,589  core l.1372 DEBUG paused? False
11:40:55,589  core l.1372 DEBUG paused? False
11:40:55,590  core l.1372 DEBUG paused? False
11:40:56,762  core l.1372 DEBUG paused? False
11:40:57,227  core l.1372 DEBUG paused? False
11:40:57,632  core l.1372 DEBUG paused? False
11:40:58,150  core l.1372 DEBUG paused? False
11:40:58,154  core l.1372 DEBUG paused? False
11:40:58,154  core l.1372 DEBUG paused? False
11:40:58,155  core l.1372 DEBUG paused? False
11:40:58,155  core l.1372 DEBUG paused? False
11:40:59,612  core l.1372 DEBUG paused? False
11:40:59,972  core l.1372 DEBUG paused? False
11:41:00,280  core l.1372 DEBUG paused? False
11:41:00,677  core l.1372 DEBUG paused? False
11:41:00,681  core l.1372 DEBUG paused? False
11:41:00,681  core l.1372 DEBUG paused? False
11:41:00,681  core l.1372 DEBUG paused? False
11:41:00,682  core l.1372 DEBUG paused? False
11:41:04,37  core l.4609 DEBUG function: closeEvent
11:41:04,37  observation_operations l.1103 INFO Close observation MEDIA
11:41:04,37  observation_operations l.1105 INFO Check state events
11:41:04,37  observation_operations l.1158 INFO Check state events done
11:41:04,37  observation_operations l.1164 INFO Stop plot timer
11:41:04,37  observation_operations l.1172 INFO Stop player #1
11:41:04,37  observation_operations l.1172 INFO Stop player #2
11:41:04,38  observation_operations l.1172 INFO Stop player #3
11:41:04,38  observation_operations l.1172 INFO Stop player #4
11:41:04,38  observation_operations l.1172 INFO Stop player #5
11:41:04,38  observation_operations l.1198 INFO close tool window
11:41:04,38  core l.1978 DEBUG function: close_tool_windows
11:41:04,39  core l.2076 DEBUG function: close_tool_windows finished
11:41:04,39  observation_operations l.1215 INFO remove dock widget
11:41:04,40  observation_operations l.1215 INFO remove dock widget
11:41:04,40  observation_operations l.1215 INFO remove dock widget
11:41:04,41  observation_operations l.1215 INFO remove dock widget
11:41:04,42  observation_operations l.1215 INFO remove dock widget
11:41:04,44  menu_options l.52 DEBUG function: menu_options
11:41:04,44  menu_options l.203 DEBUG function: menu_options finished
11:41:04,44  observation_operations l.1247 INFO Observation  closed
11:41:04,44  config_file l.322 DEBUG save config file: C:\Users\eroll\.boris
11:41:04,45  config_file l.362 DEBUG Save recent projects
11:41:04,68  core l.1978 DEBUG function: close_tool_windows
11:41:04,69  core l.2076 DEBUG function: close_tool_windows finished
C:\Users\eroll\BORIS\Lib\site-packages\boris\misc\mpv-1.dll
olivierfriard commented 1 year ago

Thank you for the details. I will try to reproduce this issue at low play rate. What do you mean by "When clicking play on videos" ?

The boris.log file is useful only in case of a crash.

erolley-parnell commented 1 year ago

When I say "clicking play" I mean using the second icon from the left of the top toolbar while an observation is running to start and stop playback of the videos included in the observation.