image_fx won't empty buffers in non-tunnelled mode

[julianscheel]

When the image_fx component is used in non-tunnelled mode, either with pre-allocated buffers through OMX_UseBuffer or with self-allocated ones through OMX_AllocateBuffer, it does not fire EmptyBufferDone events.
I made up a simple test-case, that can be found here: https://github.com/julianscheel/omx-test
It can be easily compiled on Raspberry or Cross-Compiled from any other system, without any dependencies but the rpi-firmware libs and headers.

There are three examples included:

• test-audio_render is not really relevant for this, but was my starting point.
• test-video_render reads a raw yuv frame from file (decoded.yuv is included in the repository) and displays it.
• test-image_fx reads a raw yuv frame from file and feeds it to the image_fx component, also providing a buffer for output through FillThisBuffer.

Call the examples with the input file as parameter:

./test-video_render decoded.yuv
./test-image_fx decoded.yuv

test-video_render works flawless, but test-image_fx simply never receives a EmptyBufferDone callback. In contrast to the image_fx documentation I have to set the full image parameters for the output port as well, otherwise it fails with a BadParameter error.

The overall target would be using image_fx as deinterlacing filter in VLC. The implementation we did there suffers the same behaviour as this sample code.

[popcornmix]

From openmax guy:

We set the component up in stripe mode, with 1080p frame size at 16 rows per buffer.

We send a single output buffer without making sure that nFilledLen=nFlags=0.

We then send a single input buffer marked with ENDOFFRAME and waits for the input buffer to be returned (I assume the call to waitForEmpty does this).

There does seem to be a problem, but I've got two questions first:

• Does the component work correctly when we send full frames rather than stripes?
• Does the component work correctly in stripe mode when we only flag ENDOFFRAME on the last stripe?

If neither of these work, there there is a more obvious bug to fix first.

[julianscheel]

As far as I can see full frame mode does not work either. I actually use the component in full frame mode in my usecase, but can't get that to work. No matter how/when I set the ENDOFFRAME flag.

[julianscheel]

Anything I can do to assist you further? Provide more testcases or something like that?

[julianscheel]

I'm a little confused by this comment, btw: "We set the component up in stripe mode, with 1080p frame size at 16 rows per buffer.". The example code I posted sends a full frame and flags it with ENDOFFRAME. nSliceHeight is set to a multiple of 16 to match the requirements as stated in the documentation.

[popcornmix]

The nSliceHeight determines the size of each buffer output.
It is normally 16 for stripe based mode, and ((height + 15) & ~15) for full frame mode.

[julianscheel]

@popcornmix This is exactly what I do in my example:

#define ALIGN(x, y) (((x) + ((y) - 1)) & ~((y) - 1))
sPortDef.format.image.nSliceHeight = ALIGN(sPortDef.format.image.nFrameHeight, 16);

So the example should be in full frame mode.

Just one more note: I just noticed that for empty buffers (nFilledLen==0) the EmptyBufferDone callback is executed.

[julianscheel]

Any news on this? Sorry for bugging :)

[mcshane-fire]

I've had a look at this now, sorry for the delay.

The problem is not waiting for the state transition to executing to complete before providing the output port with a buffer. This means the call to FillThisBuffer is failing with an OMX_ErrorIncorrectStateOperation, since you're not allowed to provide buffers in the idle state.

If you put a waitFor(OMX_StateExecuting) before the call to FillThisBuffer, then your buffer gets accepted. There isn't another call to FillThisBuffer in the for loop, so we then get stuck at the second buffer. You'll need to add code to wait for the FillBufferDone callback to be called, in the same way we've got waitForEmpty.

FYI the way I debugged this problem was to add a function to use the core function OMX_GetDebugInformation:

#define DEBUG_LEN 4096
OMX_STRING debug_info[DEBUG_LEN];
void print_debug() {
    int len = DEBUG_LEN;
    debug_info[0] = 0;
    OMX_GetDebugInformation(debug_info, &len);
    fprintf(stderr, debug_info);
}

