failure to exit after short stream in --live mode

[fabled]

I'm using omxplayer to play rtmp live streams. Sometimes the player is allowed to connect, but the stream is very brief, and then it ends. This can cause omxplayer to "hang" and not exit cleanly.

Logs from genlog is as follows:

22:45:39 T:335324434   DEBUG: CPCMRemap: Downmix normalization is disabled
22:45:39 T:335324554   DEBUG: CPCMRemap: Mapping mono audio to front left and front right
22:45:39 T:335324770   DEBUG: CPCMRemap: FL = CE(0.707107)
22:45:39 T:335324964   DEBUG: CPCMRemap: FR = CE(0.707107)
22:45:39 T:335330727   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_decode input port 120 output port 121 m_handle 0xce1d20
22:45:39 T:335338021   DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.audio_decode) - port(120), nBufferCountMin(4), nBu
fferCountActual(16), nBufferSize(65536), nBufferAlignmen(16)
22:45:39 T:335352714   DEBUG: COMXAudio::Initialize Input bps 32 samplerate 48000 channels 1 buffer size 288000 bytes per second 192000
22:45:39 T:335352966   DEBUG: pcm->direction      : input
22:45:39 T:335353105   DEBUG: pcm->nPortIndex     : 0
22:45:39 T:335353312   DEBUG: pcm->eNumData       : 0
22:45:39 T:335353448   DEBUG: pcm->eEndian        : 1
22:45:39 T:335353578   DEBUG: pcm->bInterleaved   : 1
22:45:39 T:335353835   DEBUG: pcm->nBitPerSample  : 32
22:45:39 T:335353966   DEBUG: pcm->ePCMMode       : 0
22:45:39 T:335354093   DEBUG: pcm->nChannels      : 1
22:45:39 T:335354223   DEBUG: pcm->nSamplingRate  : 48000
22:45:39 T:335354350   DEBUG: OMX_AUDIO_ChannelCF
22:45:39 T:335354476   DEBUG: COMXAudio::Initialize device omx:both passthrough 0 hwdecode 0
22:45:39 T:335354942   DEBUG: OMXThread::Create - Thread with id -1257149168 started
22:45:39 T:335355246  NOTICE: OMXClock using audio as reference
22:45:39 T:335356069   DEBUG: OMXClock::OMXReset audio / video : 1 / 1 wait mask 0->3 state : 2->1
22:45:39 T:335357448   DEBUG: Normal M:0 (A:-4503599627370496 V:-4503599627370496) P:1 A:0.00 V:0.00/T:0.70 (0,0,0,0) A:0% V:0% (0.00,8.80)
22:45:39 T:335357885    INFO: CDVDPlayerAudio::Decode dts:203000 pts:203000 size:119
22:45:39 T:335358637   DEBUG: COMXAudioCodecOMX::Decode(0xd32a80,119) format=8(8) chan=1 samples=1024 size=8192 data=0xce5b20,0,0,0,0,0,0,0
22:45:39 T:335358938   DEBUG: COMXAudioCodecOMX::GetData size=4096/4096 line=4096/4096 buf=0xd32b20, desired=65536
22:45:39 T:335368368    INFO: COMXVideo::SubmitEOS
22:45:39 T:335369002    INFO: COMXAudio::SubmitEOS
22:45:39 T:335379802   DEBUG: Normal M:0 (A:203000 V:-4503599627370496) P:1 A:0.20 V:0.00/T:0.70 (0,0,0,0) A:0% V:0% (0.00,8.80)

After this nothing is printed in the log, and strace shows that it is in a loop that does some mutex locking/unlocking and a nanosleep() call for 10 milliseconds. Sounds like the End-Of-Stream is not recognized properly by the main decoding loop.

[popcornmix]

Do you have an example stream I can play from?

[fabled]

It seems to be related to '--live' switch. When playing without --live mode, omxplayer exists at the end normally. For a test video, you can use http://dev.alpinelinux.org/~tteras/test.flv

To reproduce you can:

omxplayer --live http://dev.alpinelinux.org/~tteras/test.flv

[fabled]

I believe what happens is that the stream is started in stopped state. And in --live mode it's never started to be played because the buffers do not get full enough, and when EOS is signaled the latency cannot be calculated anymore. So it's hanging in the pause state waiting for buffers to fill.

This is also indicated by logs. The logs of 'hanged' state include:

06:52:34 T:1081218737   DEBUG: OMXClock::OMXStop
06:52:34 T:1081219356   DEBUG: OMXClock::OMXSetSpeed(0.00) pause_resume:1

But they do NOT include the lines indicating starting playback that are present when playing longer stream:

06:53:32 T:1138958275   DEBUG: Normal M:0 (A:1477000 V:1468000) P:1 A:1.48 V:1.47/T:0.70 (0,0,1,1) A:0% V:0% (0.0 0,8.80)
06:53:32 T:1138959924   DEBUG: Resume 1.48,1.47 (0,0,1,1) EOF:0 PKT:0
06:53:32 T:1138960461   DEBUG: OMXClock::OMXSetSpeed(1.00) pause_resume:1

[jehutting]

Just to let you know that I got a totally different behaviour.

With or without the --live option, nothing is shown (screen stays black). Only WITH the -g (generate logging) option the movie is shown and stopped normally.

Doesn't matter if the test.flv is played through http or local (so downloaded to my RPI).

Adding some printf statements shows that the (mainloop) Resume is executed, but the clock isn't started (viewable with the -s (stats) option). Only with the -g option the clock starts running.

