Record budder starving only on sunday

[bostiko]

Hallo, I am using your SW for live streaming from churches. I have a combination of picam + ffmpeg and sending live stream to youtube. When I broadcast on workdays, everything is fine. But when I start stream on sunday, I failed with error:

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

The script is not changing:

url="rtmp://a.rtmp.youtube.com/live2/"
log_ffmpeg="/var/log/ffmpeg.log"
log_picam="/var/log/picam.log"

echo "\n$(date) @ $(hostname) @ $url" | tee -a $log_picam $log_ffmpeg 
ffmpeg -i tcp://127.0.0.1:8181?listen -af "pan=mono|c0=c0+c1" -c:v copy -c:a aac -ar 44100 -ab 40000 -f flv $url >> $log_ffmpeg &
/home/pi/picam/picam --alsadev hw:2,0 --tcpout tcp://127.0.0.1:8181 >> $log_picam

HW: RPi 4, 2GB, RPi HD CAM, soundcard Hiffiberry ADC DAC Pro+

Can you please help me? Thank you, Ondrej Bostik

[bostiko]

Hallo, I have some update. In one church, we have found that when we plug electric organ/piano to the save socket, the problem occured. We have changed USB soundcard to profesional USB soundcard, but the problem persist. We have found the "solution" in first to power on the organs, then RPi. But in second church, the problem is the same. There is big organs with pipes and electric ventilator to suppy air to the pipes. Randomly during the service, the youtube streams stops. For now, I read picam log file and when I see the word "gopsize", I restart the picam and ffmpeg. But there is an annoing 20-30sec lag in the youtube stream. Both churches has the exactly same HW and SW version (I made image of SD card). I have the latest binary picam v1.4.9. Camera is conencted to the RPi with 2m cable. What exactly the message means? warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

Thank you for your assistence. O.Bostik

[iizukanao]

@bostiko Thanks for using picam! Apologies for the delayed response. That warning appears when something unusual is happening - such as very low fps or when video stream becomes unavailable. I think the power supply becomes unstable when electric organ is being used. Please try using a stable 3A power supply.

[bostiko]

@iizukanao Thank you for your response. The power supply seems stable. It is the official RPi 3A power supply... Local guy told me, that there is a electric relay under each pipe, so it could be an interference from relay to 2m RPi camera cable... What you think?

[iizukanao]

@bostiko It's possible that the electric relay interferes with camera. Try enabling a video preview by using the command line option -p, then check if camera is capturing images without any noise during the problem. You can see preview image by connecting an HDMI cable to a monitor.

If possible, please add --verbose command line option and write the output to a file (e.g. ./picam --alsadev hw:1,0 -p --verbose &> output.log), then send me the output.log.

Also, you can record a video to .ts file and see what was going on during the problem. See Recording for how to record a video.

[bostiko]

@iizukanao The preview is the problem: I have the RPi in remote church and I am logging in via TeamViewer only. But I am using --verbose command to save logs:

picam.log: `............... 29.92 fps k=1692 a-v=-4620 c-a=9128 u=0 d=8 pts=76092300

............... 30.18 fps k=1693 a-v=-5460 c-a=9712 u=0 d=8 pts=76137300

............... 29.89 fps k=1694 a-v=-4380 c-a=8816 u=0 d=8 pts=76182300

............... 30.14 fps k=1695 a-v=-5220 c-a=9464 u=0 d=8 pts=76227300

.............warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

warning: Record buffer is starving. Recorded file may not start from keyframe. Try reducing the value of --gopsize.

stop requested (signal=15)

shutdown sequence start

waiting for the camera to finish

hit Ctrl-\ to force stop`