I put a call to this function at the point where the client was getting stuck, this then shows the current state of the IL components and ports. It's in csv format, so not the easiest to manually parse on the screen, but says:

• the component is in executing, no errors or pending state transitions
• both ports are enabled, no errors or pending operations
• both ports are populated with 1 buffer ('Populated,Buffers Allocated')
• neither port had a buffer being processed by the central IL system on VC (Buffers TOP == 0)
• the input port had received one buffer which was being processed (Buffers RIL == 1, Received == 1)
• the output port hadn't seen any buffers (Received == 0)

This told me to look at the way we were supplying output buffers. Given that state transitions are asynchronous, the problem was easy to spot. Hope this helps.

[julianscheel]

Thanks for your hints, actually they helped to fix the test case, which is good. The bad thing is that the actual code I initially spotted the issue with (image_fx deinterlace module for vlc, see https://github.com/julianscheel/vlc-omx/blob/master/modules/codec/omxil/deinterlace.c) did not suffer this issue.
So there must be something else I'm doing wrong there. I am carefully comparing state transitions between the now working sample app and the vlc module, but can't spot a difference so far. Buffers RIL and Received stays 0 on input as well as output port for the plugin so far...
So allow me to leave this ticket open a little longer. I will probably come up with some more questions ;)

[mcshane-fire]

Looking at deinterlace.c, do calls to OMX_EmptyThisBuffer/OMX_FillThisBuffer return success?

[julianscheel]

Oh, this was a good note. I wonder why I did not check for omx error there in the first place. I get indeed an error, stating that the state is not correct:

[0x1446978] omxil_deinterlace filter warning: OMX_FillThisBuffer failed (80001018: OMX_ErrorIncorrectStateOperation).
[0x1446978] omxil_deinterlace filter debug: OMX_GetDebugInformation: Component,State,Pending state,Processing command,Transition error,Revert transition,Tries,Next command,Errors,Pass buffermarks,Suppress Cmd Complete,Port Index,Direction,State,Pending State,RIL state,Pending RIL state,Transition error,Pending Flush,RIL buffers,Tunneled Port,Tunnel Flags, Tunnel Supplier,EGL,Populated,Buffers Actual,Buffers Allocated,Buffers TOP, Buffers RIL,EOS,Received,Transmitted,Param Changed,
image_fx:59,OMX_StateExecuting,,0,,0,0,,0,0,0,
,,,,,,,,,,,190,Input,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,1,1,0,0,0,0,0,0
,,,,,,,,,,,191,Output,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,1,1,0,0,0,0,0,0
video_render:58,OMX_StateExecuting,,0,,0,0,,0,0,0,
,,,,,,,,,,,90,Input,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,14,14,0,0,0,0,0,0

But I wonder a bit why this error occurs as the image_fx component is in OMX_StateExecuting according to the debug information? You have any hint on this?

[popcornmix]

Looking at the (GPU) code, that error is generated by one of:
state not executing or paused
port not enabled
a flush is pending
pending state is idle

[julianscheel]

Hm, looking at the debug information:

state not executing or paused

Column "State" says: OMX_StateExecuting

port not enabled

Column "State" (the 2nd one) says: Enabled for both ports

a flush is pending

Wouldn't this be only the case after calling OMX_CommandFlush?

pending state is idle

Column "Pending state" is empty.

Am I missing something?

[julianscheel]

Got some progress. Actually I garbled pInput/OutputPortPrivate, which was the reason for the Fill/EmptyThisBuffer calls to fail. But unfortunately I still don't get any callbacks. Debug information looks like this:

Component,State,Pending state,Processing command,Transition error,Revert transition,Tries,Next command,Errors,Pass buffermarks,Suppress Cmd Complete,Port Index,Direction,State,Pending State,RIL state,Pending RIL state,Transition error,Pending Flush,RIL buffers,Tunneled Port,Tunnel Flags, Tunnel Supplier,EGL,Populated,Buffers Actual,Buffers Allocated,Buffers TOP, Buffers RIL,EOS,Received,Transmitted,Param Changed,
image_fx:34,OMX_StateExecuting,,0,,0,0,,0,0,0,
,,,,,,,,,,,190,Input,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,2,2,0,2,0,2,0,0
,,,,,,,,,,,191,Output,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,2,2,0,2,0,2,0,0
video_render:33,OMX_StateExecuting,,0,,0,0,,0,0,0,
,,,,,,,,,,,90,Input,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,14,14,0,0,0,0,0,0
video_decode:30,OMX_StateExecuting,,0,,0,0,,0,0,0,
,,,,,,,,,,,130,Input,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,20,20,0,0,0,33,33,0
,,,,,,,,,,,131,Output,Enabled,0,Executing,,,0,0,0,0,Unspecified,0,1,1,1,0,0,0,11,10,1

Any more hints what might go wrong?

[julianscheel]

Ok, I just figured out the left over difference between my testcase and the VLC code has been the selected image filter. In the testcase I had selected ColourSwap, while in the VLC code I had the DeinterlaceAdvanced selected. If I choose ColourSwap in VLC the code runs fine and passes the data. Although it does not seem to actually swap the color.
So is there anything special to do when using the ImageFilterDeinterlaceAdvanced? I tried feeding it with more input/output buffers, but it never fires events.

[popcornmix]

There is something a bit ugly when using the deinterlace effect. It needs to acquire three consecutive video frames for processing. This means the processing pipeline requires extra buffers to be available or it stalls. See:
https://github.com/popcornmix/omxplayer/blob/master/OMXVideo.cpp#L577

Now, if you are not tunneling to video_decode you'll need a different approach. Possibly increasing the number of input buffers to image_fx will have the same effect.

[julianscheel]

Thanks for that hint. This got us a little further. We finally get events fired as expected. But unfortunately the output picture is always just a plain green buffer. So it seems the image_fx is only clearing the buffer, but not filling it.
We have extended our test case to show this beheviour: https://github.com/julianscheel/omx-test/blob/master/test-image_fx.c
While we only output a single frame there (you can display output.yuv with test-video-render from the same repository if you want), it behaves the same on our VLC plugin which continously passes frames into the component. So it's not only the first frame.
Are there any further settings that have to be made for the DeInterlaceAdvanced filter to work?

[julianscheel]

Could you reproduce the problem?

[popcornmix]

I can run the test app. It would be good if it continuously submitted frames, as the deinterlace algorithm uses three frames of input to produce an output frame, so I'm not sure it can work with a single frame of input.

[julianscheel]

We extended the test-app with commit ba61b08 to feed 3 buffers into the filter. This lets it return one buffer (FillBufferDone is called once and we dump the output to /tmp/output.yuv).
If you want we can extend it to continuously run, but the behaviour stays the same no matter how many frames we push in.

[julianscheel]

I just pushed a little change, with which the sample program renders 5 frames. So when the program finishes you will have the output of the 5th frame in /tmp/output.yuv and can view it with ./test-video_render /tmp/output.yuv

[popcornmix]

Okay, I've spent a while on this. There were a couple of trivial things that were not initialised in the non-tunnelled case which stopped the input buffer being processed. rpi-update to get that fix.

However the fixes had no effect on your test code, so I've been debugging that.
The memcpy has the src/dest arguments swapped so the input buffer is uninitialised.
I also believe

for(i = 1; i < nBuffers; ++i)

should start from 0. With these fixes, I now get a plausible output buffer.

[julianscheel]

Thanks for your work. This is definitely a step forward, as we get a picture out now. But it still does not seem to be deinterlaced. Is there some additional enable command that would be required? As the single-frame sample does not really allow to see whether deinterlacing works we also tested with other filters like Blur or ColourSwap. None of these filters does actually seem to affect the output picture.