Also, only with the -g option, I get an (OMXVideo) V:PortSettingsChanged message just after the EOF (detection by OMXReader) and before the Resume.

Furthermore, the video and audio EOS are submitted, but without a running clock, an EOS signalling will never occur ("the hang").

Strange...

[fabled]

@jehutting Yes, I noticed similar effect now too. It seems '--refresh' also affects this a bit. Or potentially it just depends on timing. But at times even without --live flag it hangs.

I did notice that the PortSettingsChanged callback comes only without --live. If using --live I never get PortSettingsChanged callback. This is perhaps connected to the fact that just adding OMXResume() call to happen in --live mode does not solve the hanging.

[fabled]

As a 'hack' workaround I'll probably to my tree something along the lines of:

--- omxplayer-a4ee0743ecf49ffa1818510e8cc7872282ca66a8/omxplayer.cpp.orig
+++ omxplayer-a4ee0743ecf49ffa1818510e8cc7872282ca66a8/omxplayer.cpp
@@ -1683,6 +1683,10 @@

     if(m_omx_reader.IsEof() && !m_omx_pkt)
     {
+      // EOF before playback started, stop.
+      if (m_av_clock->OMXIsPaused())
+        break;
+
       // demuxer EOF, but may have not played out data yet
       if ( (m_has_video && m_player_video.GetCached()) ||
            (m_has_audio && m_player_audio.GetCached()) )

This is not the clean solution, but seems to fix the immediate problem I have.

[jehutting]

The only way I can get it to run without using the -g option is by forcing to call the OMXVideo PortSettingChanged() - initializes and tunnels the video OMX components.

$ git diff OMXVideo.cpp
diff --git a/OMXVideo.cpp b/OMXVideo.cpp
index 070a54c..a818ff4 100644
--- a/OMXVideo.cpp
+++ b/OMXVideo.cpp
@@ -714,6 +714,8 @@ bool COMXVideo::Open(COMXStreamInfo &hints, OMXClock *clock, const CRect &DestRe
   float fAspect = hints.aspect ? (float)hints.aspect / (float)m_decoded_width * (float)m_decoded_height : 1.0f;
   m_pixel_aspect = fAspect / m_display_pixel_aspect;

+  PortSettingsChanged();
+
   return true;
 }

I'm wondering why this PortSettingsChanged is normally done in the COMXVideo::Decode(). I find it strange that the "OMX layout behind m_omx_decoder" is setup while already reading/caching/etc. the video stream. Why is this not done in `COMXVideo::Open()``?

[senko]

I seem to have hit the same problem with slightly different scenario - the (audio only) live stream is playing but sometimes, related to network connectivity, it gets stuck. The strace log looks the same as described in the description - 10ns sleeps.

It's hard to reproduce, but based on the info in this thread looks like the buffer gets emptied, pauses, and then the player receives EOF.

@fabled would it make sense to modify your check to test both whether the stream is paused and whether it's live? If I read the fffmpeg source correctly (https://github.com/FFmpeg/FFmpeg/blob/master/libavformat/avio.c#L331) the network stream should only get EOF if it was actually closed, not if there's no more data to be read, so this check should be fine in case of live streams.

(This is the first time I'm poking around omxplayer or ffmpeg internals though, so I probably have some things wrong.)

[fabled]

@senko Yes, checking for --live also is probably right thing to do. I just noticed my patch silently discard playing short real files that get fully buffered and EOF is hit before playing started.

[fabled]

Actually this may have been fixed with commit e239f05651333b2a50532580c54ee7741775e7c2 I need to restest.

[fabled]

Hmm.. it's still broke in master. I think there's two issues:

• PortSettingsChanged might not get called, and thus the clock might not run
• in --live mode the stream might never get started

Perhaps patch from @jehutting together with fixing the --live mode would be the proper solution.

[senko]

I'll try to use both here (might be a while before the problem manifests in my use case, but I've got a RPi running omxplayer literally 24/7 so it's bound to happen sooner or later), and report what happened.

[fabled]

Ok, I sort of have now a patch that should fix the properly the above. The final problem seems to be that AVFMT_FLAG_NOBUFFER is set in live mode, and that somehow seems to mess up the dts/pts/packets for my test video. I wonder if it'd be better to turn that off.

[fabled]

The patch that seems to fix all cases for me: http://git.alpinelinux.org/cgit/aports/plain/main/omxplayer/issue-297.patch

[senko]

Took a long time, but today I got a patched player working and an unpatched stopping when we had some network problems. It’s not very reliable answer, but from what I can see, works for me as well.

:+1:

[dlernstrom]

I've been fighting this bug for approximately 4 months now. It took me this long to stumble across the thread and the patch that @fabled submitted on Dec 18, 2015. I have a video file that manifests the bug approximately 30% of the time and can confirm with a patched up OMXPlayer that the problem went away.

How do we get this patch mainstreamed into master?

[popcornmix]

@dlernstrom Can you test with just the changes to OMXReader.cpp aplied from @fabled 's patch. Then revert than and just patch OMXVideo.cpp. Then revert than and just patch omxplayer.cpp.

Report which (if any) cases were fixed.

[popcornmix]

@dlernstrom @fabled I'd also be interested if http://paste.ubuntu.com/23412695/ behaves the same as the omxplayer.cpp part of @fabled 's patch. I suspect it will behave the same as is rather simpler.

[Ruffio]

@fabled any chance that you could test @popcornmix proposal?

[fabled]

@popcornmix The ubuntu paste's omxplayer.cpp looks good to me. I can adjust my patch and test if you want that. Or perhaps apply my patches' other parts, and the other patch as separate commits? Thanks.