Help wanted with mysterious ofxVideoRecorder threading bug

So for a few years I was happily using Timothy Scaffidi’s excellend ofxVideoRecorder to render frames in OpenFrameworks and directly export them as a high-quality video.

Then at one point I upgraded my Ubuntu installation… and it stopped working. What’s really strange is that Timothy and I have very similar OS setups, yet he does not experience this issue. This has basically been blocking my side-project for a couple of years now :sweat:

The short version of what happens is this:

  1. ofxVideoRecorder (OVR) creates two pipes for video and audio (audio is optional) with an external command (ofxVideoRecorder.cpp [L293-L314])
  2. OVR opens ffmpeg with an external command, which is supposed to listen to these pipes (ofxVideoRecorder [L316-L341])
  3. the OF sketch renders the frames and generates audio, then sends the data to OVR, which then sends them to the pipes (which ffmpeg supposedly listens to) (ofxVideoRecorderExample [L42-L59])
  4. recording ends, pipes are closed (ofxVideoRecorderExample [L120-L123]
  5. NOW ffmpeg actually starts listening to the pipes…

Obviously, 5 should happen somewhere between 2 and 3. Here is the relevant output of the console:

[notice ] ofGstVideoGrabber: initGrabber(): selected device: Logitech Webcam C930e
[notice ] ofGstVideoGrabber: initGrabber(): selected format: 640x480 video/x-raw RGB framerate: 30/1
[notice ] ofGstUtils: setPipelineWithSink(): gstreamer pipeline: v4l2src name=video_source device=/dev/video0 ! video/x-raw,format=RGB,width=640,height=480,framerate=30/1    ! appsink name=ofappsink enable-last-sample=0 caps="video/x-raw, format=RGB, width=640, height=480"
[verbose] ofGstUtils: startPipeline(): attaching callbacks
[verbose] Pipeline is live and does not need PREROLL waiting PLAY
[verbose] ofGstUtils: gstHandleMessage(): unhandled message from src
[verbose] ofGstUtils: gstHandleMessage(): unhandled message from pipeline1
[verbose] ofGstUtils: gstHandleMessage(): unhandled message from src
[verbose] ofGstUtils: gstHandleMessage(): unhandled message from pipeline1
Cannot connect to server socket err = Bestand of map bestaat niet
Cannot connect to server request channel
jack server is not running or cannot be started
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for 4294967295, skipping unlock
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for 4294967295, skipping unlock
[ error ] RtApiAlsa::probeDeviceOpen: pcm device (hw:0,3) won't open for input.
[verbose] ofGstUtils: gstHandleMessage(): async done
[verbose] execThread: starting command: bash --login -c 'ffmpeg -y -acodec pcm_s16le -f s16le -ar 44100 -ac 2 -i "/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxarpipe0" -r 30 -s 640x480 -f rawvideo -pix_fmt rgb24 -i "/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxvrpipe0" -r 30  -vcodec mpeg4 -b 800k -acodec mp3 -ab 192k "/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/testMovie2016-12-24-22-27-02-345.mov"' &
[verbose] execThread: command completed successfully.
ffmpeg version 3.2.2-static http://johnvansickle.com/ffmpeg/  Copyright (c) 2000-2016 the FFmpeg developers
  built with gcc 5.4.1 (Debian 5.4.1-4) 20161202
  configuration: --enable-gpl --enable-version3 --enable-static --disable-debug --disable-ffplay --disable-indev=sndio --disable-outdev=sndio --cc=gcc-5 --enable-fontconfig --enable-frei0r --enable-gnutls --enable-gray --enable-libass --enable-libfreetype --enable-libfribidi --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-librtmp --enable-libsoxr --enable-libspeex --enable-libtheora --enable-libvidstab --enable-libvo-amrwbenc --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxvid --enable-libzimg
  libavutil      55. 34.100 / 55. 34.100
  libavcodec     57. 64.101 / 57. 64.101
  libavformat    57. 56.100 / 57. 56.100
  libavdevice    57.  1.100 / 57.  1.100
  libavfilter     6. 65.100 /  6. 65.100
  libswscale      4.  2.100 /  4.  2.100
  libswresample   2.  3.100 /  2.  3.100
  libpostproc    54.  1.100 / 54.  1.100
[verbose] ofxAudioDataWriterThread: opening pipe: /home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxarpipe0
[verbose] Recording.

[warning] ofxVideoDataWriterThread: got file descriptor 16
[verbose] ofxVideoDataWriterThread: opening pipe: /home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxvrpipe0
[verbose] ofxVideoRecorder: recDelta = -0.0333333. Too many video frames, skipping.

[verbose] ofxVideoRecorder: recDelta = -0.0333333. Too many video frames, skipping.

[verbose] ofxVideoRecorder: recDelta = -0.0333333. Too many video frames, skipping.

[verbose] ofxVideoRecorder: recDelta = -0.0333333. Too many video frames, skipping.

(...)

[verbose] ofxVideoRecorder: recDelta = -0.0333333. Too many video frames, skipping.

[verbose] Paused.

[verbose] ofxAudioDataWriterThread: closing pipe: /home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxarpipe0
[warning] ofxVideoDataWriterThread: got file descriptor 17
[verbose] ofxVideoDataWriterThread: closing pipe: /home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxvrpipe0
Guessed Channel Layout for Input Stream #0.0 : stereo
Input #0, s16le, from '/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxarpipe0':
  Duration: N/A, bitrate: 1411 kb/s
    Stream #0:0: Audio: pcm_s16le, 44100 Hz, stereo, s16, 1411 kb/s
Input #1, rawvideo, from '/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/ofxvrpipe0':
  Duration: N/A, bitrate: 221184 kb/s
    Stream #1:0: Video: rawvideo (RGB[24] / 0x18424752), rgb24, 640x480, 221184 kb/s, 30 tbr, 30 tbn, 30 tbc
Please use -b:a or -b:v, -b is ambiguous
[verbose] ofGstUtils: gstHandleMessage(): unhandled message from src
Output #0, mov, to '/home/videofelicitaties/VideoZuil2/ofxVideoRecorder/bin/data/testMovie2016-12-24-22-27-02-345.mov':
  Metadata:
    encoder         : Lavf57.56.100
    Stream #0:0: Video: mpeg4 (mp4v / 0x7634706D), yuv420p, 640x480, q=2-31, 800 kb/s, 30 fps, 15360 tbn, 30 tbc
    Metadata:
      encoder         : Lavc57.64.101 mpeg4
    Side data:
      cpb: bitrate max/min/avg: 0/0/800000 buffer size: 0 vbv_delay: -1
    Stream #0:1: Audio: mp3 (libmp3lame) (.mp3 / 0x33706D2E), 44100 Hz, stereo, s16p, 192 kb/s
    Metadata:
      encoder         : Lavc57.64.101 libmp3lame
Stream mapping:
  Stream #1:0 -> #0:0 (rawvideo (native) -> mpeg4 (native))
  Stream #0:0 -> #0:1 (pcm_s16le (native) -> mp3 (libmp3lame))
Press [q] to stop, [?] for help
frame=    0 fps=0.0 q=0.0 Lsize=       0kB time=00:00:00.00 bitrate=N/A speed=   0x    
video:0kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown

Both Timothy and I are at a loss as to what the exact bug might be, so I’m posting here as a last-ditch effort to get this fixed. Maybe someone with more knowledge about ofThread might have a clue?

Full discussion of the bug so far can be found here, although it does not feature much more information:

https://github.com/timscaffidi/ofxVideoRecorder/issues/44