The second issue we see is about timestamps. As the DeInterlace filter doubles the framerate I would assume that it interpolates timestamps for the added frames? Putting in frames with pts-delta of 40ms (25fps) I would expect the outcoming frames to have a pts-delta of 20ms (25fps). But we see mostly values around 40ms, like 39, 38, 41, etc. Is this intended? Would we have to take care of interpolating the correct timestamps?

[dennis-hamester]

Attached is an image that shows relative timestamps between two consecutive frames. Frames are doubled at first, but shortly after the initialization we seem to get only one output frame per input frame.

[popcornmix]

@dennishamester
I'm not quite understanding the input timestamps. Why the variability? Why the zero differences?
Are you submitting fields or frames? The deinterlace component expects frames.

deinterlace component estimates frame_interval from (IIR) average of difference of consecutive timestamps.
The two frames output will be at timestamp (of input) and timestamp + frame_interval/2.

[popcornmix]

@julianscheel
The BFF/TFF/frame flags are used to determine how to deinterlace the frame.
In the tunneled case these come from decoder. I'm guessing in the non-tuneled case these are not getting set.

Are you expecting TFF/BFF flags to be constant or varying with each frame?

[julianscheel]

@popcornmix
As of now we feed interleaved TFF frames only. As I understood it has to be set through setting OMX_IndexConfigCommonImageFilterParameters like this:

OMX_CONFIG_IMAGEFILTERPARAMSTYPE config;
OMX_ERRORTYPE omx_error;

OMX_INIT_STRUCTURE(config);
config.nPortIndex = image_fx_out_port; /*191 */
config.nNumParams = 1;
config.nParams[0] = 3;
config.eImageFilter = OMX_ImageFilterDeInterlaceAdvanced;
omx_error = OMX_SetConfig(sys->omx_handle, OMX_IndexConfigCommonImageFilterParameters, &config);

Where nParams[0] would be OMX_CONFIG_INTERLACETYPE.eMode, which we set to 3 for top field first interleaved.
Is this correct or must it be set differently? Or has it to be set per frame somehow?

[popcornmix]

That would have worked a week ago....
http://trac.xbmc.org/ticket/14627 was a ticket for streams with changing interlace values (i.e. a mixture of TFF/BFF/frame flags). To fix that I use the per frame flags that video_decode populates in preference.

In your non-tuneled case the missing frame flags are treated as "full frame" so deinterlace is skipped.
I should be able to distinguish the two cases and have per frame flags only applied when tunneled, so your nParams[0] flag is respected. I'll have a look.

[julianscheel]

Is it possible to set the per frame flag in non-tunnelled mode? That would be fine as well, as we have that information per frame.

[popcornmix]

From my understanding of the code I think not (I'll find out).
A guess you may be able to use OMX_IndexConfigCommonImageFilterParameters each time it changes.

[julianscheel]

Hm, it seems it's not trying to load the omxil plugin at all. You have the --vout omxil_vout part in your cmd?
Also could you paste the output of vlc -vvv --list?

[popcornmix]

My cmd:
vlc -vvv -Ioldrc --vout omxil_vout dell/deinterlace/n24hd.ts

and
vlc -vvv --list
http://pastebin.com/JreRvLd6

[julianscheel]

Hm, the plugins seem to be all available.
Looking at your first pastebin the last line is

[0x17eaa78] main decoder debug: looking for decoder module matching "any": 54 candidates

Is it stalled at that point? Because that is the part where it should find and open the omx module.

[julianscheel]

Are you running a raspbian image? I can try to setup a raspbian tomorrow and test/fix the binaries on it. I guess that will be easier than sorting it out via chat :)

[popcornmix]

Yes I'm running raspbian.

[julianscheel]

Alright, let me prepare this for you tomorrow morning.

[dennis-hamester]

