OMXPlayer not playing very short videos, <1 sec

[dannibje]

I have a python program that displays videos from a file one after the other. The videos are uploaded by people and can be anywhere between 0 and 15 sec long. When the video is very short, omxplayer does not display the video and does not exit. The process seems to get stuck and there is no way for the program to know when its finished.

I have the output for the DEBUG logs and the terminal output of omxplayer.

omxplayer.log: 12:03:45 T:105464375 DEBUG: DllBcm: Using omx system library 12:03:45 T:105465692 DEBUG: DllOMX: Using omx system library 12:03:45 T:105466486 DEBUG: DllAvFormat: Using libavformat system library 12:03:45 T:105469528 DEBUG: DBus connection succeeded 12:03:45 T:105471185 DEBUG: Keyboard: DBus connection succeeded 12:03:45 T:105471430 DEBUG: OMXThread::Create - Thread with id 1897919520 started 12:03:45 T:105471544 DEBUG: DllAvUtilBase: Using libavutil system library 12:03:45 T:105471581 DEBUG: DllAvCodec: Using libavcodec system library 12:03:45 T:105471611 DEBUG: DllAvFormat: Using libavformat system library 12:03:45 T:105824877 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.clock input port 80 output port 81 m_handle 0x8c5a10 12:03:45 T:105825216 DEBUG: OMXClock::OMXStop 12:03:45 T:105825350 DEBUG: OMXClock::OMXSetSpeed(0.00) pause_resume:1 12:03:45 T:105825591 DEBUG: DllAvUtilBase: Using libavutil system library 12:03:45 T:105825628 DEBUG: DllAvCodec: Using libavcodec system library 12:03:45 T:105825658 DEBUG: DllAvFormat: Using libavformat system library 12:03:45 T:105828067 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_decode input port 130 output port 131 m_handle 0x8ca4a0 12:03:45 T:105829043 DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.video_decode) - port(130), nBufferCountMin(1), nBufferCountActual(60), nBufferSize(81920), nBufferAlignmen(16) 12:03:45 T:105838120 DEBUG: COMXVideo::Open - decoder_component(0x0x8ca4a0), input_port(0x82), output_port(0x83) deinterlace 1 hdmiclocksync 0 12:03:45 T:105838386 DEBUG: OMXThread::Create - Thread with id 1886385184 started 12:03:45 T:105838500 DEBUG: OMXThread::Create - Thread with id 1877996576 started 12:03:45 T:105838569 DEBUG: DllAvUtilBase: Using libavutil system library 12:03:45 T:105838604 DEBUG: DllAvCodec: Using libavcodec system library 12:03:45 T:105838636 DEBUG: DllAvFormat: Using libavformat system library 12:03:45 T:105838671 DEBUG: DllAvUtilBase: Using libavutil system library 12:03:45 T:105838701 DEBUG: DllAvCodec: Using libavcodec system library 12:03:45 T:105838731 DEBUG: DllAvFormat: Using libswresample system library 12:03:45 T:105842210 DEBUG: DllAvUtilBase: Using libavutil system library 12:03:45 T:105842348 DEBUG: COMXAudio::SetCodingType OMX_AUDIO_CodingPCM 12:03:45 T:105842404 INFO: CPCMRemap: I channel map: CE 12:03:45 T:105842441 DEBUG: CPCMRemap: Mapping mono audio to front left and front right 12:03:45 T:105842499 INFO: CPCMRemap: O channel map: FL,FR 12:03:45 T:105842536 DEBUG: CPCMRemap: Downmix normalization is disabled 12:03:45 T:105842569 DEBUG: CPCMRemap: Mapping mono audio to front left and front right 12:03:45 T:105842634 DEBUG: CPCMRemap: FL = CE(0.707107) 12:03:45 T:105842681 DEBUG: CPCMRemap: FR = CE(0.707107) 12:03:45 T:105844040 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_decode input port 120 output port 121 m_handle 0x8df208 12:03:45 T:105845236 DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.audio_decode) - port(120), nBufferCountMin(4), nBufferCountActual(16), nBufferSize(65536), nBufferAlignmen(16) 12:03:45 T:105861380 DEBUG: COMXAudio::Initialize Input bps 32 samplerate 44100 channels 1 buffer size 264600 bytes per second 176400 12:03:45 T:105861472 DEBUG: pcm->direction : input 12:03:45 T:105861510 DEBUG: pcm->nPortIndex : 120 12:03:45 T:105861542 DEBUG: pcm->eNumData : 0 12:03:45 T:105861573 DEBUG: pcm->eEndian : 1 12:03:45 T:105861605 DEBUG: pcm->bInterleaved : 1 12:03:45 T:105861638 DEBUG: pcm->nBitPerSample : 32 12:03:45 T:105861668 DEBUG: pcm->ePCMMode : 0 12:03:45 T:105861699 DEBUG: pcm->nChannels : 1 12:03:45 T:105861730 DEBUG: pcm->nSamplingRate : 44100 12:03:45 T:105861764 DEBUG: OMX_AUDIO_ChannelCF 12:03:45 T:105861795 DEBUG: COMXAudio::Initialize device omx:local passthrough 0 hwdecode 0 12:03:45 T:105861985 DEBUG: OMXThread::Create - Thread with id 1865946144 started 12:03:45 T:105862062 NOTICE: OMXClock using audio as reference 12:03:45 T:105862339 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 wait mask 0->3 state : 2->1 12:03:45 T:105862710 DEBUG: Popped message member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 12:03:45 T:105862768 WARNING: Unhandled dbus message, member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 12:03:45 T:105862949 DEBUG: Normal M:0 (A:-4503599627370496 V:-4503599627370496) P:1 A:0.00 V:0.00/T:0.20 (0,0,0,0) A:0% V:0% (0.00,9.32) 12:03:45 T:105863080 INFO: CDVDPlayerAudio::Decode dts:0 pts:0 size:4 12:03:45 T:105863399 DEBUG: COMXAudioCodecOMX::Decode(0x8fd2e8,4) format=8(8) chan=1 samples=1024 size=8192 data=0x6f6054d0,(nil),(nil),(nil),(nil),(nil),(nil),(nil) 12:03:45 T:105863511 DEBUG: COMXAudioCodecOMX::GetData size=4096/4096 line=4096/4096 buf=0x6f600468, desired=65536 12:03:45 T:105863558 INFO: CDVDPlayerAudio::Decode dts:23220 pts:23220 size:150 12:03:45 T:105863873 INFO: CDVDPlayerVideo::Decode dts:0 pts:0 cur:0, size:220332 12:03:45 T:105864158 DEBUG: OMXVideo::Decode VDec : setStartTime 0.000000 12:03:45 T:105864577 INFO: CDVDPlayerAudio::Decode dts:46440 pts:46440 size:182 12:03:45 T:105865609 INFO: CDVDPlayerAudio::Decode dts:69660 pts:69660 size:161 12:03:45 T:105866538 INFO: CDVDPlayerVideo::Decode dts:0 pts:83333 cur:83333, size:84407 12:03:45 T:105867071 INFO: CDVDPlayerAudio::Decode dts:92880 pts:92880 size:167 12:03:45 T:105867510 INFO: CDVDPlayerAudio::Decode dts:116100 pts:116100 size:172 12:03:45 T:105867764 INFO: CDVDPlayerAudio::Decode dts:139320 pts:139320 size:163 12:03:45 T:105867967 INFO: CDVDPlayerVideo::Decode dts:41667 pts:41667 cur:41667, size:29221 12:03:45 T:105868308 INFO: CDVDPlayerAudio::Decode dts:162540 pts:162540 size:167 12:03:45 T:105868426 INFO: CDVDPlayerVideo::Decode dts:83333 pts:166667 cur:166667, size:39798 12:03:45 T:105868819 INFO: CDVDPlayerAudio::Decode dts:185760 pts:185760 size:176 12:03:45 T:105868936 INFO: CDVDPlayerVideo::Decode dts:125000 pts:125000 cur:125000, size:8890 12:03:45 T:105869240 INFO: CDVDPlayerAudio::Decode dts:208980 pts:208980 size:166 12:03:45 T:105869364 INFO: CDVDPlayerVideo::Decode dts:166667 pts:250000 cur:250000, size:41358 12:03:45 T:105869764 INFO: CDVDPlayerAudio::Decode dts:232200 pts:232200 size:166 12:03:45 T:105869888 INFO: CDVDPlayerVideo::Decode dts:208333 pts:208333 cur:208333, size:14031 12:03:45 T:105870203 INFO: CDVDPlayerAudio::Decode dts:255420 pts:255420 size:169 12:03:45 T:105870327 INFO: CDVDPlayerVideo::Decode dts:250000 pts:333333 cur:333333, size:60277 12:03:45 T:105870765 INFO: CDVDPlayerAudio::Decode dts:278639 pts:278639 size:162 12:03:45 T:105871008 INFO: CDVDPlayerVideo::Decode dts:291667 pts:291667 cur:291667, size:24917 12:03:45 T:105871404 INFO: CDVDPlayerAudio::Decode dts:301859 pts:301859 size:168 12:03:45 T:105871491 INFO: CDVDPlayerVideo::Decode dts:333333 pts:416667 cur:416667, size:57559 12:03:45 T:105871930 INFO: CDVDPlayerAudio::Decode dts:325079 pts:325079 size:165 12:03:45 T:105872036 INFO: CDVDPlayerVideo::Decode dts:375000 pts:375000 cur:375000, size:18059 12:03:45 T:105872412 INFO: CDVDPlayerAudio::Decode dts:348299 pts:348299 size:164 12:03:45 T:105872683 INFO: CDVDPlayerAudio::Decode dts:371519 pts:371519 size:168 12:03:45 T:105873040 DEBUG: COMXAudio::Decode ADec : setStartTime 0.000000 12:03:45 T:105876296 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_mixer input port 232 output port 231 m_handle 0x6f6005c8 12:03:45 T:105877975 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_render input port 100 output port 100 m_handle 0x6f6006e8 12:03:45 T:105878172 INFO: COMXAudio::ApplyVolume - Volume=1.00 ( 1.00 1.00) 12:03:45 T:105878499 DEBUG: COMXAudio::PortSettingsChanged - Output bps 16 samplerate 44100 channels 2 buffer size 264600 bytes per second 88200 12:03:45 T:105878542 DEBUG: pcm->direction : output 12:03:45 T:105878578 DEBUG: pcm->nPortIndex : 231 12:03:45 T:105878610 DEBUG: pcm->eNumData : 0 12:03:45 T:105878680 DEBUG: pcm->eEndian : 1 12:03:45 T:105878715 DEBUG: pcm->bInterleaved : 1 12:03:45 T:105878746 DEBUG: pcm->nBitPerSample : 16 12:03:45 T:105878777 DEBUG: pcm->ePCMMode : 0 12:03:45 T:105878807 DEBUG: pcm->nChannels : 2 12:03:45 T:105878838 DEBUG: pcm->nSamplingRate : 44100 12:03:45 T:105878869 DEBUG: OMX_AUDIO_ChannelLF 12:03:45 T:105878899 DEBUG: OMX_AUDIO_ChannelRF 12:03:45 T:105880647 DEBUG: COMXAudio::PortSettingsChanged - bits:32 mode:0 channels:1 srate:44100 nopassthrough 12:03:45 T:105886812 DEBUG: Popped message member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 12:03:45 T:105886888 WARNING: Unhandled dbus message, member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 12:03:45 T:105922736 INFO: COMXAudio::ApplyVolume - Volume=1.00 ( 1.00 1.00) 12:03:45 T:105922816 INFO: CDVDPlayerAudio::Decode dts:394739 pts:394739 size:171 12:03:45 T:105922921 DEBUG: Normal M:0 (A:371519 V:375000) P:1 A:0.37 V:0.38/T:0.20 (0,0,1,1) A:0% V:0% (0.00,9.32) 12:03:45 T:105923001 DEBUG: Resume 0.37,0.38 (0,0,1,1) EOF:1 PKT:(nil) 12:03:45 T:105923049 DEBUG: OMXClock::OMXSetSpeed(1.00) pause_resume:1 12:03:45 T:105923173 INFO: CDVDPlayerAudio::Decode dts:417959 pts:417959 size:167 12:03:45 T:105923405 INFO: CDVDPlayerAudio::Decode dts:441179 pts:441179 size:168 12:03:45 T:105923595 INFO: CDVDPlayerAudio::Decode dts:464399 pts:464399 size:172 12:03:45 T:105923782 INFO: CDVDPlayerAudio::Decode dts:487619 pts:487619 size:164 12:03:45 T:105933508 DEBUG: Normal M:0 (A:487619 V:375000) P:0 A:0.49 V:0.38/T:0.20 (0,0,1,1) A:0% V:0% (0.00,9.32) 12:03:45 T:105933744 INFO: COMXVideo::SubmitEOS 12:03:45 T:105933962 INFO: COMXAudio::SubmitEOS 12:03:45 T:105954350 DEBUG: Normal M:0 (A:487619 V:375000) P:0 A:0.49 V:0.38/T:0.20 (0,0,1,1) A:0% V:0% (0.00,9.32) 12:03:46 T:106463650 DEBUG: Previous line repeats 24 times. 12:03:46 T:106463650 DEBUG: OMXClock::OMXStop 12:03:46 T:106471705 DEBUG: OMXThread::Run - Exited thread with id 1877996576 12:03:46 T:106472076 DEBUG: OMXThread::StopThread - Thread stopped 12:03:46 T:106472298 DEBUG: OMXThread::Run - Exited thread with id 1886385184 12:03:46 T:106472407 DEBUG: OMXThread::StopThread - Thread stopped 12:03:46 T:106478804 DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.video_decode handle 0x8ca4a0 12:03:46 T:106479668 DEBUG: OMXThread::Run - Exited thread with id 1865946144 12:03:46 T:106479783 DEBUG: OMXThread::StopThread - Thread stopped 12:03:46 T:106480569 DEBUG: COMXCoreComponent::DecoderEventHandler - OMX.broadcom.audio_mixer Ignoring expected event: eEvent(0x1), nData1(0x8000101c), nData2(0x0), pEventData(0x(nil)) 12:03:46 T:106531463 DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.audio_decode handle 0x8df208 12:03:46 T:106571043 DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.audio_mixer handle 0x6f6005c8 12:03:46 T:106571865 DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.audio_render handle 0x6f6006e8 12:03:46 T:106576764 DEBUG: OMXThread::Run - Exited thread with id 1897919520 12:03:46 T:106576919 DEBUG: OMXThread::StopThread - Thread stopped 12:03:46 T:106578068 DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.clock handle 0x8c5a10

