AVFoundationPlayer: Overall Stability Issues with Recent Developments

[urshofer]

Hello -

I made an application which is asynchronously loading many short movie files (from 1 to 5 seconds a file) over a long period of time. This means countless loadAsync, play and pause commands.

I used a recent git master version https://github.com/openframeworks/openFrameworks/commit/27b09aae8c2108cb78cd1b18140ba6ab1040a891 where @i-n-g-o made some changes and I tested them quite extensively (https://github.com/openframeworks/openFrameworks/pull/3736).

Compiling the same application against current oF master creates certain instabilities and runtime crashes. I'll try to give some more details about the bugs, but I need some time to gather them. I just noticed that since the commit above some major changes were made to the AVFoundationPlayer.

Best, Urs

[ofTheo]

Thanks for reporting this! As we�re close to a release it would be great if you could track down the issues soon. Would love to have the player as stable as possible for release.

Or if you want to post some minimal sample code that demonstrates the issue - that would help too!

[urshofer]

Allright -

I added an example into ofxGaplessVideo. It does nothing more than loading every 500ms a movie clip (async) and 500ms later playing:

https://github.com/urshofer/ofxGaplessVideo

It seems to me that the application runs well if compiled as a 64bit target. If compiled 32bit, it crashes already during startup (Tested on OSX 10.10.5, mid 2009PB 12"):

libobjc.A.dylib`objc_msgSend:
    0x94838090 <+0>:  movl   0x8(%esp), %ecx
    0x94838094 <+4>:  movl   0x4(%esp), %eax
    0x94838098 <+8>:  cmpl   $0xfffeb010, %ecx
    0x9483809e <+14>: je     0x948380ed                ; <+93>
    0x948380a0 <+16>: testl  %eax, %eax
    0x948380a2 <+18>: je     0x948380e8                ; <+88>
    0x948380a4 <+20>: movl   (%eax), %edx
    0x948380a6 <+22>: pushl  %edi
    0x948380a7 <+23>: movl   0x20(%edx), %edi
    0x948380aa <+26>: pushl  %esi
    0x948380ab <+27>: movl   (%edi), %esi
    0x948380ad <+29>: movl   %ecx, %edx
    0x948380af <+31>: shrl   $0x2, %edx
    0x948380b2 <+34>: andl   %esi, %edx
->  0x948380b4 <+36>: movl   0x8(%edi,%edx,4), %eax

And the console:

2015-10-27 17:27:19.644 videoTestDebug[44207:2455619] video loaded at 640 x 360 @ 23.649729 fps
[17:27:19.681] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293
[17:27:19.682] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293
[17:27:19.682] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293
[17:27:19.682] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293
[17:27:19.682] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293
[17:27:19.682] itemasync_CopyProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2088
2015-10-27 17:27:19.815 videoTestDebug[44207:2455643] video loaded at 640 x 360 @ 23.649729 fps
2015-10-27 17:27:19.978 videoTestDebug[44207:2455617] video loaded at 640 x 360 @ 23.220974 fps
fCoreAudioDriverUID AppleHDAEngineInput:8,0,1,0:1
Append 3.mp4
(lldb) 

So I'm not sure about my bug report. If openFrameworks goes 64bit anyway, the report will be obsolete, I guess.

Urs

[bakercp]

Just want to echo some problems we're seeing as well with the latest release of kibio. I haven't had a chance to drill down and figure out what's going on, but we're just looping videos (no speed changes, etc) and occasionally loading new ones. I'll try to spend some time on this over the next few days and report back ...

[pizthewiz]

Crashing on objc_msgSend suggests that the object being messaged is a deallocated zombie. Interesting it only occurs when compiled and run 32-bit.

@bakercp Is it your experience that the stability issues are limited to the i386 arch and not x86_64?

[bakercp]

Honestly I'm not sure yet -- I know for sure that it is happening with x86_64. I haven't compared to 32bit yet.

[pizthewiz]

Gotcha, so the crash above on launch when built/run i386 is only one symptom of a larger issue.

[bakercp]

The strange thing is I can't reproduce the issues on my machine ... they always happen on other people's machines ... :/ So I have to get into a computer lab and try to break it. Yeah, ours crash during runtime.

[bakercp]

I think it mostly happens if we try to load new videos during runtime ... but will confirm that.

[ofTheo]

Just tried your example @urshofer On 10.9 I get no errors or crashes on 32bit or 64bit

[urshofer]

Okay...

On my machine (10.10.5) it crashes sometimes at startup, sometimes not. 64bit seems reliable...

Am 27.10.2015 um 18:24 schrieb Theodore Watson notifications@github.com:

Just tried your example @urshofer https://github.com/urshofer On 10.9 I get not errors or crashes on 32bit or 64bit

— Reply to this email directly or view it on GitHub https://github.com/openframeworks/openFrameworks/issues/4485#issuecomment-151576967.

[pizthewiz]

Hmm, I wonder if this is related to the media files. What is the media codecs/container/resolution/framerate you are using? Also a gist of the full backtrace when the crash occurs would be great. From the debugger just tap out bt, hit return and copy/paste the full output.

[urshofer]

allright: here's the backtrace: https://gist.github.com/urshofer/16ebd05fbc37773d0e5a https://gist.github.com/urshofer/16ebd05fbc37773d0e5a

and here's the file info of the movies: https://gist.github.com/urshofer/e898b2fd6cc4740cdc49 https://gist.github.com/urshofer/e898b2fd6cc4740cdc49

as I said: 10.10.5 / compiled as 32 bit...

Am 28.10.2015 um 17:26 schrieb pizthewiz notifications@github.com:

Hmm, I wonder if this is related to the media files. What is the media codecs/container/resolution/framerate you are using? Also a gist https://gist.github.com/ of the full backtrace when the crash occurs would be great. From the debugger just tap out bt, hit return and copy/paste the full output.

— Reply to this email directly or view it on GitHub https://github.com/openframeworks/openFrameworks/issues/4485#issuecomment-151900342.

[urshofer]

Now it also crashed if compiled as 64 bit - so I guess it has nothing to do with the compilation.

The test application possibly does a loadAsync twice on the same player object, in case a clip was not loaded in time. Probably, this could be a problem. Therefore, the bug happens more often on my slow laptop than on a faster machine.

Am 28.10.2015 um 17:26 schrieb pizthewiz notifications@github.com:

Hmm, I wonder if this is related to the media files. What is the media codecs/container/resolution/framerate you are using? Also a gist https://gist.github.com/ of the full backtrace when the crash occurs would be great. From the debugger just tap out bt, hit return and copy/paste the full output.

— Reply to this email directly or view it on GitHub https://github.com/openframeworks/openFrameworks/issues/4485#issuecomment-151900342.

[bakercp]

@urshofer your slow machine theory sounds like a very very strong possibility. As I review my encounters with the issue -- I've only run into my crashing during loads on slower machines ... mine is not slow, and thus I never can reproduce the crash. But people in our workshops on slower machines see it often.

[ofTheo]

could we just add a check to see if the load function has completed? make the second call to load block until load is finished?

looking at the code now it looks like non-async loading is the default. but maybe there is still something where the video isn't fully loaded.

[ofTheo]

ignore the return stuff I mentioned.

[ofTheo]

a really easy way to get this to crash for me is to change the time from 500ms to 50ms in the example @urshofer provided.

looking at it now

[ofTheo]

a much simpler way of reproducing this issue even on fast machines is modifying the videoPlayerExample as below:

this seems to be an issue with non async too.

I think you will get a crash if you try and reload a movie before the first frame has come in.

int timeLastLoaded = 0;
//--------------------------------------------------------------
void ofApp::setup(){
    ofBackground(255,255,255);
    ofSetVerticalSync(true);
    frameByframe = false;

    // Uncomment this to show movies with alpha channels
    // fingerMovie.setPixelFormat(OF_PIXELS_RGBA);

    fingerMovie.load("movies/fingers.mov");
    fingerMovie.setLoopState(OF_LOOP_NORMAL);
    fingerMovie.play();
}

//--------------------------------------------------------------
void ofApp::update(){
    if( ofGetElapsedTimeMillis() - timeLastLoaded > 100 ){
        fingerMovie.load("movies/fingers.mov");
        fingerMovie.play();
        timeLastLoaded = ofGetElapsedTimeMillis();
    }
    fingerMovie.update();
}

[ofTheo]

ping @i-n-g-o @julapy @openframeworks/video @openframeworks/macos

Not sure if I will have time to debug this before this weekend, so if others might be able to take a look that would be great.

It looks like the internal video player is getting deleted fine. But something is still running ( I think getting the first frame loaded maybe )?

[urshofer]

Hi -

I think the async features need in general some improvement. For example would it be nice to have an event triggered when an asset is loaded. Or that repeated loading is blocked if a previous async-load has not finished.

Best, Urs

[i-n-g-o]

hi. the crash only happens when we use AVPlayerItemVideoOutput for scrubbing on OSX >= 10.8. the crash can be avoided by setting: #define USE_VIDEO_OUTPUT 0 in ofAVFoundationVideoPlayer.h and force not to use newer features.

something is not getting cleanup up when loading it seems. looking into it deeper.

[bakercp]

@i-n-g-o thanks for looking at this -- I'd say this is pretty important for 0.9.0.

[bakercp]

@bilderbuchi can we get this bugfix milestoned for 0.9.0 since it's essentially a core bug :)

[i-n-g-o]

hm. when adding: [self.playerItem removeOutput:self.videoOutput]; to method unloadVideo it is more stable. while it crashes quite soon without it, i can load much more often.

but it still does crash

[i-n-g-o]

hm. not sure what happens. but it is related to the VideoOutput (AVPlayerItemVideoOutput)

not setting the videoOutput ([self.playerItem addOutput:self.videoOutput];) avoids the problem, but also the video-output ;) not setting the playerItem also avoids the problem. seems the problem is withing AVPlayer when using a AVPlayerItemOutput.

would be interesting if this behaviour can be reproduced without oF.

[ofTheo]

going to do the #define USE_VIDEO_OUTPUT 0 fix for now as it seems to work well with the test example above ( once you add fingerMovie.play(); after loadMovie which was missing. )

we can than milestone a fix for the newer approach for 0.9.1

thanks for looking into this @i-n-g-o @urshofer @bakercp !

[i-n-g-o]

forcing USE_VIDEO_OUTPUT to 0 removes backwards-playing capability.

i tried to reproduce the behaviour in a plain cocoa-project loading video like in the ofAVFoundationVideoPlayer. i could not. when loading a new file, we actually destroy the player-object and create a new one. while in theory this should work, there is something weird going on.

i see 2 ways: a) we fix it. this seems not to be so trivial. after analyzing the code i dont have an idea where to start. b) rebuild the player in a way, that we re-use the player-object within ofAVFoundationPlayer. this should in theory work. (that's what i basically tried in the cocoa-only-tests).

i have one problem with (b) at the moment: the Observer for the playerItem does not trigger, when loading a new file. hence the player internally is "not ready"

[ofTheo]

@i-n-g-o I just noticed the backwards playing issue. I'll leave this issue open then for now and will also try and look at it more this weekend.

reusing the player seems like it could be a good approach!

[i-n-g-o]

@ofTheo jep. i also think re-using the player could improve things. weird the observer-thing. i see the same behaviour in the cocoa-only test i made.

[i-n-g-o]

we need to destroy the AVPlayer object to get the key-updates of the newly created AVPlayerItem. (why??)

i now re-use the internal ofAVFoundationVideoPlayer. loading synchronously for ~1000 times now without crashes. memory seems to be stable. it looks good until now.

[i-n-g-o]

for async loading we need proper locking.

here are my changes so far: https://github.com/i-n-g-o/openFrameworks/tree/ofAVFoundationPlayer_fastloading_fixes

has some problems when loading async. since the player is reused we need to add a check when drawing the pixels.

getting there :)

[ofTheo]

awesome! thanks so much for looking at this issue.

[ofTheo]

@i-n-g-o I think the goal is to release RC3 this week. Should we pull in these changes now, or wait for a PR?

Cheers! Theo

[i-n-g-o]

already wanted to give an update on this... i proceed slower than i hoped (job). also it's not quite done, still having issues with async loading. i can work on it tomorrow, maybe tonight.

it would be good to have some improvement in RC3.

[arturoc]

i was planing to directly release 0.9 after RC2, RC1 has been out for about 2 months with a feature freeze so i'd say we should be ready after the remaining things are fixed.

also @i-n-g-o there's the berlin meetup this sunday if you want to finish it there :)

[i-n-g-o]

@arturoc right, another month passed already ;)

let's see. maybe we can test something until sunday and finalize it then.

[ofTheo]

@arturoc I mentioned on the IRC I think it's good practice to do a final RC before release. There have been quite a few changes/fixes since RC2 and this would be a chance to double check and test everything.

If RC3 works without issue it would become the 0.9.0 release. I think that has been our approach in the past too.

[arturoc]

yes, i thought RC2 was the final RC before the release :) i was thinking on doing an RC3 when i released RC1 but it's been published for 2 months so i don't think it's necesary now, also we've only done RC3 once for 0.8.1 but since then we've only done RC2.

and there hasn't been that many changes since the RC2, mostly

• some fixes to the packaging script in linux arm to include makefiles
• fixes for crosscompiling in arm
• compiled libraries with osx 10.8
• fixes for area light
• some fixes for msys2 for opencv and renamed the platfrom from win_cb
• removed ofx3dModelLoader
• fix for android grabber

here's the full list:

http://ci.openframeworks.cc/logs/logsinceRC2.txt

[ofTheo]

huh - thats a lot less than I thought :) this AVF OS X issue will be important to test for sure.

@i-n-g-o I just tried your current branch and it currently does seem a lot less fast at reloading the movie than just the #define fix

also I noticed it will crash when trying to close the movie before reloading it.

The crashing on close can be simulated with the code below. I'm sure this is still very much work in progress, but maybe its helpful feedback? Thanks!!

#include "ofApp.h"

int timeLastLoaded = 0;
//--------------------------------------------------------------
void ofApp::setup(){
    ofBackground(255,255,255);
    ofSetVerticalSync(true);
    frameByframe = false;

    // Uncomment this to show movies with alpha channels
    // fingerMovie.setPixelFormat(OF_PIXELS_RGBA);

    fingerMovie.load("movies/fingers.mov");
    fingerMovie.setLoopState(OF_LOOP_NORMAL);
    fingerMovie.play();
    timeLastLoaded = ofGetElapsedTimef();
}

//--------------------------------------------------------------
void ofApp::update(){
    if( ofGetElapsedTimeMillis() - timeLastLoaded > 2000 ){
        fingerMovie.close();
        fingerMovie.load("movies/fingers.mov");
        fingerMovie.play();
        timeLastLoaded = ofGetElapsedTimeMillis();
    }
    fingerMovie.update();
}

[i-n-g-o]

@ofTheo the closing-crash basically is the same as the loading-crash related to destroying the internal player object. close also destroys the ofAVFoundationVideoPlayer, if this happens too fast (and or too often) after loading it crashes.

in both cases close and load (loadAsync) we need to keep the object and just clean things up. (or fix the dispose-crash)

synchron loading is much slower on the branch at the moment because it does not dispose resources on a background thread.

[i-n-g-o]

i just pushed an update to: https://github.com/i-n-g-o/openFrameworks/tree/ofAVFoundationPlayer_fastloading_fixes

sync/async-loading should work, close should not cause a crash anymore.

@ofTheo @urshofer and anybody who can: please give it a try, if possible test it for longer.

i did not come around to test what happens when ofAVFoundationPlayer objects are created and destroyed.

[i-n-g-o]

when loading async this error shows up: itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293

seems something was invalidated before a property gets set.

somebody knows what it means and how to avoid this?

[armadillu]

I'll give it a try it when I get to the office; sorry I don't have more time to help out.

ofxAVFVideoPlayer player has gone through so many iterations; but at some point in the past I tried to tackle the loading an unloading slowness problem... I had a project that had to load an unload CMS driven video content pretty much at any random time and in doing so the main thread would stop for 100 ms or so... It totally spoiled the mood for he app, so I really spent time trying to fix. I ended up building some sort of "Garbage Collector" for videos, so you didn't delete the video directly, you just flagged it as deletable and the background thread would dispose of it after a while. It was kind of ghetto but it worked pretty well at the time (with that version of the player, and on 10.9 only) but it doesn't seem to work anymore now. I'm not implying this should be implemented now; just noting that this "Garbage Collector" strategy worked well for me once in a time.

https://github.com/armadillu/ofxThreadedVideoPlayer/tree/master/src

[i-n-g-o]

@armadillu i know ofxThreadedVideoPlayer and used it a while ago. ofAVFoundationVideoPlayer uses a similar strategy and disposes its resources on a background thread. loading itself is not concerned with the disposal and therefore fast. (a while ago i referred to the threaded player here: https://github.com/openframeworks/openFrameworks/issues/3704)

great if you can test and give some feedback.

[armadillu]

I've just tested it; it throws quite a few errors

12:04:28.634] itemasync_SetProperty signalled err=-12785 (kFigBaseObjectError_Invalidated) (invalidated) at /SourceCache/CoreMedia/CoreMedia-1562.238/Prototypes/Player/FigPlayer_Async.c line 2293

but it doesn't seem to crash. It does leak a lot though; after loading and unload 50 videos, the app uses 1Gb of RAM.

One bizarre error I noticed is that the video playback (or at least the sound) stops when the OF window is behind some other window. The error spit rate also accelerates madly when that happens. I suspect the framerate of the app skyrockets when the app is hidden / minimized??

I am testing with this:

    video.update();
    if(ofGetFrameNum()%30 == 1 && c < 5000){
        video.stop();
        video.close();
        video = ofAVFoundationPlayer();
        video.load("sound_in_sync_test.mp4");
        video.play();
        c++;
    }

[i-n-g-o]

@armadillu thanks for testing no clue where itemasync_SetProperty comes from and how to avoid it.

ok. the leaks come from object-breeding. if you load with the same object (comment out video = ofAVFoundationPlayer();), there should be no leak. can you confirm?

[armadillu]

Yep, no leaks when I "re-use" the object.

    video.update();
    if(ofGetFrameNum()%30 == 1 && c < 5000){
        video.stop();
        video.close();
        //video = ofAVFoundationPlayer();
        video.load("sound_in_sync_test.mp4");
        video.play();
        c++;
    }

But that means the destructor is missing some stuff

[i-n-g-o]

the destructor disposes the videoPlayer... theoretically. it seems it doesnt.

[i-n-g-o]

looking at the memory-location of the objects shows:

first load: loadPlayer: 0x100f18dd8
destructor: ~ofAVFoundationPlayer: 0x7fff5fbff2c8
second load: loadPlayer: 0x100f18dd8

that the same object loads the movie again.

using a shared pointer works, the videoPlayer gets released : fingerMovie = shared_ptr<ofAVFoundationPlayer>(new ofAVFoundationPlayer());

[i-n-g-o]

creating and deleting ofAVFoundationPlayer objects quickly (every 100ms) makes problems. thought the lock would prevent that from happening. :/