I just tested the vlc in the tarball on a clean raspbian and everything worked. I had to install ffmpeg and libdvbpsi. I also updated the firmware and set the gpu_mem to 128.
On a side note, are you sure your vlc output is complete? It seems unusually short for a vlc -vvv run and does not indicate any relevant errors.

[julianscheel]

@popcornmix
Can you verify that you have a memory split that's at least 128MB for GPU?
And maybe check again if vlc freezes at that point or if your paste was just incomplete? We can run the binaries flawlessly with latest raspbian + rpi-update from today.

[popcornmix]

Yes, I've got 256M gpu_mem, and that is when the paste stops.
I'm currently on BRANCH=next rpi-update, but I wouldn't expect that to be a problem.
I'll switch to master branch when I get a chance.

[julianscheel]

Ok, we will test with the next branch tomorrow. Besides the next firmware you run a stock raspbian? We could also provide a full sd card image if this helps?

[popcornmix]

I develop from an nfs rootfs that started out as a clone of an older raspbian image.
It has been apt-get upgrade-ed since the last official raspbian image and gets rpi-update run frequently.

But as it has existed for many months, there is always a chance that something that has been installed is conflicting. I can install a new raspbian sdcard image and that may well let me run vlc.

[julianscheel]

Ok, that sounds like a good chance that a fresh sd card image will work for you. Especially as a fresh image worked for us. After installing ffmpeg, libdvbpsi and running rpi-update.

[dennis-hamester]

We're currently trying to use video_scheduler without a tunnel to video_renderer for debugging purposes. I'd like to see exactly when the scheduler outputs images. But I'm having problems setting this up properly. Even when the video_renderer is in state Executing, I get an ErrorIncorrectStateOperation when trying to call EmptyThisBuffer on it.
Is it even possible to run the video_scheduler without a tunnel on its output port? Can you think of any other way for us to debug if the scheduler properly delays the intermediate images?

[popcornmix]

