popcornmix / omxplayer

omxplayer
GNU General Public License v2.0
1.01k stars 334 forks source link

--live streaming-lag with RPICam running stream on antoher rpi with tontec display SPI and fbcp #690

Open piffjosef opened 5 years ago

piffjosef commented 5 years ago

Hi!

Thank you for omxplayer, this is really a super player... resource-conserving is excellent... I had it working since I created a doorbell with RPICam on a outdooor RPI2. On a inHouse Raspberry3 with a mounted Tontec Display 3.5" (SPI) I was streaming with --live Option the MJPEG Stream from the RPICam with following URL: http://10.0.0.11/html/cam_pic_new.php which was working really good and no delay.

Since a SDCard Problem on my internal RPI3 I had to reinstall it with newest distri - no GUI, downloaded omxplayer from here and compiled it against the tutorial here... (I can remember, that I also had something to compile, but I forgot...) Now I have a 1min Delay after running 5mins, and the delay grows and grows... I've read something about, that ffmpeg do some buffering for internal analyzing, but I thought the --live option will exclude buffering. restart omxplayer is not an option, because it alway delays somewhere...

I used the normal fbcp and the fbcp-ili9341, no difference, same behaviour, when installing lxde and stream via midori or chromium, it is working, but rpi get very hot ~75C, with omxplayer and no gui it was about 55C - this is what my prefered solution, but I can't get working without the delay...

so when calling omxplayer it shows picture immediatly, but the timestamp delays asap, I mean 1 second is 3 seconds.... and it grows up about 30sec, then it runs smooth, after some time the delay grow and grow....

this is output with the -i Option: root@raspberrypi:~# /usr/bin/omxplayer.bin --live http://10.0.0.11/html/cam_pic_new.php -i Input #0, mpjpeg, from 'http://10.0.0.11/html/cam_pic_new.php': Duration: N/A, bitrate: N/A Stream #0:0: Video: mjpeg, yuvj420p(pc, bt470bg/unknown/unknown), 512x384, 25 tbr, 25 tbn, 25 tbc have a nice day ;)

I also tried: #ExecStart=/usr/bin/omxplayer --video_fifo 0.1 --video_queue 0.1 "http://10.0.0.11/html/cam_pic_new.php" --refresh --stats --lines 1 --threshold 0.1 --live

--> this was best: #ExecStart=/usr/bin/omxplayer --live --threshold 0 --video_queue 0.1 --aidx -1 "http://10.0.0.11/html/cam_pic_new.php"

ExecStart=/usr/bin/omxplayer --live "http://10.0.0.11/html/cam_pic_new.php"

#ExecStart=/opt/omxplayer/omxplayer --video_fifo 0.1 --video_queue 0.1 "http://10.0.0.11/html/cam_pic_new.php" --refresh --stats --lines 1 --threshold 1

Thank you for your support, please also find enclosed omxplayer.log

Systeminformations:

RPICam-Infos: https://elinux.org/RPi-Cam-Web-Interface

`root@raspberrypi:~# cat /etc/debian_version 9.4

root@raspberrypi:~# cat /etc/os-release PRETTY_NAME="Raspbian GNU/Linux 9 (stretch)" NAME="Raspbian GNU/Linux" VERSION_ID="9" VERSION="9 (stretch)" ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

omxplayer - Commandline multimedia player for the Raspberry Pi Build date: Wed, 27 Feb 2019 20:53:38 +0100 Version : f06235c [master] Repository: https://github.com/popcornmix/omxplayer.git

root@raspberrypi:~# ffmpeg ffmpeg version N-93257-gb38dd2d219 Copyright (c) 2000-2019 the FFmpeg developers built with gcc 6.3.0 (Raspbian 6.3.0-18+rpi1+deb9u1) 20170516 configuration: --arch=armel --target-os=linux --enable-gpl --enable-libx264 --enable-nonfree --enable-decoder=mjpeg --enable-demuxer=mjpeg libavutil 56. 26.100 / 56. 26.100 libavcodec 58. 47.102 / 58. 47.102 libavformat 58. 26.101 / 58. 26.101 libavdevice 58. 6.101 / 58. 6.101 libavfilter 7. 48.100 / 7. 48.100 libswscale 5. 4.100 / 5. 4.100 libswresample 3. 4.100 / 3. 4.100 libpostproc 55. 4.100 / 55. 4.100 Hyper fast Audio and Video encoder usage: ffmpeg [options] [[infile options] -i infile]... {[outfile options] outfile}...`