ffmpeg.log: `frame=25355 fps= 30 q=-1.0 size= 227593kB time=00:14:04.58 bitrate=2207.5kbits/s speed=1.01x

frame=25373 fps= 30 q=-1.0 size= 227737kB time=00:14:05.18 bitrate=2207.4kbits/s speed=1.01x

frame=25389 fps= 30 q=-1.0 size= 227883kB time=00:14:05.73 bitrate=2207.3kbits/s speed=1.01x

frame=25406 fps= 30 q=-1.0 size= 228032kB time=00:14:06.31 bitrate=2207.3kbits/s speed=1.01x

frame=25424 fps= 30 q=-1.0 size= 228184kB time=00:14:06.91 bitrate=2207.2kbits/s speed=1.01x

frame=25435 fps= 30 q=-1.0 size= 228290kB time=00:14:07.25 bitrate=2207.3kbits/s speed=1.01x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:07.78 bitrate=2206.1kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:08.96 bitrate=2203.1kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:10.13 bitrate=2200.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:11.28 bitrate=2197.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:12.43 bitrate=2194.1kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:13.61 bitrate=2191.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:14.78 bitrate=2188.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:15.95 bitrate=2185.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228308kB time=00:14:17.11 bitrate=2182.1kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228332kB time=00:14:18.28 bitrate=2179.3kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228360kB time=00:14:19.45 bitrate=2176.6kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228388kB time=00:14:20.60 bitrate=2174.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228417kB time=00:14:21.78 bitrate=2171.3kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228445kB time=00:14:22.95 bitrate=2168.6kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228473kB time=00:14:24.10 bitrate=2166.0kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228502kB time=00:14:25.28 bitrate=2163.3kbits/s speed= 1x

frame=25437 fps= 30 q=-1.0 size= 228530kB time=00:14:26.45 bitrate=2160.7kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228558kB time=00:14:27.60 bitrate=2158.1kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228586kB time=00:14:28.75 bitrate=2155.5kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228614kB time=00:14:29.91 bitrate=2152.9kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228643kB time=00:14:31.08 bitrate=2150.2kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228671kB time=00:14:32.25 bitrate=2147.6kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228700kB time=00:14:33.43 bitrate=2145.0kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228728kB time=00:14:34.58 bitrate=2142.4kbits/s speed= 1x

frame=25437 fps= 29 q=-1.0 size= 228756kB time=00:14:35.73 bitrate=2139.9kbits/s speed= 1x . . . last log repeats itself for a long time... . . . untill... . . frame=25437 fps= 23 q=-1.0 size= 234195kB time=00:18:19.49 bitrate=1744.9kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234224kB time=00:18:20.67 bitrate=1743.3kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234252kB time=00:18:21.82 bitrate=1741.6kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234280kB time=00:18:22.97 bitrate=1740.0kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234308kB time=00:18:24.15 bitrate=1738.4kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234337kB time=00:18:25.32 bitrate=1736.8kbits/s speed= 1x

frame=25437 fps= 23 q=-1.0 size= 234365kB time=00:18:26.49 bitrate=1735.1kbits/s speed= 1x

frame=25439 fps= 22 q=-1.0 size= 234403kB time=00:18:27.62 bitrate=1733.6kbits/s speed=0.977x

[flv @ 0x13af900] Failed to update header with correct duration.

[flv @ 0x13af900] Failed to update header with correct filesize.

Error writing trailer of rtmp://a.rtmp.youtube.com/live2/atvd-6z8k-pphw-33gg-4s6j: End of file

frame=25439 fps= 22 q=-1.0 Lsize= 234406kB time=00:18:27.67 bitrate=1733.6kbits/s speed=0.977x

video:207214kB audio:26074kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.479049%

[aac @ 0x141a5e0] Qavg: 138.162`

When I see the stream stops, I log in via teamviewer and pkill -9 picam. I have a background rountine, which restarts picam when it stops prematurely.

Recently I extended this rountine to monitor the picam.log for a word gopsize and if it shows up for more than 2 times in the last 10 rows, I pkill -9 picam and restart it again. In this manner, I am able to automatically continue the youtube stream, but there is a lag of around 30 seconds....

[iizukanao]

@bostiko Looks like the camera stops producing image for unknown reason. When the problem occurs and you restart picam without rebooting the pi, does picam capture video and audio without issues? Also, please let me know the specific hardware model of your pi and camera.

[bostiko]

@iizukanao Yes, all it needs is to restart the picam and the problem solved... I have RPi 4B, 2GB RAM (512 GPU), HQ camera on 2m cable...

[iizukanao]

@bostiko Thanks. Hmm, I'm not sure why the problem is happening, but let me test with similar setup.

[bostiko]

@iizukanao Thank you, let me know than :)

[iizukanao]

@bostiko I'm testing on my pi, but haven't been able to reproduce the problem. I think your camera or camera cable is suffering electrical interference from the environment. Maybe wrapping an aluminum foil around the camera cable improves the problem? Please be careful not to touch an electronic component with an aluminum foil.

[bostiko]

@iizukanao Tomorow I will (probably) replace the cable for the shorther one and I will report to you, if there is any difference.

[feacluster]

What's the output of "uname -a". I have noticed strange behavior with the newer 5.x kernel. I have several cameras using the older 4.x kernel on pi4b's without any issue.

[bostiko]

@feacluster The kernel version is Linux kam 5.4.83-v7l+ #1379

@iizukanao I have replaced the cable for the shorter one (from 200cm to 50cm) and move the RPi out of the electric relays controling the pipes. From then the straming is working fine. Thanks a lot for your help :)

[iizukanao]

@bostiko That's great! 🙂