output to terminal: Video codec omx-h264 width 1080 height 1920 profile 100 fps 24.000000 Audio codec aac channels 1 samplerate 44100 bitspersample 16 Subtitle count: 0, state: off, index: 1, delay: 0

And after this the process is "frozen", doesn't end.

Is this something that som1 has experienced before?

[jehutting]

@dannibje Did you tried it with --audio_fifo, --video_fifo, --audio_queue and --video_queue options? The smallest mp4 I have with a Duration: 00:00:01.92 plays/loops fine. Otherwise try to create a logging (omxplayer.log) with the -g option, or just post the video.

[jehutting]

@dannibje Thanks for the logging. Indeed, From it, I can see that the video is never started. It issues a SubmitEOS, but never catch this EOS (missing IsEOS in logging). It seems to stop (the rest of the logging after the SubmitEOS, I have to verify that for sure).

I can't determine the duration of the video.

Try to see what --audio_fifo 0 and/or --video_fifo 0 does.

Possible to post the video?

[dannibje]

@jehutting Thanks for your quick answers. I tried playing the video with --audio_fifo 0 and/or --video_fifo 0 options and it seems to give the same results. Sending the logs in case you can see something I cant. I attached the video so you can check it out. I know it is an m4v file but I have had the same issue with mp4 and successfully played longer m4v videos with the omxplayer (The video plays but is not correctly enoded stuff).