piffjosef commented 5 years ago

how to add omxplayer.log, it has 3MB ?

piffjosef commented 5 years ago

These are the first lines of the omxplayer.log

09:33:33 T:18446744073640654246 DEBUG: DllBcm: Using omx system library 09:33:33 T:18446744073640655478 DEBUG: DllOMX: Using omx system library 09:33:33 T:18446744073640656587 DEBUG: DllAvFormat: Using libavformat system library 09:33:33 T:18446744073640659449 DEBUG: DBus connection succeeded 09:33:33 T:18446744073640661181 DEBUG: Keyboard: DBus connection succeeded 09:33:33 T:18446744073640661583 DEBUG: OMXThread::Create - Thread with id 1854927328 started 09:33:33 T:18446744073640661920 DEBUG: DllAvUtilBase: Using libavutil system library 09:33:33 T:18446744073640661975 DEBUG: DllAvCodec: Using libavcodec system library 09:33:33 T:18446744073640662003 DEBUG: DllAvFormat: Using libavformat system library 09:33:33 T:18446744073640663539 DEBUG: COMXPlayer::OpenFile - avformat_open_input http://10.0.0.11/html/cam_pic_new.php 09:33:33 T:18446744073640677407 DEBUG: COMXPlayer::OpenFile - avformat_open_input enabled SEEKING 09:33:33 T:18446744073640682203 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.clock input port 80 output port 81 m_handle 0x374458 09:33:33 T:18446744073640682516 DEBUG: OMXClock::OMXStop 09:33:33 T:18446744073640682803 DEBUG: OMXClock::OMXSetSpeed(0.00) pause_resume:1 09:33:33 T:18446744073640683029 DEBUG: DllAvUtilBase: Using libavutil system library 09:33:33 T:18446744073640683060 DEBUG: DllAvCodec: Using libavcodec system library 09:33:33 T:18446744073640683086 DEBUG: DllAvFormat: Using libavformat system library 09:33:33 T:18446744073640685388 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_decode input port 130 output port 131 m_handle 0x378ea0 09:33:33 T:18446744073640686318 DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.video_decode) - port(130), nBufferCountMin(1), nBufferCountActual(60), nBufferSize(81920), nBufferAlignmen(16) 09:33:33 T:18446744073640693183 DEBUG: COMXVideo::Open - decoder_component(0x0x378ea0), input_port(0x82), output_port(0x83) deinterlace 1 hdmiclocksync 0 09:33:33 T:18446744073640693571 DEBUG: OMXThread::Create - Thread with id 1844441568 started 09:33:33 T:18446744073640693734 DEBUG: OMXThread::Create - Thread with id 1836052960 started 09:33:33 T:18446744073640693950 NOTICE: OMXClock using video as reference 09:33:33 T:18446744073640694167 DEBUG: OMXClock::OMXReset audio / video : 0 / 1 wait mask 0->2 state : 2->1 09:33:33 T:18446744073640694557 DEBUG: Popped message member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 09:33:33 T:18446744073640694612 WARNING: Unhandled dbus message, member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 09:33:33 T:18446744073640694756 DEBUG: Normal M:0 (A:0 V:-4503599627370496) P:1 A:0.00 V:0.00/T:0.70 (0,0,1,0) A:0% V:0% (0.00,0.00) 09:33:33 T:18446744073640695052 INFO: CDVDPlayerVideo::Decode dts:40000 pts:40000 cur:40000, size:13706 09:33:33 T:18446744073640695229 DEBUG: OMXVideo::Decode VDec : setStartTime 0.040000 09:33:33 T:18446744073640700710 INFO: CDVDPlayerVideo::Decode dts:80000 pts:80000 cur:80000, size:13706 09:33:33 T:18446744073640712211 INFO: CDVDPlayerVideo::Decode dts:120000 pts:120000 cur:120000, size:13739 09:33:33 T:18446744073640713575 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_render input port 90 output port 90 m_handle 0x6ce005b0 09:33:33 T:18446744073640713625 DEBUG: COMXVideo::PortSettingsChangedLogger - 512x384@25.00 interlace:0 deinterlace:0 anaglyph:0 par:1.12 display:0 layer:0 alpha:255 aspectMode:0 09:33:33 T:18446744073640714874 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_scheduler input port 10 output port 11 m_handle 0x6ce006c0 09:33:33 T:18446744073640723624 INFO: CDVDPlayerVideo::Decode dts:160000 pts:160000 cur:160000, size:13739 09:33:33 T:18446744073640723725 DEBUG: Popped message member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 09:33:33 T:18446744073640723797 WARNING: Unhandled dbus message, member: NameAcquired interface: org.freedesktop.DBus type: 4 path: /org/freedesktop/DBus 09:33:33 T:18446744073640723970 DEBUG: Normal M:0 (A:0 V:160000) P:1 A:0.00 V:0.16/T:0.70 (0,0,1,0) A:0% V:0% (0.00,0.00) 09:33:33 T:18446744073640734927 INFO: CDVDPlayerVideo::Decode dts:200000 pts:200000 cur:200000, size:13739 09:33:33 T:18446744073640746344 INFO: CDVDPlayerVideo::Decode dts:240000 pts:240000 cur:240000, size:13741 09:33:33 T:18446744073640746478 DEBUG: Normal M:-160000 (A:0 V:240000) P:1 A:0.16 V:0.40/T:0.70 (0,0,1,0) A:0% V:0% (0.00,0.00) 09:33:33 T:18446744073640757830 INFO: CDVDPlayerVideo::Decode dts:280000 pts:280000 cur:280000, size:13741 09:33:33 T:18446744073640769144 INFO: CDVDPlayerVideo::Decode dts:320000 pts:320000 cur:320000, size:13741