You can get logging from openmax (http://www.raspberrypi.org/phpBB3/viewtopic.php?f=67&t=23185&p=232643#p232643) which almost certainly contains scheduled timestamps.

[popcornmix]

Okay, I've had another look, and my problem was missing libdvbpsi (sudo apt-get install libdvbpsi-dev fixed it).
I can now run the clip. Deinterlace appears to be working, but the video is juddery.

Poking around, all the timestamps produced by image_fx component are zero, because EmptyThisBuffer seems to be called with pBuffer->nTimeStamp=0.

Are you setting the timestamp on frames submitted?

[dennis-hamester]

Thanks for helping, we just stumbled into the same. After fixing this, we finally saw fluid playback. Now we're onto our next problem.. the teardown in Close does not always work and leaks memory. Anyways, thanks again for your help.

[dennis-hamester]

We changed our code to use tunnels between image_fx, video_scheduler, a clock and iv_renderer.
video_decode is not part of this but still its own vlc module. There are still problems with the exact timings, which are frequently a few milliseconds off compared to omxplayer. Here are two log files from the same video played with vlc and omxplayer.
omxplayer: https://gist.github.com/dennishamester/7465296
vlc: https://gist.github.com/dennishamester/7465307

Looking at the video_render lines, it seems the omxplayer uses 5 different buffers, but vlc uses only 3. Does this have anything to do with setting OMX_IndexParamBrcmExtraBuffers for the decoder?
The video_scheduler lines differ also: For vlc the request to the clock is always prefixed with a 0, like
"4103011.060: video_schedulerRIL:requesting media time for 0:(1f494878,59933848763,F10)"
but omxplayers log show numbers 0-3. Can you tell me what this means? Is it some kind of internal buffer id? And what does the F10 at the end mean?

Do you see anything else in the vlc log that could cause a slight delay in the frame output?

[popcornmix]

OMX_IndexParamBrcmExtraBuffers will cause extra buffers to be added to the decode pool.
OMXPlayer calls this when deinterlace is automatic or force on (but not off). Are you calling it?
(it may not be needed in your case, as the rendered images are coming from a different pool than the decode images).

The parameters to that logging message are "free_slot, img, timestamp, flags".
The free slot appears to be a queue of pending buffers (i.e. scheduled but not yet rendered).
The flags are usual nFlags containing OMX_BUFFERFLAG_*. 0x10 == OMX_BUFFERFLAG_ENDOFFRAME.

The free_slot==0 you are getting suggests only one frame is ever queued to be rendered, whereas omxplayer has a few frames queued to be rendered. That sounds like the problem.
Can you have a few frames buffered up to be rendered? You would them have more tolerance to being late.

[julianscheel]

The OMX_IndexParamBrcmExtraBuffers does not make much sense in our use case, I think. As you say it only affects the decoder pool, but not the pool which is used in our tunnel.
Still we managed to get smooth output with 1080i25 streams being deinterlaced now. We had to change the timestamp logic we have in our VLC module a bit.

So now we are stumbling into the next issue. For 720p50 streams we need deinterlace to be disabled, as they are progressive already. Our first approach was setting OMX_InterlaceProgressive on the OMX_ImageFilterDeInterlaceAdvanced. This badly fails, because the Filter still seems to double frames, which makes 100fps output, which probably is just too much for the Pi.
So our second approach was to switch to OMX_ImageFilterNone in case of progressive content, which works better, but still fails to cope with the 50fps of input. It just seems that OMX_ImageFilterNone takes too long to process each frame, so that the output can not be done fast enough.

I see that in omxplayer you just unplug image_fx from the tunnel. Unfortunately this seems hardly possible for us, because we need to allocate the buffers for our picture pool on the first element in the tunnel, which is image_fx in deinterlace scenario and would be video_scheduler if no deinterlace is done. So we would have to teardown the tunnel and reallocate all buffers if a progressive/interlaced change occurs. This does not sound like a good approach after all.
Do you have any thoughts how we could deal with this? In general I wonder why OMX_ImageFilterNone could be too slow after all? Shouldn't it just blindly pass the pictures through without touching?

[popcornmix]

image_fx is a component that copies images (as the usual case is to have a non-none effect).
So there is a cost to having it present and set to OMX_ImageFilterNone compared to not using it.

Tearing down and creating a tunnel should only take a fraction of a second, so doing that whilst running seems like an option (omxplayer does this to audio pipeline when audio parameters like number of channels changes).
I assume deinterlace changing is a rare event? (i.e. at adverts/programme change).

[dennis-hamester]

We are following your advice and create image_fx only when it is necessary. But now we must operate the scheduler in non-tunneled mode (on the input side), which doesn't work as expected. All components transition to executing properly, but no images get output. In the debug log we see many lines like this:

115829.695: video_render:7:RIL:GetParameter(2000001)
115829.718: video_render:7:processingCommand=1
115829.745: video_schedulerRIL:GetParameter(2000001)
115829.769: video_scheduler:6:processingCommand=1

Is it possible to use the scheduler in non-tunneled mode? Are there any special parameters we need to set? Currently we only set the video format params.

Edit: It seems images don't even reach the renderer. I can see:
video_schedulerRIL: about to send 2:1f48ee00
in the logs, but usually this is followed by a "display image" line which is missing when we use the scheduler in non-tunneled mode.

[dennis-hamester]

I added some more details to my last comment.

[julianscheel]

Just recognized, that we haven't updated this issue lately. Actually image_fx with FilterNone works just fine for 720p channels. We just needed to reduce the virtual delay our scheduler clocks sees, to reduce the number of queued frames in the scheduler. When image_fx doubles frames we run with 160ms scheduling delay now, when it does not (ImageFilterNone) we use 80ms scheduling delay.
With this we have pretty good results now. Our latest code can be found here: https://github.com/julianscheel/vlc-omx/tree/tunnel
We will do some more testing and then hopefully close this bug finally.

[julianscheel]

I think we can close this ticket. Things work as good as they probably can in non-tunneled omx mode as of now.