omxLogs.zip IMG_0884.m4v.zip

[jehutting]

Again a problem of the media time clock not getting to run.

It is the same as I found out here. With the patch which forces the call to OMXVideo::PortSettingChanged, your short video plays...well that is to say... it is more a flash as it is so short :-).

Out of curiosity, what's the purpose of having so small videos?

[dannibje]

Thank you so much for your help! And to satisfy your curiosity. People can upload any kind of videos to our platform and those videos get displayed on a TV-screen via RPi. Someone uploaded a very short video and the whole thing froze. We fixed it with a timer that triggered after x-time. But that is a hack, thank you for the fix!

[tvjon]

Actually, omxplayer will play it, but only via a contrived way...

$ omxplayer -v omxplayer - Commandline multimedia player for the Raspberry Pi Build date: Mon, 30 Jan 2017 01:52:37 +0000 Version : 62fb580 [master] Repository: https://github.com/popcornmix/omxplayer.git

$ omxplayer --display 4 IMG_0884.m4v Video codec omx-h264 width 1080 height 1920 profile 100 fps 24.000000 Audio codec aac channels 1 samplerate 44100 bitspersample 16 Subtitle count: 0, state: off, index: 1, delay: 0 Seek to: 00:00:00 V:PortSettingsChanged: 1080x1920@24.00 interlace:0 deinterlace:0 anaglyph:0 par:1.00 display:4 layer:0 alpha:255 aspectMode:0