jehutting commented 5 years ago

Omxplayer.log can be posted e.g. on pastebin.com or dropbox.com.

piffjosef commented 5 years ago

thank you for the tipp, here the link to the logfile... if you need more logs, please let me know...

https://www.dropbox.com/s/nehwvxcr22s8nki/omxplayer.log?dl=0

jehutting commented 5 years ago

Thanks for the logging. Looking at the 'Live' lines in the logging, I see the slowly increasing latency:

09:33:33 T:18446744073640861160   DEBUG: Live: 0.72 (0.78) S:1.000 T:0.70
09:36:10 T:88146356               DEBUG: Live: 2.64 (2.62) S:1.010 T:0.70

As you are able to compile the OMXPlayer code could you do a little experiment?

The latency determines how much the increase of the playing speed will be. see https://github.com/popcornmix/omxplayer/blob/master/omxplayer.cpp#L1718

            m_latency = m_latency*0.99f + latency*0.01f;
            float speed = 1.0f;
            if (m_latency < 0.5f*m_threshold)
              speed = 0.990f;
            else if (m_latency < 0.9f*m_threshold)
              speed = 0.999f;
            else if (m_latency > 2.0f*m_threshold)
              speed = 1.010f;                      <<<<< change to e.g 1.5f
            else if (m_latency > 1.1f*m_threshold)
              speed = 1.001f;                       <<<<< change to e.g 1,2f

            m_av_clock->OMXSetSpeed(S(speed));
            m_av_clock->OMXSetSpeed(S(speed), true, true);
            CLog::Log(LOGDEBUG, "Live: %.2f (%.2f) S:%.3f T:%.2f\n", m_latency, latency, speed, m_threshold);

The experiment would be to change the speed values to see if OMXPlayer can catch up. I don't know what the value would be (and why they are currently so small!?). Try speed 1.2f, 1.5f, that kind of values.

I am not aware of a change of these values between you (previously) working version and your (current) upgraded version.

jehutting commented 5 years ago

Nope. I tried it myself. Doesn't improve the latency.

piffjosef commented 5 years ago

You still want me to try?

jehutting commented 5 years ago

You can try it yourself if you like to do so. It will just be a confirmation that it is not the solution for this issue.

piffjosef commented 5 years ago

did not yet test it, hopefully tomorrow.... what I also recognized, just additional info: in the working installation there was always activity on the network interface, but now if omxplayer runs longer, then the led does not flicker continuously, as if it would wait, and then continue loading... also the video isn't fluid, it's a slight forward/backward flicker and osd is not synchronous

piffjosef commented 5 years ago

doesnt improve....

18:28:44 T:1187178161 DEBUG: Live: 0.72 (0.78) S:1.000 T:0.70 18:30:29 T:1292508462 DEBUG: Live: 2.64 (2.62) S:1.500 T:0.70

piffjosef commented 5 years ago

I tried mjpegstreamer instead of rpicam, running whole day, no lag with live Switch.... maybe some Kind of codec issue with rpicam?