At this stage, pressing left-arrow (quickly followed by pressing space if you want to study it) will show it. I also managed to get dbuscontrol.sh to do similar, but inconsistently, so possibly with the right combination (can dbus commands be concatenated?) it could be done properly.

[rbckman]

Hello! I've been running into this same issue. Is there a workaround / fix? I'm building a camera that can glue your film together. It would be important to get to see your takes even if they're just around 2 secs. But at the moment the playback only works 2 out of 10 times due to this issue. :'(

heres the log omxplayer.log ps. heres a link to my camera project called tarina

[rbckman]

hmm.. wondering if this pull request would fix this issue.

[dronus]

I don't think that would help. There where some discussions (can't find them now) for this well known bug of omxplayer to not play very short files. The bug as I remember was inside the firmware / hardware stack for video decoding (OpenMAX) and there whas no idea how omxplayer could reliable circumvent the problem. Maybe that is fixed as of today, but maybe not. If not, pausing or resuming the video won't help, as it is the software / hardware of the accelerated video codec that won't start running until at least x kb or frames are fed into.

[rbckman]

thanks! figured out how to do it! tvjon, you said the video will play if you press left key (previous video). So im using omxplayer through Will Prices wrapper https://github.com/willprice/python-omxplayer-wrapper and it's as easy as to send the player.previous() command before you start the video and it works!